[Logging]. gunicorn 에러 로깅 설정하기

1. 배경

부하가 7~8시간 정도 정상적으로 작동하다가
어느 순간 서버가 멈춰버렸다, 원인을 파악하려했으나 로깅 설정을 제대로 하지않아.
"A서버가 문제가 있었어 잠시 중단 되었다" 정도만 알게되었다.

2. 문제 발생

서버가 도중에 멈춰도 원인을 파악할 수 없었다.
fastapi의 기본셋팅인 uvicorn은 에러 로깅을 잘 해주지만 나는 gunicorn으로 한 번더 감싸주었기때문에 서버 측면에서는 좋지만, 로깅설정을 따로 해줘야했다.

언젠가 할 작업이라서 뒤로 미루다가 결국 터져버렸다...

3. 문제 해결

문제는 gunicorn에 로그옵션을 추가해주면 간단하게 해결되지만,
파일을 하나 만들어서 좀 더 깔끔하게 정리했다.

# gunicorn.conf.py
from datetime import datetime
import os

if not os.path.exists("logs"):
    os.makedirs("logs")
    os.makedirs("logs/gunicorn")

bind = "0.0.0.0:8200"
workers = 2
worker_class = "uvicorn.workers.UvicornWorker"
reload = True
accesslog = f"./logs/gunicorn/access_{datetime.now().strftime('%Y-%m-%d_%H')}.log"
errorlog = f"./logs/gunicorn/error_{datetime.now().strftime('%Y-%m-%d_%H')}.log"
loglevel = "info"

이런식으로 파일에 옵션들을 정의하였고, 로그 파일은 현재 시간을 기준으로
서버가 재시작될때 계속 만들어 내도록 설계했다.

accesslog 와 errorlog 를 따로 분리해서 진행했다.

accesslog.log

250.250.250.250:53138 - "POST /combot/answer/recommend HTTP/1.1" 200
250.250.250.250:53140 - "POST /combot/answer/recommend HTTP/1.1" 200
250.250.250.250:53176 - "POST /combot/answer/recommend HTTP/1.1" 200
250.250.250.250:53286 - "POST /combot/answer/recommend HTTP/1.1" 200
250.250.250.250:53456 - "POST /combot/answer HTTP/1.1" 200
250.250.250.250:53458 - "POST /combot/answer HTTP/1.1" 200
250.250.250.250:53446 - "POST /combot/answer HTTP/1.1" 200
250.250.250.250:53450 - "POST /combot/answer HTTP/1.1" 200

error.log

[2023-07-26 03:45:53 +0000] [8] [INFO] Starting gunicorn 20.1.0
[2023-07-26 03:45:53 +0000] [8] [INFO] Listening at: http://0.0.0.0:8200 (8)
[2023-07-26 03:45:53 +0000] [8] [INFO] Using worker: uvicorn.workers.UvicornWorker
[2023-07-26 03:45:53 +0000] [9] [INFO] Booting worker with pid: 9
[2023-07-26 03:45:53 +0000] [10] [INFO] Booting worker with pid: 10
[2023-07-26 03:46:15 +0000] [10] [INFO] Started server process [10]
[2023-07-26 03:46:15 +0000] [9] [INFO] Started server process [9]
[2023-07-26 03:46:15 +0000] [10] [INFO] Waiting for application startup.
[2023-07-26 03:46:15 +0000] [9] [INFO] Waiting for application startup.
[2023-07-26 03:46:15 +0000] [9] [INFO] Application startup complete.
[2023-07-26 03:46:15 +0000] [10] [INFO] Application startup complete.

start_server.sh

#!/bin/sh
gunicorn manage:app -c gunicorn.conf.py

서버를 실행할때는 파일을 읽어서 실행하도록 변경했다.

[파일구조]

logs/gunicorn에 로그들을 저장하도록 변경했다.
이제 다시 부하테스틀키고 만약 서버가 멈춘다면 원인을 파악해서 해결해야겠다.

끝.