会社のデベロッパーブログでも書いたけど再現手順は記載してなかったので、改めて。
Gunicorn 19.6.0 をthread workerで稼働していると、max_requestsに達してworker threadが再起動したときにUnixドメインソケットが削除される現象にあった。
以下、再現手順。
事前準備
$ pip install gunicorn==19.6.0 bottle==0.12.13
以下のPythonモジュールを作成しておく。
web.py (WSGIアプリケーション)
# -*- coding:utf-8 -*-
from bottle import route, run, default_app
@route('/')
def index():
return 'Hello World'
= default_app() app
config.py (gunicorn設定)
= 'unix:/tmp/gunicorn.sock'
bind = 2048
backlog
= 5
workers = 5
threads = 'sync'
worker_class = 1000
worker_connections = 30
timeout = 2
keepalive
= 512
max_requests
= False
spew
= False
daemon = None
pidfile = 0
umask = None
user = None
group = None
tmp_upload_dir
# Logging
= '-'
errorlog = 'info'
loglevel = '-'
accesslog = '%(h)s %(l)s %(u)s %(t)s "%(r)s" %(s)s %(b)s "%(f)s" "%(a)s"'
access_log_format
# Process naming
= None
proc_name
# Server hooks
def post_fork(server, worker):
"Worker spawned (pid: %s)", worker.pid)
server.log.info(
def pre_fork(server, worker):
pass
def pre_exec(server):
"Forked child, re-executing.")
server.log.info(
def when_ready(server):
"Server is ready. Spawning workers")
server.log.info(
def worker_int(worker):
"worker received INT or QUIT signal")
worker.log.info(
## get traceback info
import threading, sys, traceback
= dict([(th.ident, th.name) for th in threading.enumerate()])
id2name = []
code for threadId, stack in sys._current_frames().items():
"\n# Thread: %s(%d)" % (id2name.get(threadId,""),
code.append(
threadId))for filename, lineno, name, line in traceback.extract_stack(stack):
'File: "%s", line %d, in %s' % (filename,
code.append(
lineno, name))if line:
" %s" % (line.strip()))
code.append("\n".join(code))
worker.log.debug(
def worker_abort(worker):
"worker received SIGABRT signal") worker.log.info(
h2o.conf (h2o設定)
listen:
port: 18080
hosts:
default:
paths:
"/":
proxy.reverse.url: http://[unix:/tmp/gunicorn.sock]/
proxy.preserve-host: ON
access-log: /dev/stdout
サーバー起動
gunicorn 起動
$ gunicorn web:app -c config.py
h2o 起動
$ h2o -c h2o.conf
再現
$ wrk -t10 -c200 -d10s http://127.0.0.1:18080
以下のようなエラーログが出力される。
(場合によっては、スレッド数や接続数等のオプションを変更する必要があるかもしれない)
[2017-02-18 01:26:57 +0900] [56927] [INFO] Autorestarting worker after current request.
- - [18/Feb/2017:01:26:57 +0900] "GET / HTTP/1.1" 200 11 "-" "-"
- - [18/Feb/2017:01:26:57 +0900] "GET / HTTP/1.1" 200 11 "-" "-"
- - [18/Feb/2017:01:26:57 +0900] "GET / HTTP/1.1" 200 11 "-" "-"
[2017-02-18 01:26:57 +0900] [56927] [ERROR] Exception in worker process
Traceback (most recent call last):
File "/Users/thara/.pyenv/versions/3.6.0/envs/gunicorn_bug/lib/python3.6/site-packages/gunicorn/arbiter.py", line 557, in spawn_worker
worker.init_process()
File "/Users/thara/.pyenv/versions/3.6.0/envs/gunicorn_bug/lib/python3.6/site-packages/gunicorn/workers/gthread.py", line 109, in init_process
super(ThreadWorker, self).init_process()
File "/Users/thara/.pyenv/versions/3.6.0/envs/gunicorn_bug/lib/python3.6/site-packages/gunicorn/workers/base.py", line 132, in init_process
self.run()
File "/Users/thara/.pyenv/versions/3.6.0/envs/gunicorn_bug/lib/python3.6/site-packages/gunicorn/workers/gthread.py", line 240, in run
s.close()
File "/Users/thara/.pyenv/versions/3.6.0/envs/gunicorn_bug/lib/python3.6/site-packages/gunicorn/sock.py", line 123, in close
os.unlink(self.cfg_addr)
FileNotFoundError: [Errno 2] No such file or directory: '/tmp/gunicorn.sock'
この状態になると、Unixドメインソケットのファイルが紛失するため、gunicornに対してリバースプロキシ(この例だとH2O)から接続できなくなり、 HTTPリクエストしたクライアントには502が返される。
該当issueは これ。 該当箇所は19.6.0での修正箇所であるため、19.6.0より前のバージョンではこの現象は発生しないと思われる。 また、このissueはすでに対応されcloseされているが、まだリリースには至っていない。
回避方法
現状では、Unixドメインソケットを使わず、portのlistenのみで対応するのが確実。