Reputation: 11023
gunicorn version 19.9.0
Got the following gunicorn config:
accesslog = "access.log"
worker_class = 'sync'
workers = 1
worker_connections = 1000
timeout = 300
graceful_timeout = 300
keepalive = 300
proc_name = 'server'
bind = '0.0.0.0:8080'
name = 'server.py'
preload = True
log_level = "info"
threads = 7
max_requests = 0
backlog = 100
As you can see, the server is configured to run 7 threads.
The server is started with:
gunicorn -c gunicorn_config.py server:app
Here are the number of lines and thread IDs from our log file at the beginning (with the last line being the thread of the main server):
10502 140625414080256
10037 140624842843904
9995 140624859629312
9555 140625430865664
9526 140624851236608
9409 140625405687552
2782 140625422472960
6 140628359804736
So 7 threads are processing the requests. (Already we can see that thread 140625422472960 is processing substantially fewer requests than the other threads.)
But after the lines examined above, thread 140625422472960 just vanishes and the log file only has:
19602 140624859629312
18861 140625405687552
18766 140624851236608
18765 140624842843904
12523 140625414080256
2111 140625430865664
(excluding the main thread here)
From the server logs we could see that the thread received a request and started processing it, but never finished. The client received no response either.
There is no error/warning in the log file, nor in stderr.
And running the app for a little longer, two more threads are gone:
102 140624842843904
102 140624851236608
68 140624859629312
85 140625405687552
How to debug this?
Upvotes: 1
Views: 2515
Reputation: 11023
Digging into the stderr logs further, finally found something like this exception stack trace:
Traceback (most recent call last):
File "/usr/local/lib/python3.6/site-packages/gunicorn/workers/sync.py", line 134, in handle
req = six.next(parser)
File "/usr/local/lib/python3.6/site-packages/gunicorn/http/parser.py", line 41, in __next__
self.mesg = self.mesg_class(self.cfg, self.unreader, self.req_count)
File "/usr/local/lib/python3.6/site-packages/gunicorn/http/message.py", line 181, in __init__
super(Request, self).__init__(cfg, unreader)
File "/usr/local/lib/python3.6/site-packages/gunicorn/http/message.py", line 54, in __init__
unused = self.parse(self.unreader)
File "/usr/local/lib/python3.6/site-packages/gunicorn/http/message.py", line 230, in parse
self.headers = self.parse_headers(data[:idx])
File "/usr/local/lib/python3.6/site-packages/gunicorn/http/message.py", line 74, in parse_headers
remote_addr = self.unreader.sock.getpeername()
OSError: [Errno 107] Transport endpoint is not connected
[2018-11-04 17:57:55 +0330] [31] [ERROR] Socket error processing request.
Traceback (most recent call last):
File "/usr/local/lib/python3.6/site-packages/gunicorn/workers/sync.py", line 134, in handle
req = six.next(parser)
File "/usr/local/lib/python3.6/site-packages/gunicorn/http/parser.py", line 41, in __next__
self.mesg = self.mesg_class(self.cfg, self.unreader, self.req_count)
File "/usr/local/lib/python3.6/site-packages/gunicorn/http/message.py", line 181, in __init__
super(Request, self).__init__(cfg, unreader)
File "/usr/local/lib/python3.6/site-packages/gunicorn/http/message.py", line 54, in __init__
unused = self.parse(self.unreader)
File "/usr/local/lib/python3.6/site-packages/gunicorn/http/message.py", line 230, in parse
self.headers = self.parse_headers(data[:idx])
File "/usr/local/lib/python3.6/site-packages/gunicorn/http/message.py", line 74, in parse_headers
remote_addr = self.unreader.sock.getpeername()
OSError: [Errno 107] Transport endpoint is not connected
This is due to this gunicorn bug.
An interim solution until this bug is fixed is to monkey patch gunicorn as done by asantoni.
Upvotes: 2