I ran it on Python 3.7.6 and Python 3.8.2 and found the deadlock issue on both.
I then adjusted the settings to *only* have the console logger, and added these lines at the end of the settings file: import faulthandler faulthandler.enable() print(os.getpid()) faulthandler allows getting a stacktrace in dire situations such as hangs like this: https://docs.python.org/3/library/faulthandler.html Then used `runserver`, ran until the deadlock, and killed the *second* printed PID with `kill -ABRT` . This kills the actual Django server process, rather than the outer "watch & restart" process. This ended with a traceback with lots of threads all trying to acquire a lock. Some are trying to log at the end of the request: Thread 0x000070000cecf000 (most recent call first): File "/Users/chainz/.pyenv/versions/3.8.2/lib/python3.8/logging/__init__.py", line 221 in _acquireLock File "/Users/chainz/.pyenv/versions/3.8.2/lib/python3.8/logging/__init__.py", line 1687 in isEnabledFor File "/Users/chainz/.pyenv/versions/3.8.2/lib/python3.8/logging/__init__.py", line 1433 in info File "/Users/chainz/Documents/Projects/wedge/venv38/lib/python3.8/site-packages/django/core/servers/basehttp.py", line 157 in log_message File "/Users/chainz/.pyenv/versions/3.8.2/lib/python3.8/http/server.py", line 544 in log_request File "/Users/chainz/.pyenv/versions/3.8.2/lib/python3.8/wsgiref/simple_server.py", line 34 in close File "/Users/chainz/Documents/Projects/wedge/venv38/lib/python3.8/site-packages/django/core/servers/basehttp.py", line 114 in close File "/Users/chainz/.pyenv/versions/3.8.2/lib/python3.8/wsgiref/handlers.py", line 196 in finish_response File "/Users/chainz/.pyenv/versions/3.8.2/lib/python3.8/wsgiref/handlers.py", line 138 in run File "/Users/chainz/Documents/Projects/wedge/venv38/lib/python3.8/site-packages/django/core/servers/basehttp.py", line 197 in handle_one_request File "/Users/chainz/Documents/Projects/wedge/venv38/lib/python3.8/site-packages/django/core/servers/basehttp.py", line 174 in handle File "/Users/chainz/.pyenv/versions/3.8.2/lib/python3.8/socketserver.py", line 720 in __init__ File "/Users/chainz/.pyenv/versions/3.8.2/lib/python3.8/socketserver.py", line 360 in finish_request File "/Users/chainz/.pyenv/versions/3.8.2/lib/python3.8/socketserver.py", line 650 in process_request_thread File "/Users/chainz/.pyenv/versions/3.8.2/lib/python3.8/threading.py", line 870 in run File "/Users/chainz/.pyenv/versions/3.8.2/lib/python3.8/threading.py", line 932 in _bootstrap_inner File "/Users/chainz/.pyenv/versions/3.8.2/lib/python3.8/threading.py", line 890 in _bootstrap One stood out to me as trying to reconfigure logging through wsgi.py: Thread 0x000070000eed5000 (most recent call first): File "<frozen importlib._bootstrap>", line 163 in _get_module_lock File "<frozen importlib._bootstrap>", line 148 in __enter__ File "<frozen importlib._bootstrap>", line 988 in _find_and_load File "<frozen importlib._bootstrap>", line 1014 in _gcd_import File "/Users/chainz/.pyenv/versions/3.8.2/lib/python3.8/importlib/__init__.py", line 127 in import_module File "/Users/chainz/Documents/Projects/wedge/venv38/lib/python3.8/site-packages/django/utils/module_loading.py", line 17 in import_string File "/Users/chainz/Documents/Projects/wedge/venv38/lib/python3.8/site-packages/django/utils/log.py", line 89 in __init__ File "/Users/chainz/.pyenv/versions/3.8.2/lib/python3.8/logging/config.py", line 744 in configure_handler File "/Users/chainz/.pyenv/versions/3.8.2/lib/python3.8/logging/config.py", line 563 in configure File "/Users/chainz/.pyenv/versions/3.8.2/lib/python3.8/logging/config.py", line 808 in dictConfig File "/Users/chainz/Documents/Projects/wedge/venv38/lib/python3.8/site-packages/django/utils/log.py", line 71 in configure_logging File "/Users/chainz/Documents/Projects/wedge/venv38/lib/python3.8/site-packages/django/__init__.py", line 19 in setup File "/Users/chainz/Documents/Projects/wedge/venv38/lib/python3.8/site-packages/django/core/wsgi.py", line 12 in get_wsgi_application File "/Users/chainz/Documents/Projects/wedge/wedge/wsgi.py", line 6 in application File "/Users/chainz/Documents/Projects/wedge/venv38/lib/python3.8/site-packages/django/contrib/staticfiles/handlers.py", line 68 in __call__ File "/Users/chainz/.pyenv/versions/3.8.2/lib/python3.8/wsgiref/handlers.py", line 137 in run File "/Users/chainz/Documents/Projects/wedge/venv38/lib/python3.8/site-packages/django/core/servers/basehttp.py", line 197 in handle_one_request File "/Users/chainz/Documents/Projects/wedge/venv38/lib/python3.8/site-packages/django/core/servers/basehttp.py", line 174 in handle File "/Users/chainz/.pyenv/versions/3.8.2/lib/python3.8/socketserver.py", line 720 in __init__ File "/Users/chainz/.pyenv/versions/3.8.2/lib/python3.8/socketserver.py", line 360 in finish_request File "/Users/chainz/.pyenv/versions/3.8.2/lib/python3.8/socketserver.py", line 650 in process_request_thread File "/Users/chainz/.pyenv/versions/3.8.2/lib/python3.8/threading.py", line 870 in run File "/Users/chainz/.pyenv/versions/3.8.2/lib/python3.8/threading.py", line 932 in _bootstrap_inner File "/Users/chainz/.pyenv/versions/3.8.2/lib/python3.8/threading.py", line 890 in _bootstrap This stood out to me. I checked your wsgi.py , it contained: def application(environ, start_response): return get_wsgi_application()(environ, start_response) This means "create a new wsgi application for each request." During creation of a WSGI application, Django sets itself up, including configuring logging. This is why logging was trying to acquire that lock. I changed it to use the standard definition from the startproject template: application = get_wsgi_application() (The outrer "def application" was previously a no-op, so gone) Then I stopped experiencing the logging issue. This is your solution. So it seems there *may* be a python logging lock issue if you reconfigure logging whilst logs are being sent in other threads. But I'm not sure if that is intended to be supported. On Thu, 23 Apr 2020 at 13:26, Brian Tiemann <[email protected]> wrote: > It happens with Apache/mod_wsgi in prod. > > > On Thursday, April 23, 2020 at 7:59:45 AM UTC-4, Tom Forbes wrote: >> >> Just to confirm - are you running into this issue while using the Django >> development server in production, or does this occur with Gunicorn/uwsgi as >> well? >> >> Tom >> >> On 23 Apr 2020, at 12:40, Brian Tiemann <[email protected]> wrote: >> >> It also happens in 3.6.9, which is my prod environment. >> >> FWIW, by way of background context, this is not a heavily used app, not >> enough so to warrant logging to a custom buffered consumer or remote agent. >> It's just a small office using it. But the main home view's UI has 5 AJAX >> calls that cause the site to lock up on a regular basis, such that I have >> to have a watchdog in place to bounce Apache whenever it happens. >> >> It's not the logging itself that's the issue; none of the AJAX views log >> anything. The app only actually logs maybe 100 lines per day. My >> investigation however turned up that if I commented out LOGGING altogether, >> it worked fine. Further trimming down of the codebase showed that I could >> remove all the loggers and it would still happen as long as any handlers >> were defined. So that's how I set up the demo. The logging itself isn't >> important, in other words; it's that the whole app is wedging just because >> I happen to have a vanilla LOGGING setup configured. >> >> >> >> On Thursday, April 23, 2020 at 7:02:11 AM UTC-4, Brian Tiemann wrote: >>> >>> Hi — Thanks for looking into this. Adam, I skipped over details like the >>> Python version because I noted them in the readme on my gitlab demo. But I >>> was using Python 3.7.2 for the record. >>> >>> I used "deadlock" because my digging into this had previously turned up >>> https://bugs.python.org/issue6721 , suggesting this was to do with >>> thread locking. But I'm not qualified to make that call for sure, so I >>> don't want to throw red herrings into the mix. If "standstill" is a better >>> term for this that's what I'll use. >>> >>> Thanks again. >>> >>> >>> On Wednesday, April 22, 2020 at 1:23:31 PM UTC-4, Brian Tiemann wrote: >>>> >>>> Hi all, >>>> >>>> I was directed here after getting corroboration on #django and >>>> elsewhere. >>>> >>>> I have what appears to be a bug in which a Django app can deadlock if >>>> you hit it with a lot (>3) of AJAX requests within a short time (i.e. all >>>> triggered in parallel from a single HTML page). I have a reproducible case >>>> here: >>>> >>>> https://github.com/data-graham/wedge >>>> >>>> I'd really appreciate it if someone could take a look and let me know >>>> whether I'm doing something wrong, or if there's something systemic going >>>> on. Thanks much! >>>> >>>> >> -- >> You received this message because you are subscribed to the Google Groups >> "Django developers (Contributions to Django itself)" group. >> To unsubscribe from this group and stop receiving emails from it, send an >> email to [email protected]. >> To view this discussion on the web visit >> https://groups.google.com/d/msgid/django-developers/9a5bc078-66b9-4e09-97c2-8340b8882c02%40googlegroups.com >> <https://groups.google.com/d/msgid/django-developers/9a5bc078-66b9-4e09-97c2-8340b8882c02%40googlegroups.com?utm_medium=email&utm_source=footer> >> . >> >> >> -- > You received this message because you are subscribed to the Google Groups > "Django developers (Contributions to Django itself)" group. > To unsubscribe from this group and stop receiving emails from it, send an > email to [email protected]. > To view this discussion on the web visit > https://groups.google.com/d/msgid/django-developers/aa37f782-50bb-42a9-b4ed-45516e3751e5%40googlegroups.com > <https://groups.google.com/d/msgid/django-developers/aa37f782-50bb-42a9-b4ed-45516e3751e5%40googlegroups.com?utm_medium=email&utm_source=footer> > . > -- Adam -- You received this message because you are subscribed to the Google Groups "Django developers (Contributions to Django itself)" group. To unsubscribe from this group and stop receiving emails from it, send an email to [email protected]. To view this discussion on the web visit https://groups.google.com/d/msgid/django-developers/CAMyDDM39fO-dPJfGSBiom8kxJmK3-Z_nCTu1rU8qPy9n2C856g%40mail.gmail.com.
