GKE上で動かしているgunicornアプリケーションで、特に負荷が高いわけでもないのに、突然
[CRITICAL] WORKER TIMEOUT (pid:667)
というログを出しまくって止まってしまうことが発生していた。
いつなるかわからないのでしばらく見守っていたけど、原因を調べることにした。
gunicornのタイムアウトはconfファイルで設定している。
gunicorn_conf.py
worker_class = "gevent"
proxy_protocol = True
x_forwarded_for_header = "X-Real-IP"
bind = ":80"
# reload = True
timeout = 5
graceful_timeout = 5
# loglevel="debug"
Dockefileでは下記のように実行
CMD ["gunicorn", "-c", "gunicorn_conf.py", "arms:app"]
エラーが発生したときには、ログには上記の [CRITICAL] WORKER TIMEOUT が連発するだけで、エラーの原因がわからないなーと思っていたけど考えれば当たり前で、アプリ内の処理は特に時間がかかっているだけなので、エラーとは認識できない。
そのため、これから下記の対策を行う。
- タイムアウトが発生しそうなところ(DBとかRedis等外部への接続する関数) にすべて短めのタイムアウトをつける
- gunicornのタイムアウトは1でエラーが発生できるようにちょっと長めにする
タイムアウトは以前記事にも書いたtimeout-decoratorを使う。
uyamazak.hatenablog.com
そして、本番公開を行ったけど、いつ起こるかわからないのでしばらく様子見。
現時点の仮説としてはおそらくRedisへの接続でたまに時間がかかってしまうのと予想している。
アクセスの負荷とはあまり関係ないので、GKEでRedisのpodが移動したりでネットワークがつながらなくなっている可能性も。
その際は待っても解決しないので、PODごと落として、再起動させる必要があるかも。