아스

✅ 오늘 배운 것

여전히 배포 실패 이슈가 이어지고 있다! 이제 왜 로드밸런서의 헬스체크가 실패하는지는 알았는데, 어떻게 해야 성공시킬지를 잘 모르겠다.

생각해보면 지금 문제상황은 'python manage.py runserver'로 잘 돌아가던 서버의 명령어를 gunicorn, uvicorn을 사용하도록 바꾸기만 했을 뿐인데 배포가 안 되는 거였다. 그러면 이럴 경우에는 로컬호스트에서 서버를 띄워도 뭔가 확인 가능하지 않을까? 싶어서 로컬에서도 같은 gunicorn 명령어로 서버를 실행시켜 보았다. 

로컬에서 Dockerfile의 명령어를 실행시키고, 로드밸런서에 등록한 엔드포인트로 도메인만 localhost로 바꿔서 요청을 보냈는데, 브라우저에는 응답이 잘 나오는데 로그에는 원하는 것처럼 200 반응이 뜨질 않았다. 그래서 AWS 로그를 볼 때도 이 서버가 요청을 제대로 받고 있는건지 모호했다. 

알고보니 uvicorn에 'access-logfile' 이라는 커맨드를 추가해야 HTTP 로그에 대한 기록을 추가로 남길 수 있었다. 설정을 추가해 주니 요청에 대한 HTTP 로그도 볼 수 있었다. 이러면 이제 AWS에서 태스크가 실행될 때 로드밸런서가 해당 태스크 안의 컨테이너에 어떤 HTTP 요청을 보내고 있는지도 볼 수 있겠다. 

그런데 좀 걸리는 점이 있다. 보통 8000번 포트에서 장고 서버가 실행되는 걸로 알고 있는데, 49735번 포트였다..! 혹시 로드밸런서는 계속 8000번 포트로 요청을 보내고 있는데 막상 gunicorn으로 시작된 서버는 다른 포트에서 시작하고 있었던 건 아닐까? 라는 생각도 들었다. 하지만 응답은 잘 오는데, 무슨 상황일까?

다행히 로그를 자세히 보니 8000번 포트에서 listening을 하고 있는 건 맞았다. 

다음과 같이 명령어를 입력해주고 다시 develop 브랜치에 해당 내용을 올려보았다. 

gunicorn onestep_be.asgi:application --timeout 300 -w 2 -k uvicorn.workers.UvicornWorker --log-level debug --access-logfile -

그런데 여전히 서버로 접속이 안 되었다. 워크플로우는 일단 서버가 성공적으로 배포가 되었으면, 그 이후에 헬스체크나 기타 설정에 상관 없이 성공하도록 wait-for-service-stability 설정을 바꿔 두었으니 성공하긴 했다. 문제는 로드밸런서의 헬스체크가 또 fail이 났다는 것이었다. 

의심되는 부분은 과연 올바른 포트에 요청을 보내고 있는지였다. 왜냐하면 앞서 access-logfile 이라는 커맨드를 추가해서 HTTP 요청이 왔다면 로그가 남아있어야 하는데, 요청을 받았다는 로그 자체가 없었기 때문이다. 그래서 헬스체크가 fail이 된 것이라고 생각되었다. 

GPT가 제시한 내용들을 봐도 감이 잘 잡히지 않았다. 제시한 내용들 중에는 '올바른 경로로 요청을 보내는지 확인해라', '태스크가 실패한 원인을 확인해라' 등의 내용이 있었는데, 이미 로컬에서 서버를 돌렸을 때는 올바른 경로로 200 응답을 잘 리턴하고 있었고, 태스크가 실패한 원인은 확인해봤더니 내가 아는 "Health check failed" 였기 때문이다. 

어떤 단서라도 나오려나 싶어 CloudWatch에서 좀 더 자세한 실행 로그를 살펴보았다. 그랬더니 이런 문장이 눈에 띄었다. 

찾아보니 이 설정은 "gunicorn이 어떤 IP의 요청으로부터 'X-forwarded-for' 이라는 헤더값을 신뢰할지" 를 결정하는 값이라고 했다. 그런가보다 하려다가, 'allow_ips' 라는 부분에서 혹시 이 gunicorn 서버가 외부 요청을 허용하지 않는 건 아닐까? 라는 의심이 들었다. 

그 결과 'bind' 라는 부분에서 할당된 값이 '127.0.0.1:8000' 밖에 없다는 사실을 알았다. 즉 이 상황에서면 WAS 서버는 자기 자신과 같은 localhost가 아닌 외부에서 보낸 요청을 받지 않고 있다는 말이 되겠다. 로드밸런서야 당연히 해당 서버와는 또 다른 원격에서 실행되고 있기 때문에, 이거라면 접속이 안 되었던 이유가 설명이 되었다. 

명령어를 다음과 같이, '--bind 0.0.0.0:8000' 부분을 추가해서 모든 외부 IP에서의 요청을 다 받도록 설정했다. 그 다음에 다시 워크플로우를 실행시켜 주었다. 

gunicorn onestep_be.asgi:application --bind 0.0.0.0:8000 --timeout 300 -w 2 -k uvicorn.workers.UvicornWorker --log-level debug --access-logfile -

그랬더니 서버가 실행되었다!!

혹시나 싶어 ECS의 태스크가 최신 태스크 정의를 반영하고 있는지도 확인해봤다. 최신 태스크 정의를 반영하고 있었다! 그 말은 gunicorn, uvicorn을 통해서 django WAS가 정상적으로 동작하고 있다는 뜻이었다. 

이제 진짜 진짜로 locust를 통해 부하 테스트를 해볼 수 있겠다. 

그런데 또 뭔가 이상했다..! gunicorn으로 worker를 2개를 띄웠고, gunicorn으로 시작한 서버에서 로그가 잘 찍히고 있는 것도 확인했다. 그런데 테스트의 RPS(request per second) 지표가 영 시원찮았다. 테스트에서는 우선은 DB에 영향이 가지 않는 단순 조회 API만 사용하였다. 

20명의 동시 접속자(유저)를 가정했을 때 RPS가 약 30 정도였다. 이 정도 수치면 예전과 거의 차이가 없었다.

뭐지 싶어서 ECS 서비스의 CPU 사용률을 보았는데 CPU가 과로를 하다 못해 죽기 직전이었다. 식겁해서 돌리던 테스트를 일단 종료시켰다. 

이런 경우는 어떻게 하면 좋을까? 애초에 우리 서버의 상태로는 RPS 1000이 무리였던 것일까? 아니면 위처럼 확인은 해 봤는데 설마 아직 gunicorn에서 2개의 worker가 서비스를 처리하고 있지는 않은 건가? 라는 생각도 들고... 일단 이 부분은 멘토님께 추가적인 조언을 구해보고 개선할 방법을 찾아봐야겠다. 일단은 아주 잠깐동안 보류해 보자!

그럼 다른 이슈를 해야 하나 싶어서 지라 이슈를 보니, SZ-243의 하위 이슈로 지금 당장 할 수 있는 것들이 남아있었다. 사실 여기에 1시간 정도를 쓴 터라 이제 다른 걸로 context switching을 하고 싶었는데 어림도 없다. 이거 먼저 해결하고 다른 것들을 하러 가보자. 

우선은 매번 워크플로우 yaml 파일의 큰 용량을 차지했던 ECS의 '태스크 정의'용으로 매번 만들던 json 파일을 yaml 파일을 통해 만드는 부분을 개선해야 하겠다. 기존 방법 대신에, json 파일의 껍데기는 만들어 두자. 그리고 그 안의 환경변수와 관련된 내용은 동적으로 yaml 파일이 실행될 때 파이썬 스크립트를 통해 해당 파일 안에 넣어주도록 해 보자. 

우선 위의 이슈는 계속 배포와 관련된 부분을 다루다보니 develop 브랜치에서 임시로 작업했었다. (사실 이게 바람직한 방법이 아닌 걸 알긴 하는데, 그럼 이렇게 사소한 변경을 하고 그 변경된 결과를 배포 서버에서 확인하고... 등의 작업을 할 때는 어떻게 해야 할까? 매번 PR 날리는 게 번거로워서 이 방법을 쓰고 있는데 그럼에도 PR을 매번 날리는 것이 옳은 방법인지 궁금하다.)

기존에는 'git pull origin develop'으로 매번 develop의 내용을 당겨 왔는데, 이제부터는 더 권장되는 방법인 git rebase를 사용해 보자. 다행히 큰 conflict 없이 develop 브랜치의 커밋들을 SZ-243 브랜치의 앞에 배치할 수 있었다. 

git checkout SZ-243
git rebase develop

그런데 GPT가 제시한 방법은 로컬의 .env 파일에서 값을 가져와서 json 파일에 넣어주는 방식이었다. 그런데 이렇게 하면 모두가 이미 Github Secrets에 저장되어 있는 값을 굳이 .env 파일에 한번 더 저장해야 해서 번거롭다고 느껴졌다. 하지만 제시해 준 예제 코드를 보면서 어떻게 해야 할지 조금이나마 감은 잡았다. 

우선 현재 yaml 파일에서 사용하고 있는 템플릿을 그대로 가져오자. 그리고 ecs-task.json 이라는 이름으로 프로젝트의 루트 디렉토리에 빈 템플릿용 json 파일을 만들어주었다. 

그리고 render_ecs_task_definition.py 라는 파이썬 파일을 하나 만든다. 이때 로컬 .env 파일의 값은 가져올 수 없으므로, 파이썬 커맨드에서 필요한 Github Secrets 값을 인자로 받아 주어야 하겠다. 여기서 필요한 값들은 다음과 같았다: 

AWS_ACCOUNT_ID, AWS_REGION, ECR_REPOSITORY_NAME, AWS_SECRET_NAME, AWS_ACCESS_KEY_ID, AWS_SECRET_ACCESS_KEY, AWS_SECRET_NAME_PROD.

다음과 같은 파일을 만들었다. 코드에서는 파일을 실행시킬 때 파라미터로 Github Secrets 값들 중 필요한 값을 넘겨받은 뒤, 그 값을 딕셔너리 형태로 변환한다. 이후 딕셔너리 형태의 키-값 맵을 이용해서 변환해야 하는 값(키)이 나오면 키-값 맵의 값으로 교체해주는 작업을 해 준다. 

import argparse
import json


def replace_ecs_task_definition():

    with open('ecs-task.json', 'r') as file:
        task_definition = json.load(file)

    parser = argparse.ArgumentParser()
    parser.add_argument("--aws_account_id", type=str)
    parser.add_argument("--aws_region", type=str)
    parser.add_argument("--ecr_repository_name", type=str)
    parser.add_argument("--aws_secret_name", type=str)
    parser.add_argument("--aws_access_key_id", type=str)
    parser.add_argument("--aws_secret_access_key", type=str)
    parser.add_argument("--aws_secret_name_prod", type=str)
    args = parser.parse_args()

    global key_map
    key_map = {
        "AWS_ACCOUNT_ID": args.aws_account_id,
        "AWS_REGION": args.aws_region,
        "ECR_REPOSITORY_NAME": args.ecr_repository,
        "AWS_SECRET_NAME": args.aws_secret_name,
        "AWS_ACCESS_KEY_ID": args.aws_access_key_id,
        "AWS_SECRET_ACCESS_KEY": args.aws_secret_access_key,
        "AWS_SECRET_NAME_PROD": args.aws_secret_name_prod,
    }
    

    def render_ecs_task_definition(obj):
        global args        
        if isinstance(obj, dict):
            return {k: render_ecs_task_definition(v) for k, v in obj.items()}
        elif isinstance(obj, list):
            return [render_ecs_task_definition(v) for v in obj]
        elif isinstance(obj, str) and obj.startswith("${") and obj.endswith("}"):
            env_var = obj.strip()[9:-1] # remove ${secrets.} from string
            return key_map.get(env_var)
        return obj

    task_definition = render_ecs_task_definition(task_definition)
    with open('ecs-task.json', 'w') as file:
            json.dump(task_definition, file, indent=2)


if __name__ == "__main__":
    replace_ecs_task_definition()

나머지는 이따가 시간이 나면 더 처리해 보겠다.

✅ 궁금한 점

1. 8000번 포트에서 gunicorn으로 시작한 장고 WAS가 listening을 하고 있다고는 나왔는데 막상 로그에는 49735번 포트와 관련된 내용이 찍혔다. 이유가 궁금하다. 

✅ 오늘의 시간표

+ 결국 다 못 끝냈다...! 나머지는 내일 더 해보자

✅ 오늘 배운 것

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을 사용하도록 바꾼 것밖에 없는데 로드밸런서의 헬스체크는 왜 실패하는 걸까? 이유가 궁금하다. 

✅ 오늘의 시간표 (예정)

✅ 오늘 배운 것

오늘은 발표 준비를 한 것 말고는 한 게 없다! 내일이 중간발표이니, 오늘까지 더 힘내서 발표 준비를 하고 내일 후련하게 잘 마쳤으면 좋겠다. 

✅ 오늘의 시간표

✅ 오늘 배운 것

오늘은 대부분 발표 준비를 하면서 시간을 쓸 예정이다. 개발과 발표 준비는 엄연히 다른 업무라 개발만 하다가 갑자기 또 발표를 위한 준비 모드로 전환하는 것은 개발자 입장에서 엄청 하고 싶은 업무도 아닐뿐더러, context switching 비용도 꽤 드는 것 같다. 다행히 발표가 가장 빠른 목요일(심지어 오전)이니, 조금만 더 발표 준비에 집중해 보자. 

원래는 모든 시간을 그렇게 쓰려고 했었는데, 어제 문제였던 이슈를 처리하고 반영하던 과정에서 또 다른 문제가 생겼다. 어제 이슈를 처리하기 위해서 프론트와 백엔드 코드를 모두 로컬에서 수정했다. 이제 이걸 반영해야 하는데, 깃허브 워크플로우가 실패해서 이전 버전으로 태스크가 롤백되고 있었다(이 문제는 저번에 ECS 서비스의 이벤트 로그를 보면서 파악한 그 패턴과 똑같았다). 

어제의 문제를 해결하고 develop 브랜치에 PR을 올려두었는데, 이 PR을 개발서버에 반영하기 위해서는 워크플로우가 성공적으로 실행되어야 했다. 

그런데 사실 워크플로우가 실패하는 이유는 알고 있었다. 다른 이슈에서 API 부하 테스트를 하면서 서버 성능을 개선하기 위해서 uvicorn과 gunicorn 명령어로 서버를 실행시키고 있었는데, 어떤 부분에서 설정이 잘못된 것인지 waiter(이 친구의 정확한 정체는 모른다)에서 timeout 문제가 난 것으로 추측하고 있다. 

서버 부하 테스트는 사실상 중간평가가 끝나고 목요일에 작업할 수 있을 것 같았다. 그래서 임시로 Dockerfile의 서버 실행 명령어를 python manage.py runserver로 바꿔주었다. 그랬더니 임시방편이지만 워크플로우는 일단 잘 반영되었다. 

✅ 오늘의 시간표

✅ 오늘 배운 것

axios 인스턴스에 대해서는 어제 axios interceptor를 사용해서 401 AxiosError가 발생했을 경우 액세스토큰 갱신 API를 호출하고, 해당 리프레시 토큰으로 액세스토큰을 갱신시키는 로직을 추가해 두었었다. 

그런데 오늘 다시 로그를 보니 여전히 401 에러(어제는 400 에러도 중간에 섞여 있었는데 오늘은 401 에러만 나온다)가 나왔다. 

알고보니 리프레시 토큰이 만료된 경우는 액세스 토큰을 갱신하려고 해도 갱신할 수 없었다. 혹시나 해서 API 서버의 리프레시 토큰의 만료일자를 찾아보니 1일로 되어있었다. 그래서 어제는 400 에러가 나왔는데 오늘은 401 에러가 나왔을 수 있겠다. 

그렇다면 만약 액세스토큰을 갱신하려고 시도했을 때도 401 AxiosError가 난다면, 이를 리프레시 토큰 만료 에러로 간주하고 강제로 로그인 페이지로 리디렉션 시켜야 하겠다. 우리 프로젝트에서는 expo router를 사용하고 있어서, 다음 코드를 추가해 주었다. 

router.replace('(tabs)');

그런데도 여전히 에러에 의해 무한루프가 발생했다. 

알고보니 로그인 페이지로 리다이렉션 하면서 axios의 interceptor 로직을 return문 등으로 빠져나온 것도 아니기 때문에, 해당 401 에러에서 또 다시 renew API로 요청을 보내면서 위 과정이 반복되는 것이었다. 이걸 막으려면 단순히 로그인 페이지로 리다이렉션 시키는 것뿐만 아니라 추가적인 처리가 필요하겠다. 

만약 refresh API를 요청하다 401 오류가 난 경우, 액세스토큰과 리프레시 토큰을 지운 다음 로그인 페이지로 리다이렉션 시켰다. 

if (originalRequest.url === API_PATH.renew) {
  await AsyncStorage.removeItem('accessToken');
  await AsyncStorage.removeItem('refreshToken');
  router.replace('(tabs)');
  return Promise.reject(error);
}

그런데 여전히 반복적인 오류가 난다. 이번에는 로그인 페이지에서 혹시 액세스나 리프레시 토큰의 유무에 관계없이 투두 리스트 뷰로 접근을 시도하는 것은 아닌지 확인해 보았다. 

로그인 페이지에서 컴포넌트의 리렌더링마다 시행되는 로직들, 즉 useEffect 훅 안에 정의된 함수들은 뭐가 있는지를 보았다. 'handleToken'과 'handleLocalToken' 이라는 함수들이 useEffect 안에 정의되어 있었다. 공식문서에서 useEffect의 정의를 찾아보니 컴포넌트를 외부 요소들과 동기화하고 싶을 때 사용하는 훅이라고 했다. 

내가 그런 심오한 작업을 위해 useEffect를 사용하고 있나? 라는 의문이 들어서 handleLocalToken과 handleToken의 로직들을 보았다. handleLocalToken의 경우는 비동기 저장소 AsyncStorage에서 유저 정보 및 토큰들의 값을 가져오고 있었으므로 일종의 외부 시스템과 컴포넌트를 동기화시키는 작업이었다. 

const handleLocalToken = async () => {
  const token = await getAccessTokenFromLocal();
  const user = await getUserInfoFromLocal();
  api.verifyToken(token);
  setAccessToken(token);
  setUserId(user.userId);
  router.replace('(tabs)');
};

또한 handleToken의 경우도 외부 API를 호출하여 유저의 정보를 받아오고, 그 정보를 AsyncStorage에 저장하면서 외부 시스템과 통신하고 있었다. 

const handleToken = useCallback(async () => {
  if (response?.type === 'success') {
    const token = response.authentication?.idToken;
    if (token) {
      await getToken({ token });
      const user = await api.getUserInfo();

      await AsyncStorage.setItem('userId', user.id.toString());
      await AsyncStorage.setItem('userName', user.username);
      setUserId(user.id);
      router.replace('(tabs)');
    }
  }
}, [response, setUserId, getToken, api]);

그리고 쓰다보니 내가 위에서 router.replace()의 값으로 잘못된 주소를 할당했다는 것을 알았다. 나는 로그인 화면으로 돌아가고 싶었는데, 해당 파일의 이름은 'index.jsx'였기 때문에 router.replace()의 값으로 공백 문자열을 넘겨줘야 했다. 이 부분을 수정하고 다시 앱을 실행해 보았다. 

그랬더니 이번에는 투두 뷰에서만 무한루프가 일어났던 것과 달리 로그인 뷰와 투두 뷰를 오가면서 어떠한 로직이 무한루프로 실행되고 있었다. 로그인 페이지에서 계속해서 투두 뷰로 이동하기 위해 토큰을 체크하는 로직을 호출하는 부분이 의심이 갔다. 그러지 않고서야 가만히 로그인 페이지에 유저가 머물러 있어야 하기 때문이다. 

앞서 언급한 로그인 페이지에서 useEffect() 안에 정의된 두 함수는 handleLocalToken, handleToken 이었다. 찾아보니 두 함수 모두 API를 호출하고 있었다. 다만 handleToken은 if문을 통해서 구글로그인 버튼을 눌러서 로그인의 결과로 구글에서 발급하는 idToken 값이 있어야만 추가 로직을 처리하고 있었기 때문에, 구글로그인 버튼을 누르지 않는다면 API를 호출하지 않는다. 

그렇다면 handleLocalToken 로직을 봐야 하겠다. 여기서는 현재 가진 액세스토큰이 유효한지를 인증 API를 호출함으로써 확인하고 있었다. 이 부분이 문제라고 판단했다. 왜냐하면 로컬의 AsyncStorage에서 토큰과 유저 정보를 가져오는 것 까지는 괜찮은데, 최소한 해당 정보가 있어야 그 정보를 가지고 API를 호출하는 것이 맞기 때문이다. 그런데 현재 로직에서는 그런 정보가 있는지 확인하는 절차 없이 바로 토큰이 유효한지 인증하는 API를 호출하고 있었다. 

우선 현재 로그인 뷰<->투두 뷰 사이에서 무한루프를 도는 상황에서, handleLocalToken 안에 있는 token과 user의 값을 찍어보았다. 

현재는 리프레시 토큰이 만료되어서 액세스토큰과 리프레시 토큰의 값은 지워진 상태이다. 그런데 원칙상 유저가 현재 로그인되어 있지 않으니 AsyncStorage에는 유저의 값도 없어야 하는 것이 맞다. 그런데 유저의 값은 저장되어 있었다. 

리프레시 토큰 만료 시, AsyncStorage에 저장되어 있는 토큰 값뿐만 아니라 유저의 값도 지워주는 코드를 추가해주었다. 이제 리프레시토큰이 만료되어서 로그인이 실패한 경우 모든 값이 null로 잘 나온다. 

이제 적어도 AsyncStorage에 관련 토큰이나 유저 값이 있을 때만 verify API로 토큰이 유효한지 조회하도록 로직을 조금 수정해보았다. (기존에는 if문과 try/catch문이 없었다) 

if (token && user.userId) {
  try {
    api.verifyToken(token);
    setAccessToken(token);
    setUserId(user.userId);
    router.replace('(tabs)');
  } catch (e) {
    Sentry.captureException(e);
  }
}

그리고 AsyncStorage.setItem()으로 토큰값을 바꿔줄 때는 해당 컴포넌트에서 사용 중인 싱글톤 Api 객체의 토큰값도 바꿔 주었다. 그러기 위해서 setter 메소드를 Api 클래스에 추가해주었다. 

setAccessToken(newAccessToken) {
  this.accessToken = newAccessToken;
}

setRefreshToken(newRefreshToken) {
  this.refreshToken = newRefreshToken;
}

이렇게 했더니 앞서 언급한 '로그인 뷰와 투두 뷰를 계속 오가면서 무한루프가 일어나는 문제'는 해결되었다. 그런데 이제는 구글로그인이 성공적으로 실행되어도 투두 뷰로 이동하지 않는 문제가 발생했다. 

로그를 찍어보니, 구글로그인이 성공적으로 진행되고 나서 handleToken 함수 내부에서 유저 정보를 불러오는 API를 호출할 때 액세스 토큰값이 최신값으로 반영되지 않아서 401 AxiosError가 나는 것 같았다. 그래서 다시 로그인 페이지로 돌아오는 것으로 보였다. 

왜 토큰값이 최신값으로 반영되지 않을까 알아보기 위해서, handleToken 함수 내부에서 유저 정보를 불러오는 API 호출 전에 실행되는 'getToken' 함수를 보았다. 이 함수에서는 구글로그인으로 받아온 idToken의 값을 서버의 특정 API를 호출하여 API 서버와 통신할 때 사용할 수 있는 JWT 토큰으로 바꾸는 작업을 했다.

이 API의 실행 로직 관련해서 로그를 찍어 보았더니 400 AxiosError가 나오고 있었다. 즉 여기서 400 에러가 리턴되어서 AsyncStorage에 저장된 액세스토큰의 값이 최신값으로 반영되지 않았고, 그래서 이후에 유저 정보를 받아오는 API에서 401 에러가 호출되는 것이었다. 

무엇이 잘못되었을까? api 호출 로직의 내부를 보았다. 서버에서는 '400 Bad Request'라는 응답만 내려줄 뿐, 무엇 때문에 400 에러가 났는지는 알 수 없었다. (어서 빨리 Fargate를 EC2로 바꿔야 하는 이유 중 하나이기도 하다...) 아무튼 그래서 임시방편으로 develop 브랜치 상태인 로컬 서버를 실행시킨 다음 해당 로컬 서버로 API 요청을 보내보았다. 

그랬더니 구글로그인 API에서 401 Unauthorized 에러가 나고 있었다. 이해할 수 없는 에러였다. 왜냐하면 구글로그인 API는 토큰값과 디바이스 토큰값만 제대로 보낸다면 클라이언트에서 액세스토큰 없이도 접근 가능해야 하는 API였기 때문이다. 개발서버에서도 똑같은 패턴의 에러가 나고 있었다. 즉 400 에러는 구글로그인 API가 아니라 토큰 갱신(refresh) API에서 토큰값이 null로 되어있기 때문에 나는 에러로 보였다. 

가능한 원인들은 여러 가지였다. 예를 들면 해당 구글로그인 API에서는 파이썬에서 사용 가능한 google.oauth 라이브러리를 사용해서 앞서 프론트에서 구글로그인을 통해 받은 idToken을 인증한다. 이때 401 에러가 났을 가능성도 있다. 이 경우에는 프론트에서 사용하는 GOOGLE_CLIENT_ID의 값과 백엔드에서 사용하는 GOOGLE_CLIENT_ID의 값이 같은지 확인해야 되겠다. 

그런데 이 원인 때문은 아니었다. API가 호출되는 시점에 로그를 찍고 있었는데, 그 로그조차 호출되지 않으니 아예 요청이 거부가 되는 것이었다. 미들웨어 단에서 무언가가 요청을 거부한다고 추측했다. 내가 현재 아는 요청을 거부할만한 미들웨어는 DRF의 미들웨어가 있었으니, settings.py에 DRF 설정을 추가해서 기본 permission을 AllowAny로 변경해주었다. 

# settings.py
REST_FRAMEWORK = {
    # 기존 내용
    'DEFAULT_PERMISSION_CLASSES': [
        'rest_framework.permissions.AllowAny',
    ],
}

여전히 API 호출 시점에 로그가 찍히지 않아서 이 문제도 아니었다. 해당 코드는 원래대로 돌려놓았다.

즉 DRF 기본 미들웨어가 아닌 다른 미들웨어에서 요청을 막고 있을 가능성도 있다. 현재 사용 중인 미들웨어는 다음과 같았다. 

# settings.py
MIDDLEWARE = [
    "corsheaders.middleware.CorsMiddleware",
    "django.middleware.security.SecurityMiddleware",
    "django.contrib.sessions.middleware.SessionMiddleware",
    "django.middleware.common.CommonMiddleware",
    "django.middleware.csrf.CsrfViewMiddleware",
    "django.contrib.auth.middleware.AuthenticationMiddleware",
    "django.contrib.messages.middleware.MessageMiddleware",
    "django.middleware.clickjacking.XFrameOptionsMiddleware",
    "allauth.account.middleware.AccountMiddleware",
    "djangorestframework_camel_case.middleware.CamelCaseMiddleWare",
]

또한 DRF에서 사용하는 기본 인증 클래스(default authenticationn classes)의 값으로 설정해 준 authentication backend에서도 미들웨어로 요청을 가로챌 수 있기에, 이 부분도 고려해야 하겠다. 

# settings.py
REST_FRAMEWORK = {
    # 다른 내용
    "DEFAULT_AUTHENTICATION_CLASSES": (
        "rest_framework_simplejwt.authentication.JWTAuthentication",
    ),
}

현재 미들웨어 중 고려해볼 만한 것들은 다음과 같겠다. 

1. allauth 라이브러리의 AccountMiddleware

2. django에서 기본으로 제공하는 AuthenticationMiddleware

3. django에서 기본으로 제공하는 SessionMiddleware

4. 기본 인증 클래스로 정의된 JwtAuthentication(Middleware)

이 중에서 1번은 사실상 allauth 라이브러리가 설치는 되어있지만 코드에서 직접 사용하지 않았고, 2번과 3번은 장고에서 기본으로 제공하는 미들웨어라서 처음부터 정의되어 있었는데 어느 시점까지는 잘 동작했다. 즉 갑자기 동작을 바꿀 가능성은 거의 없다. 따라서 이 중에서 4번에 문제가 있겠다고 생각했다. 

우선은 1번 라이브러리의 dependency를 제거하기 위해서 middleware 변수에서 해당 부분을 빼고 실행해 보았다. 그랬더니 에러가 났다. allauth 라이브러리를 사용하는 상황에서 AccountMiddleware를 빼면 안 되나보다. 

사실 원칙상 사용하지 않는 라이브러리는 uninstall하고 dependency에서 지우는 게 맞다. 그런데 이걸 지우다가 무슨 에러가 날지도 모르기에, 일단은 덮어두기로 했다. 아니면 사실 allauth는 장고 소셜로그인에서 가장 많이 사용되는 라이브러리이니 simplejwt 라이브러리 대신 allauth를 사용해서 JWT 소셜로그인을 사용해도 되긴 하다(사실 이게 젤 바람직한 방법이다). 

그러나 지금은 일단은 '정상적으로 동작하는 배포'가 급해서, 이 문제를 지라 백로그에 일단 기록해둔 다음 중간평가 끝나고 처리해두기로 했다. 

그래서 이 부분은 그대로 두고, 다른 문제 후보인 JwtAuthenticationMiddleware의 동작 코드를 보면서 로그를 좀 찍어보았다. 다행히 해당 미들웨어의 authenticate 메소드까지는 호출이 되고 있었다. 구글로그인 API를 호출할 때에는 Bearer 토큰값이 null인 것이 당연한 거라서, 해당 부분에는 문제가 없다. 그런데 사실 그 밑에 추가로 로그를 찍어 놓았었는데, 그 부분까지는 도달하지 못한 것으로 보였다. 

혹시나 해당 미들웨어(메소드)에서 none을 리턴해서 401 에러가 날 가능성도 생각해야 했다. 그러나 구글로그인 API는 토큰을 넣을 수가 없는 API이기에, 특정 API에 대해서 해당 미들웨어를 우회하는 방법을 찾아보았다. 알고보니 APIView의 필드값으로 authentication_classes의 값을 빈 배열로 설정하면, 해당 뷰에 대해서는 인증 미들웨어를 우회할 수 있었다. 

그랬더니 구글로그인을 무사히 통과하여 투두 뷰 화면이 나왔다!

✅ 궁금한 점

1. axios 인스턴스를 create할 때 timeout 설정이 있다. 이게 정확히 뭘 의미하는건지 궁금하다. 

2. expo router과 react의 navigation의 차이가 궁금하다. 

3. router의 원리도 새삼스럽지만 갑자기 궁금해졌다. 

4. 왜 안드로이드에서는 자바를 사용해서 빌드를(컴파일인지 빌드인지 모르겠다... 암튼) 진행할까? 소스 코드가 자바로 되어 있다는 건 아는데 왜 자바 말고 다른 언어로는 아예 실행할 수 없는 것인지도 궁금하다. 

5. LocalStorage와 AsyncStorage의 차이가 무엇일까?

6. useCallback의 원리가 잘 이해되지 않는다. 함수를 캐싱한다는 것이 무슨 의미일까? 그리고 그게 앱의 성능에 유의미한 영향을 줄 정도로 중요한가? 라는 의문이 든다. 

7. permission_classes와 authentication_classes의 의미 차이가 궁금하다. 인증과 인가의 차이일까?

✅ 오늘 배운 것

저번에 멘토님께 피드백을 받은 대로 Context API에 액세스토큰 값을 넣어두는 대신 Api 클래스를 싱글톤 패턴으로 만들고, 해당 클래스의 메소드를 사용하도록 컴포넌트 내부의 코드들도 수정해주었다. 그런데도 여전히 401 AxiosError가 발생하고 있었다. 

해당 에러를 수정해야 무사히 PR을 하고 잘 동작하는 앱 화면을 볼 수 있기에, 여기에 달려있는 dependency가 많다고 느껴져서 이 일을 급하다고 판단했다. 

현재 Api 클래스의 일부 코드는 다음과 같다. 여기서 핵심은 request 메소드에서 this.accessToken으로 Api 싱글톤 클래스가 갖고 있는 토큰값을 넣어주고, 에러가 날 경우 Sentry에 로그를 남긴 뒤 해당 에러가 액세스토큰이 만료되어 발생하는 401 AxiosError라면 액세스토큰을 갱신시키고 다시 시도하는 로직이다. 

class Api {

  // 싱글톤 패턴으로 구현

  async request(url, options) {
    try {
      const response = await axios.request(url, {
        ...options,
        'Content-Type': 'application/json',
        Authorization: `Bearer ${this.accessToken}`,
      });
      return response.data;
    } catch (e) {
      Sentry.captureException(e);
      if (axios.isAxiosError(e)) {
        if (
          (e.response.status === 401 &&
            e.response.data.detail === TOKEN_INVALID_OR_EXPIRED_MESSAGE) ||
          e.response.data.detail === TOKEN_INVALID_TYPE_MESSAGE
        ) {
          // access token 재발급
          const responseData = await axios.post(API_PATH.renew, {
            refresh: this.refreshToken,
            access: this.accessToken,
          });
          const newAccessToken = responseData.data.access;
          await AsyncStorage.setItem('accessToken', newAccessToken);
          this.accessToken = newAccessToken;

          // 다시 요청
          return axios.request(url, {
            ...options,
            'Content-Type': 'application/json',
            Authorization: `Bearer ${this.accessToken}`,
          });
        }
      }
    }
  }

  fetchTodos(userId) {
    return this.request(`${API_PATH.todos}?user_id=${userId}`, {
      method: 'GET',
    });
  }

  // 다른 투두 메소드들
  
}

export default Api;

그런데 로그를 찍어보니 401 AxiosError가 발생하였다고 콘솔에는 나오는데 catch 문에서 해당 에러를 못 잡고 있었다. 대신 콘솔에서는 react query의 useQuery 메소드에서 에러가 호출되고 있었다. 내가 원하는 건 useQuery에러 에러를 캐치하기 전에 위의 request 메소드에서 에러를 먼저 캐치하고, 액세스토큰 관련 에러일 경우 에러가 나지 않도록 액세스토큰을 갱신하는 것이었다. 

질문을 통해 얻은 해결 방법은 axios의 interceptor 기능을 사용하는 것이었다. 제시된 다른 해결방법 중에는 react query에서 axios 인스턴스를 직접 사용하거나 react query의 메소드(useQuery, useMutation)에서 onError 파라미터로 401 에러가 났을 때 그것을 처리하는 함수를 인자로 넘겨주는 방법도 있었다. 그러나 지금 하려는 작업은 API 서버로 보내는 모든 요청에 대해서 적용되어야 했기 때문에 이 방법들을 쓰면 각 API를 요청하는 코드를 일일이 수정해 주어야 해서 번거로웠다. 정말 신기했던 게 어제 멘토링을 하면서 멘토님도 axios의 interceptor 기능을 추천해주셨었다. 이 상황을 미리 내다보신 것일까? 신기했다. 

그런데 별도의 파일에 axios interceptor를 적용하고 그 axios 인스턴스를 import해서 사용하는 기존 방법은 기존에 만들었던 Api 싱글톤 인스턴스와는 별개로 동작하는 방법이었다. 나는 Api 싱글톤 인스턴스를 사용하면서, 그 안의 request 메소드에서 사용하는 axios 인스턴스에 interceptor를 적용하고 싶었다. 

적용하려는 두 가지 방법(Api 싱글톤 클래스, axios 인스턴스)은 별도의 문제였다. 즉 둘 다 같이 적용할 수 있었다. Api 싱글톤 클래스 안에 axios 인스턴스를 만들고, 그 인스턴스에 대해 interceptor 기능을 적용하면 되는 문제였다. 

그랬더니 이번에는 401 대신 400 AxiosError가 떴다. 이것은 클라이언트에서 요청을 뭔가 잘못 보내고 있는 문제이니, 로직을 수정해보면 될 것 같다. 

일단 콘솔로 로그를 찍어서(바람직하지 못한 방법이긴 하다... 중간평가 끝나고는 꼭 디버거를 써 봐야지) 에러 객체를 그대로 찍어봤다. 

인내심을 가지고 로그를 쭉 읽다 보니 응답 정보 쪽에 이런 메시지가 보였다. 

"_response": "{\"refresh\":[\"This field is required.\"]}"

해당 코드는 401 에러가 나서 토큰 갱신 API를 다시 호출하고 있는 로직에서 난 400 에러를 캡처한 부분이다. 즉 토큰 갱신 API를 통해 액세스토큰을 갱신하려면 파라미터로 리프레시 토큰을 넣어줘야 하는데, 그 부분이 빠져서 400에러가 난 것으로 보였다. 

✅ 오늘의 할 일 계획

계속 할 일이 많으니 심적 여유나 심리적 안전감이 떨어지는 느낌이다. 일을 안 하면 당연히 회복은 될 텐데 그런 방법은 일이 많을 때는 쓸 수가 없다. 이럴 때는 어떻게 해야 할까? 현재 생각나는 방법으로는 취미 활동을 중간에 30분씩이라도 끼워 넣으면서 중간중간 회복을 해 주는 방법인데, 다른 방법이 또 있을지도 찾아봐야겠다. 

✅ 오늘 배운 것

오늘은 개발적으로는 이슈 처리를 하지는 않았다. 왜냐하면 발표 대본을 써야 하고, 그 발표 대본이 있어야 다른 팀원이 PPT를 만들 수 있는 모종의 dependency가 걸려있는 상황이었기 때문이다. 오늘까지 발표 대본 및 보고서를 대부분 작성하고, 내일은 남은 이슈(SZ-243, SZ-215)를 처리한 다음, 스프링 사이드 프로젝트에도 1시간 정도만 써 봐야겠다. 

✅ 궁금한 점 / 개선점 / 논의할 점

1. 멘토님이 보여주신 공식문서를 보니 RN에서 디버거를 사용하는 방법에 대해서 자세히 나와있었다. 사실 다른 팀원이 이미 이 문제를 해결하고 있긴 한데, 나도 중간평가 끝나고 나서부터는 기능을 개발하고 테스트할 때 RN/React에서 디버거를 사용해야 더 쉽게 개발할 수 있어서 이 부분을 중간평가 끝나고 잘 배워봐야겠다. 

✅ 오늘의 할 일

오늘 할 일이 뭔가 매우 많은데 정리되어 있지는 않아서 얼레벌레 그냥 했다가는 일정이 지연될 것 같았다. 그래서 시간별로 할 일을 정리해보았다. 각 일정은 1시간 동안 처리하고, 쉬거나 조금 오버되거나 하는 식으로 시간을 더 쓸 수도 있을 것 같아서 각 일정 사이에는 30분의 쉬는 시간을 두었다. 

+ 현재 5시인데 아직 SZ-243번 이슈 못 끝냈다..! 역시 생각만큼 쉽지 않다. 

✅ 오늘 배운 것

첫 번째 일정부터 해결해 보자. 어제의 포스팅에 이어서 별도로 적지는 않았지만, 테스트 서버를 띄우기 위한 ECS, ECR, 대상그룹, 로드밸런서 등의 설정을 추가로 해 주어서 yaml 파일이 정상 동작한다는 가정 하에 테스트 서버가 뜰 수 있도록 설정을 해 놓았다. 이제는 이와 더불어 현재 장고 서버에서 사용하고 있는 DB 서버가 커넥션 풀링(connection pooling)을 사용하도록 장고 서버에서 설정을 바꾸어 주면 된다. 

까먹을까봐 정리해두면 커넥션 풀링(connection pooling)은 HTTP에서도 DB에서도 같은 개념으로 사용된다. 요청이 들어오면 해당 요청을 스레드(thread)로 처리하는데, 싱글 스레드를 사용할 경우 스레드를 재사용할 수 있지만 요청이 한꺼번에 많이 들어올 경우 대기열이 생기면서 응답 시간이 지연되거나 병목(bottleneck)이 생길 수 있다. 반면 요청이 들어올 때마다 새 스레드를 생성해서 요청을 처리하는 경우에는 응답 시간 지연이나 병목의 문제는 덜하겠지만 스레드를 생성하는 작업 자체도 오버헤드가 꽤 있는 작업인데 그렇게 만든 스레드를 요청 하나만 처리하고 버린다는 점에서 비효율적이다. 또한 사용자가 요청하는 대로 요청을 다 받기 때문에 자칫 잘못하면 서버가 감당할 수 없을 양의 스레드가 만들어져서 해당 스레드가 사용하는 메모리나 cpu를 서버가 감당할 수 없게 되어 서버가 다운될 수도 있다. 

커넥션 풀링은 이럴 때 사용한다고 알고 있다. 말 그대로 사전에 정의된 개수의 커넥션이나 스레드만 만들어 두고, 이를 커넥션 풀에 담아두고 요청이 들어오면 해당 커넥션을 사용하고, 요청을 처리한 후에는 다시 커넥션 풀에서 해당 커넥션을 대기시키는 것이다. 

이 설정을 DB에서 해 줘야 하는 거 아닌가 싶었는데 아닌가보다. 장고 서버에서 현재 서버가 사용하는 DB에서 지정한 수의 커넥션에 대해 커넥션 풀링을 하도록 해 주자. 

django-db-connection-pool 이라는 라이브러리를 사용하면 settings 파일에 설정 몇 줄을 추가하는 걸로 DB에서 커넥션 풀링을 하도록 바꿀 수 있다. 

pip install django-db-connection-pool

그리고 환경 파일(settings.py)에서 다음과 같이 설정하자. 기존의 ENGINE 값은 'django.db.backends.mysql'로 되어 있었는데 커넥션 풀링을 사용하기 위해서 바꿔주었다. 

DATABASES = {
    "default": {
        'ENGINE': 'dj_db_conn_pool.backends.mysql',
        # 다른 값들
    },
}

이렇게만 되어도 해당 DB에서 커넥션 풀링을 할 수 있다. 커넥션 풀에서 기본값으로 유지하는 커넥션 개수(POOL_SIZE)는 5개라고 하며, 이론상 설정할 수 있는 최댓값의 제한은 따로 없다고 한다. 또한 갑자기 요청이 몰릴 시에는 POOL_SIZE 값보다 많은 커넥션을 사용하기도 한다. 그러나 이럴 때라도 최대한으로 사용할 수 있는 커넥션 값의 제한(MAX_OVERFLOW)이 있다. 기본값은 10개로 설정되어 있다. 즉 기본으로 커넥션 풀에서는 5개까지의 커넥션을 사용하지만, 요청이 몰릴 경우는 최대 10개를 '추가로' 사용한다. 즉 커넥션 풀에서 최대로 사용할 수 있는 커넥션의 개수는 15(5+10)개가 되는 셈이다. 

그리고 깃헙 워크플로우가 초반에 오류 없이 실행되는 것을 확인하고 잠시 쉬었다가 다시 돌아왔다. 

그런데 그 시간 사이에 깃허브 워크플로우 에러가 발생해 있었다. 심지어 30분 동안 완료되지도 않고 실행되다가 오류가 난 상황이다. 

에러 로그의 'waiter'라는 말을 보아, worker처럼 작업을 실행하는 단위인가? 라는 추측을 했다. 만약 그렇다면 uvicorn과 gunicorn 관련 에러일 수도 있다고 생각했다. GPT에게도 물어보니, 작업을 기다리다가 timeout 에러가 뜬 것이라고 한다. 이럴 때는 timeout 시간을 더 길게 설정해 주거나, waiter(아마도 프로세스일 것이라고 생각한다)가 기다리고 있는 EC2나 다른 시스템이 제대로 동작하지 않아서 발생한 오류일 수 있겠다. 

혹시 추가적인 힌트를 얻을 수 있을까 싶어 AWS 콘솔에 들어가보았다. ECS 서비스의 이벤트 로그를 보니, 로드밸런서의 헬스체크가 fail이 나서 계속해서 기존 태스크에 커넥션 연결을 해제하고 새 태스크를 만들어서 또 시도하고... 이 작업을 반복하다가 fail 처리가 난 것 같았다. 

로드밸런서의 헬스체크 상태를 보니 fail이 떠 있었다. 중지된 태스크의 로그를 ECS에서 확인했을 때는, 'Application startup complete'와 'Waiting for application startup' 문구가 반복되어 나와서, 이게 서버가 잘 실행된 것인지 아니면 무언가를 기다리고 있는 것인지 파악하기 어려웠다. 

GPT에게 나름의 추론 문제를 낸 결과 서버는 잘 실행된 것 같다고 알려주었다. 중간에 뜨는 경고들은 서버의 실행에는 영향을 주지 않는 정도라고 했다. 

정황상 로드밸런서의 헬스체크가 fail 한 것은 맞아 보인다. 아직 이게 위에서 로그로 나온 "Waiter has timed out"과는 어떤 관련이 있는지는 잘 모르겠지만, 헬스체크가 fail해도 서버가 배포될 수 없는 것은 똑같으니 이 문제도 해결해야 한다고 생각했다. 

로드밸런서의 헬스체크는 대상그룹의 헬스체크 기준이 올바르게 설정되어 있다고만 해서 항상 성공하는 게 아니었고 여러 요소를 고려해야 했다. 그런데 아무리 봐도 개발 서버의 경우 도커파일의 실행 커맨드가 python manage.py runserver 대신 uvicorn과 gunicorn을 사용하도록 바꿔준 것밖에 없어서 이쪽 문제일 것이라는 의심이 들었다. 

관련이 있을 수도 있겠다! gunicorn과 uvicorn을 함께 사용하는 경우, 예를 들면 gunicorn이 uvicorn의 워커를 너무 일찍 타임아웃 처리하고 일찍 종료시킬 수도 있다고 한다. 이럴 때는 gunicorn과 uvicorn의 설정을 적절하게 변경해줘야 하겠다. 해당 문제와 관련있어 보이는 설정은 타임아웃과 워커 개수 설정이었는데, 워커 개수는 이전에 공식문서를 보고 4개로 맞춰주었으니 타임아웃 설정만 변경했다.

기존 커맨드에 --timeout 120 부분을 추가해서 uvicorn 워커가 2분 안에 요청을 처리하지 않으면 타임아웃 처리를 하도록 변경했다. 2분이 좀 긴 감이 있는데, 우선 2분으로 아예 길게 설정한 다음 만약 이 설정을 추가했더니 에러가 안 나면 추측대로 uvicorn 워커가 예상보다 빨리 timeout 되어서 깃허브 워크플로우가 fail한 것이 맞다. 이 추측이 맞는지 확인하고, 그 다음에 다시 적절한 값을 찾아서 timeout 설정값을 바꿔줄 계획이다. 

gunicorn onestep_be.asgi:application --timeout 120 -w 4 -k uvicorn.workers.UvicornWorker

잠시 백엔드 이슈가 막혀서 프론트 이슈로 Context Switching을 했다. SZ-215번, 기존에 액세스 토큰 갱신 로직을 작성하다가 커스텀 훅 관련 문제가 있었었다. 원래 커스텀 훅을 컴포넌트나 다른 커스텀 훅 내부 외에는 사용할 수 없는 것이 원칙인데. 그러다 보니 커스텀 훅을 사용하기 위해 연쇄적으로 커스텀 훅을 만들게 되는 문제가 있었다. 이 부분은 결국 커스텀 훅이 아니라 클래스를 사용하는 방향으로 가는 것이 맞다고 결론을 내렸었다. 

다만 해당 클래스를 싱글톤 패턴으로 구현해야 하겠다. 왜냐하면 애초에 만드려는 'Api' 클래스는 요청을 보내는 데 사용하는 객체라서 인스턴스가 여러 개일 필요가 없다. 또한 Api 클래스 안에는 액세스 토큰과 리프레시 토큰이 멤버 변수로 정의되어 있다. 그런데 여러 개의 Api 인스턴스가 생길 경우, 예를 들면 어떤 Api 인스턴스의 액세스토큰은 갱신되었는데 다른 Api 인스턴스의 액세스토큰은 예전 값으로 남아있는 등의 관리가 어려운 경우가 생길 수 있다. 

예전에 학교 과제에서는 java로는 싱글톤 패턴을 구현해본 적이 있었는데, javascript는 생소했기에 공식문서를 참고해서 진행했다. 

import AsyncStorage from '@react-native-async-storage/async-storage';
import axios from 'axios';
import { API_PATH } from './config';

const TOKEN_INVALID_OR_EXPIRED_MESSAGE = 'Token is invalid or expired';
const TOKEN_INVALID_TYPE_MESSAGE = 'Given token not valid for any token type';

class Api {
  async init() {
    this.accessToken = await AsyncStorage.getItem('accessToken');
    this.refreshToken = await AsyncStorage.getItem('refreshToken');
  }

  constructor() {
    if (Api.instance) {
      throw new Error('You can only create one instance!');
    }
  }

  static getInstance() {
    if (!Api.instance) {
      Api.instance = new Api();
    }
    return Api.instance;
  }

  async request(url, options) {
    try {
      return axios.request(url, {
        ...options,
        'Content-Type': 'application/json',
        Authorization: `Bearer ${this.accessToken}`,
      });
    } catch (e) {
      if (axios.isAxiosError(e)) {
        if (
          (e.response.status === 401 &&
            e.response.data.detail === TOKEN_INVALID_OR_EXPIRED_MESSAGE) ||
          e.response.data.detail === TOKEN_INVALID_TYPE_MESSAGE
        ) {
          // access token 재발급
          const responseData = await axios.post(API_PATH.renew, {
            refresh: this.refreshToken,
            access: this.accessToken,
          });
          const newAccessToken = responseData.data.access;
          await AsyncStorage.setItem('accessToken', newAccessToken);
          this.accessToken = newAccessToken;

          // 다시 요청
          return axios.request(url, {
            ...options,
            'Content-Type': 'application/json',
            Authorization: `Bearer ${this.accessToken}`,
          });
        }
      }
    }
  }

  fetchTodos(userId) {
    return this.request(`${API_PATH.todos}?user_id=${userId}`, {
      method: 'GET',
    });
  }
  
}

export default Api;

✅ 궁금한 점

1. django-db-connection-pool 라이브러리에서 어떻게 설정만으로 장고에서 사용하는 DB에서 커넥션 풀링을 할 수 있는지가 궁금하다. 나중에라도 소스 코드를 한번쯤은 꼭 찾아보자.

2. 위의 라이브러리의 공식문서에 나와있던 SQLAlchemy는 또 뭘까? 예전에 fastAPI 코드 볼 때 잠깐 봤었는데 이 녀석의 정의가 궁금하다.