Open alex-kowalczyk opened 1 year ago
@alex-kowalczyk will you post the output of gunicorn --version
please?
@christianbundy Sorry, haven't look here for a while. gunicorn (version 20.1.0)
@christianbundy , Here is a minimal testbed. Reproducible on latest 21.2.0 too.
gunicorn --workers 1 --threads 2 --max-requests 3 --timeout 300 repro:app
using code below.curl http://localhost:8000/threads -v
(a long-running request, will launch futures in ThreadPoolExecutor)curl http://localhost:8000 -v & curl http://localhost:8000 -v & curl http://localhost:8000 -v
repro.py:
from concurrent import futures
from concurrent.futures import ThreadPoolExecutor
import time
import logging
logging.basicConfig(level=logging.DEBUG)
def app(environ, start_response):
"""Simplest possible application object"""
try:
logging.info('Start')
if 'threads' in environ.get('PATH_INFO', ''):
time.sleep(15)
logging.info("Scheduling futures")
with ThreadPoolExecutor() as ex:
for i in range(100):
logging.info(i)
futures.wait([ex.submit(time.sleep, 5)])
else:
time.sleep(1)
status = '200 OK'
response_headers = [
('Content-type', 'text/plain'),
('Content-Length', '0')
]
start_response(status, response_headers)
logging.info('Responding')
return iter([b''])
except BaseException as ex:
logging.exception(f'Failed: {ex}')
raise
[2023-09-15 11:14:24 +0200] [17949] [INFO] Starting gunicorn 21.2.0
[2023-09-15 11:14:24 +0200] [17949] [INFO] Listening at: http://127.0.0.1:8000 (17949)
[2023-09-15 11:14:24 +0200] [17949] [INFO] Using worker: gthread
[2023-09-15 11:14:24 +0200] [17950] [INFO] Booting worker with pid: 17950
INFO:root:Start
INFO:root:Start
INFO:root:Responding
[2023-09-15 11:14:47 +0200] [17950] [INFO] Autorestarting worker after current request.
INFO:root:Start
INFO:root:Responding
INFO:root:Start
INFO:root:Responding
INFO:root:Scheduling futures
INFO:root:0
INFO:root:1
INFO:root:2
INFO:root:3
[2023-09-15 11:15:18 +0200] [17950] [INFO] Worker exiting (pid: 17950)
INFO:root:4
ERROR:root:Failed: cannot schedule new futures after shutdown
Traceback (most recent call last):
File "./repro.py", line 19, in app
futures.wait([ex.submit(time.sleep, 5)])
^^^^^^^^^^^^^^^^^^^^^^^^
File "/opt/homebrew/Cellar/python@3.11/3.11.3/Frameworks/Python.framework/Versions/3.11/lib/python3.11/concurrent/futures/thread.py", line 167, in submit
raise RuntimeError('cannot schedule new futures after shutdown')
RuntimeError: cannot schedule new futures after shutdown
[2023-09-15 11:15:19 +0200] [17950] [ERROR] Error handling request /threads
Traceback (most recent call last):
File "./venv/lib/python3.11/site-packages/gunicorn/workers/gthread.py", line 282, in handle
keepalive = self.handle_request(req, conn)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "./venv/lib/python3.11/site-packages/gunicorn/workers/gthread.py", line 334, in handle_request
respiter = self.wsgi(environ, resp.start_response)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "./repro.py", line 19, in app
futures.wait([ex.submit(time.sleep, 5)])
^^^^^^^^^^^^^^^^^^^^^^^^
File "/opt/homebrew/Cellar/python@3.11/3.11.3/Frameworks/Python.framework/Versions/3.11/lib/python3.11/concurrent/futures/thread.py", line 167, in submit
raise RuntimeError('cannot schedule new futures after shutdown')
RuntimeError: cannot schedule new futures after shutdown
meet the same issue on 20.1.0, anyone has solutions?
remove max_requests config could resolve this issue, so is any bug here?
Yes. It’s great that we can mitigate the defect by disabling a feature, but that doesn’t mean that there isn’t a defect.
From time to time a request fails with the following exception:
RuntimeError: cannot schedule new futures after interpreter shutdown
This happens when a gunicorn is configured with
--threads 2
and--max_requests N
option in the following scenario:max_requests
threshold.Seems that gunicorn signals "interpreter shutdown" too early, causing abnormal termination of a request which should finish normally before shutdown.
The exception is raised here: