✅ 오늘의 시간표
| 시간 | 카테고리 | 할 일 상세 |
| 20:30-22:30 | OneStep | SZ-243 오류 수정 |
| 22:30-23:00 | 사이드 프로젝트 | django model과 spring entity 연결해서 모델 생성 |
| 23:00-00:00 | 사이드 프로젝트 | API 개발 |
+ 결국 다 못 끝냈다...! 나머지는 내일 더 해보자
✅ 오늘 배운 것
SZ-243번 이슈, 즉 uvicorn과 gunicorn으로 서버 성능을 향상시키고 이를 locust로 실행시키는 문제는 github workflow가 실패하면서 반영하지 못했었다. 중간평가도 끝났으니 이 부분을 먼저 해결해보려고 한다.
당시 timeout 설정과 worker 설정을 해 주었는데, 멘토님께도 여쭤보니 명령어에서 migrate를 같이 하는데 이 경우 worker가 migration을 기다리다가 timeout이 될 수도 있다고 하셨다. GPT에게도 같은 질문을 해 보니 비슷한 해결책을 제시했다.
우선은 migration이 다 완료된 다음에 gunicorn으로 서버를 시작해서 timeout을 방지하도록 하는 방법이 있었다. 그러나 이미 'python manage.py &&'으로 migration 다음에 순차적으로 gunicorn 명령어를 실행하고 있었으므로, 이 부분에서 문제가 났을 가능성은 적었다.
또 다른 방법은 gunicorn의 timeout 설정을 더 늘리고(여기서는 300초를 제시했다), worker의 수가 많아서 서버 자원이 부족할 수 있으니 worker의 수를 기존 4개에서 2개로 줄이는 방법도 있었다. 두 방법 모두를 적용해서 다음과 같이 명령어를 바꿔 보았다.
gunicorn onestep_be.asgi:application --timeout 300 -w 2 -k uvicorn.workers.UvicornWorker
워크플로우의 실행 시간이 20분을 넘어가고 있다... 이대로라면 실패할 가능성이 매우 높다. (실제로 한 10분 쯤 뒤에 실패했다.) 이유가 뭘까 싶어서 AWS ECS 클러스터>서비스의 이벤트 로그를 보았다.
왜인지 모르겠지만 타겟 그룹을 등록한 이후 15분 뒤에 헬스체크가 fail이 났다. 원래는 5분 간격이었는데 15분이 된 걸 보면 uvicorn의 timeout 설정이 영향을 준 것으로 보인다. 또한 헬스체크가 fail한 원인도 알아봐야 하겠다.
지금 생각하고 있는 원인이나 개선 방법들은 다음과 같다.
1. 로드밸런서의 헬스체크 URL을 수정하자.
2. 로드밸런서의 헬스체크 대기 시간을 더 길게 수정하자.
3. 로그를 debug 모드로 설정해서 gunicorn, uvicorn에서 더 많은 정보를 수집할 수 있도록 하자.
1번을 얘기한 이유는, 해당 uvicorn 및 gunicorn 커맨드가 잘 실행되기는 하는지 의심이 되억서 로컬에서 명령어를 그대로 실행해 보았었다. 다행히 잘 실행은 되는데, 로그와 같이 나온 'Not Found' 라는 부분이 걸렸다. 기존에 로드밸런서 헬스체크에서는 /swagger URL에서 200이나 301을 리턴해야 성공이라고 간주하는데 혹시 404를 리턴받은 것은 아닌가? 라는 추측을 했다.
그래서 우선은 200을 리턴하는 것이 확실한 API를 다시 헬스체크 포인트로 설정해주려고 한다.
또한 2번의 경우 헬스체크 대기 시간을 얼마나 더 길게 설정해야 할지는 모르겠다. 현재는 제한 시간이 5초로 되어 있었어서, 이를 10초로 바꿔 주었다.
마지막으로 현재는 gunicorn과 uvicorn worker에서 무슨 일이 일어나는지 정확히 알 수 없으니, log level을 debug로 설정해서 CloudWatch에서 더 많은 정보를 수집하도록 바꿔주었다.
gunicorn onestep_be.asgi:application --timeout 300 -w 2 -k uvicorn.workers.UvicornWorker --log-level debug
우선은 짚이는 부분을 전부 바꿔 주었으니 이제 또 워크플로우를 기다려 보는 수밖에 없다. 워크플로우를 debug 모드에서 실행시킬 수 있길래 yes를 한번 눌러보았다. 그랬더니 보라색 글씨로 더 자세한 로그가 떴다. 이 중에서 걸리는 점은 30분 간 서버가 안정화될 때까지 기다린다는 것이었다... 더 빠른 방법이 있을 것 같은데 말이다.
아마도 yaml 파일에서 "wait-for-service-stability: true"로 설정한 것이 원인으로 보였다. 공식문서를 찾아보니 기본값은 false였다.
그런데 이 값이 설정된다고 30분을 기다려야 한다는 건 내가 느끼기에는 너무 긴 시간 같았다. 기본값을 낮추고 싶었다.
알고보니 대기시간이 30분으로 기본값으로 설정된 것은 아니고, 'minimumHealthyPercent'와 'maximumHealthyPercent'의 값을 조정해서 '새 태스크가 몇 퍼센트 이상 준비되어야 기존 태스크를 중지할지'와 '최대 몇 퍼센트의 태스크가 동시에 실행될 수 있는지'를 조정할 수 있다고 한다. 'minimumHealthyPercent'의 값을 낮추고, 'maximumHealthyPercent'의 값을 높이면 새 태스크가 더 빨리 실행될 수 있다고 한다.
이 내용이 신기해서 해당 내용을 어디서 찾았는지 링크를 달라고 했다. 그랬더니 이 녀석이 하나는 유효한 링크를 주었지만 다른 하나는 없는 링크를 준다. 사실 'minimumHealthyPercent' 관련 내용을 알고 싶어서 좀 아쉬웠지만, 유효한 링크에 나와있는 정보도 어차피 내가 잘 모르는 내용이니 한번 읽어보았다.
읽어보던 와중 30분 기다린 워크플로우가 fail이 났다는 슬픈 소식이 들려왔다.
이 로그만으로는 정보가 충분치 않아서 AWS ECS 서비스의 이벤트 로그 및 태스크 로그도 같이 살펴보았다. 그랬더니 더더욱 상황을 알 수 없게 되었다. 아무래도 내가 ECS 클러스터와 서비스와 태스크, 그리고 이걸 워크플로우로 실행시키는 것에 대한 모종의 지식이 부족해서 이 로그들만 보고 상황을 이해하지 못하는 것 같다.
일단 이해를 못 하겠는 이유는 다음과 같다.
1. 로드밸런서의 타겟 그룹의 헬스체크 설정을 적절히 바꿔줬다고 생각했는데 헬스체크가 또 실패했다. 이 정도면 헬스체크 설정이 잘못되어서 헬스체크가 실패한 것이 아닐 수도 있겠다.
2. 왜 워크플로우는 실패하는데 현재 실행되고 있는 서비스의 태스크는 최신 태스크 정의를 반영하고 있을까?
특히 2번이 정말 이해가 되지 않았다. 혹시 코드가 개발서버에 잘 반영이 되어도 워크플로우는 실패할 수가 있나?
알고보니 가능한 여러 시나리오들이 있었다. 우선 첫 번째는 내가 예상했던 '후속 작업의 실패'였다. 가령 서버에 코드는 잘 배포했지만 뒤에 있는 테스트가 실패했을 경우 워크플로우는 하나라도 작업이 실패했으니 실패라고 기록된다고 한다. 그 외에도 다양한 원인들이 있었다.
'타임아웃 및 서비스 안정화 문제'의 경우, 앞서 언급했던 'wait-for-service-stability' 값과 관련이 있었다. 서비스가 처음에 성공적으로 실행되었어도, 안정화 되는데 기준보다 긴 시간이 걸리면 워크플로우는 실패로 간주한다고 한다. 다른 설정도 있지만 이 설정이 바꾸기 간단하기도 하고 아까 의심했던 부분이기도 해서, 이 값을 기본값인 false로 지정하고 다시 워크플로우를 다시 실행시켰다.
세상에. 바로 성공했다. 심지어 2분 만이었다..! 완전 짱이다. 설정 하나로 이렇게 결과가 바뀔 줄은 몰랐다. 더 복잡한 문제면 어디부터 봐야 하나 싶어서 조금 막막해지려던 찰나였는데, 아주 좋은 결과다. 그리고 덕분에 모르는 부분들에 대해서도 많이 알 수 있었어서 나름의 수확이 있었다.
이제 마음 놓고 locust로 부하 테스트를 다시 해 보자.
그런데 Locust로 부하 테스트를 해 보니 결과가 이상했다.
이전과 차이가 거의 없었다. 여러 worker가 동작하고 있는지 의심이 들었다. 아마 아닐 것 같았다. 워크플로우는 성공했는데 뭘까? 이에 대한 답은 잘 돌아가던 태스크를 삭제하니 알 수 있었다. AWS ECS 클러스터의 서비스를 보니 태스크가 2개 돌아가고 있었다. 하나는 구 버전(45), 하나는 최신 버전(53) 이었다. 왜 두 개가 돌아가지? 싶어서 구 버전을 지웠다. 그랬더니 서버가 동작하지 않았다.
알고보니 구 버전(uvicorn, gunicorn 설정이 반영되지 않은 버전)에서 서버가 돌아가고 있었고, 최신 버전에서는 아직 헬스 체크 등의 작업이 진행 중이었다. 그래서 태스크가 두 개 떠 있던 것이었다.
결국 문제는 다시 원점으로 돌아갔다. 워크플로우는 'wait-for-service-stability' 설정을 바꿔준 덕분에 성공하였지만, 새 태스크의 헬스체크가 오래 걸리고, 아마도 높은 확률로 실패할 것이다. 결국 로드밸런서의 헬스체크가 자꾸 실패하는 문제를 해결해야 했다.
여러 가지 가능성이 있었다. 우선은 uvicorn & gunicorn이 사용하는 포트와 로드밸런서가 헬스체크를 하는 포트가 다를 가능성을 보자. 그러나 지금은 삭제해버린 이전 태스크에서 로드밸런서가 헬스체크를 할 때 충분히 요청을 잘 받고 있었으므로 이 문제일 것 같지는 않았다.
여러 가지 가능성들 중 걸리는 부분은 "ASGI 'lifespan' protocol appears unsupported." 라는 경고였다. 이는 ASGI 인터페이스에서 lifespan이라는 프로토콜을 지원하지 않는다는 것인데, 나도 이 로그를 예전부터 봐 왔지만 로그 레벨이 INFO로 되어 있어서 단순 경고 정도겠지 하고 그냥 넘겼었다. 그런데 이 부분이 문제가 될 수도 있다고 한다. 이러면 WAS의 생명주기와 관련해서 문제가 있을 수 있다고 한다.
그런데 알고보니 GPT가 잘못된 명령어를 알려준 것 같다. ECS 서비스 안에서 생성된 태스크의 로그를 보니 이렇게 나와있었다.
다시 올바른(GPT 피셜) 명령어를 찾아서 파일을 바꿔 주었다.
UVICORN_LIFESPAN=off gunicorn onestep_be.asgi:application --timeout 300 -w 2 -k uvicorn.workers.UvicornWorker --log-level debug
여전히 해당 에러가 났다. 아무래도 위의 방법으로는 여전히 ASGI에서는 lifespan 프로토콜을 실행하려고 하고, django에서는 이를 지원하지 않는 것 같았다. 사실 ASGI에서 lifespan 프로토콜을 실행하게 두는 것이 맞는 것인지, 아니면 django에서 이를 막도록 하는 게 맞는 것인지는 잘 모르겠다.
아무래도 명령어가 듣지 않는 것 같아서, 아까 추가했던 '--lifespan off' 명령어를 uvicorn 명령어 중간에 배치해두었다. 이러면 gunicorn이 아니라 uvicorn 명령어로 인식하겠지? 라는 마음에서였다.
그랬더니 깃헙 워크플로우가 시작도 못 하고 실패했다. 심지어 상세보기를 누르고 싶어도 그냥 fail 이라고만 나왔다. 그래서 debug 모드를 킨 다음에 다시 실행했다. 그랬더니 성공했다..! 대체 뭘까..?
여전히 서버는 '상태 확인 중'이다... 일이 꼬여버릴 줄은 몰랐다. 적어도 내일까지는 이 문제를 해결해서 부하 테스트를 해 보고 싶다. 그래야 다른 과제들도 차차 해볼 수 있겠다.
✅ 궁금한 점
1. 적합한 worker의 수는 어떻게 짐작해서 알 수 있을까?
2. 워크플로우가 실패했다고 항상 롤백되는 것은 아니라서 신기했다. 별도의 기준이 있을까?
3. 'python manage.py runserver' 명령어를 gunicorn, uvicorn을 사용하도록 바꾼 것밖에 없는데 로드밸런서의 헬스체크는 왜 실패하는 걸까? 이유가 궁금하다.