arun
arun

Reputation: 11023

gunicorn threads getting killed silently

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

Answers (1)

arun
arun

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

Related Questions