Hello Graham, many thanks for your detailed reply!
I must add that my Django project is a simple webcam application: A webcam sends POST requests to upload the images, the views show them. A single webcam is connected over a very slow internet connection (32 kBit/s), so a single POST can take several minutes. However, that never was and still doesn't seem to be a problem: Uploads still succeed, it's only the GET requests that fail. The GET requests in turn do more than just sending some HTML with the image URLs: especially they use the Pillow library to lazily produce thumbnails, put timestamps into the images, etc. Therefore I thought that Pillow (9.4.0) might be the culprit, so I removed the related code, made a new virtuelenv without Pillow from scratch and restarted Apache. Unfortunately, it didn't help – please see the error log below. The timeout occurs only after the browser has received a large portion, possibly all, of the view's response. `pip list` shows Package Version -------------------- ------- asgiref 3.6.0 Django 4.1.5 django-improved-user 2.0a2 django-widget-tweaks 1.4.12 pip 22.0.2 python-dateutil 2.8.2 setuptools 59.6.0 six 1.16.0 sqlparse 0.4.3 Is any of these know for causing problems like numpy? Best regards, Carsten The above mentioned error log: [Mon Feb 06 20:52:20.329545 2023] [mpm_event:notice] [pid 25844:tid 140714434877312] AH00489: Apache/2.4.52 (Ubuntu) mod_wsgi/4.9.0 Python/3.10 configured -- resuming normal operations [Mon Feb 06 20:52:20.330207 2023] [core:notice] [pid 25844:tid 140714434877312] AH00094: Command line: '/usr/sbin/apache2' [Mon Feb 06 20:52:20.380741 2023] [wsgi:info] [pid 25845:tid 140714434877312] mod_wsgi (pid=25845): Attach interpreter ''. [Mon Feb 06 20:52:20.395024 2023] [wsgi:info] [pid 25846:tid 140714434877312] mod_wsgi (pid=25846): Attach interpreter ''. [Mon Feb 06 20:52:20.395771 2023] [wsgi:info] [pid 25845:tid 140714434877312] mod_wsgi (pid=25845): Adding '/home/carsten/HallCam/web' to path. [Mon Feb 06 20:52:20.411711 2023] [wsgi:info] [pid 25846:tid 140714434877312] mod_wsgi (pid=25846): Adding '/home/carsten/HallCam/web' to path. [Mon Feb 06 20:52:48.621284 2023] [wsgi:info] [pid 25845:tid 140714369189440] mod_wsgi (pid=25845): Create interpreter '192.168.1.222:32228|'. [Mon Feb 06 20:52:48.634464 2023] [wsgi:info] [pid 25845:tid 140714369189440] mod_wsgi (pid=25845): Adding '/home/carsten/HallCam/web' to path. [Mon Feb 06 20:52:48.635248 2023] [wsgi:info] [pid 25845:tid 140714369189440] [remote 88.75.25.178:42162] mod_wsgi (pid=25845, process='cf-hallcam-site', application='192.168.1.222:32228|'): Loading Python script file '/home/carsten/HallCam/web/HallCam/wsgi.py'. [Mon Feb 06 20:57:40.661043 2023] [wsgi:info] [pid 25845:tid 140714419545664] mod_wsgi (pid=25845): Daemon process request time limit exceeded, stopping process 'cf-hallcam-site'. [Mon Feb 06 20:57:40.661184 2023] [wsgi:info] [pid 25845:tid 140714434877312] mod_wsgi (pid=25845): Shutdown requested 'cf-hallcam-site'. [Mon Feb 06 20:57:45.661421 2023] [wsgi:info] [pid 25845:tid 140714177934912] mod_wsgi (pid=25845): Aborting process 'cf-hallcam-site'. [Mon Feb 06 20:57:45.661464 2023] [wsgi:info] [pid 25845:tid 140714177934912] mod_wsgi (pid=25845): Exiting process 'cf-hallcam-site'. [Mon Feb 06 20:57:45.666987 2023] [wsgi:error] [pid 25847:tid 140714226689600] [client 37.81.109.237:49940] Truncated or oversized response headers received from daemon process 'cf-hallcam-site': /home/carsten/HallCam/web/HallCam/wsgi.py [Mon Feb 06 20:57:45.667005 2023] [wsgi:error] [pid 25848:tid 140714335794752] (104)Connection reset by peer: [client 88.75.25.178:42162] mod_wsgi (pid=25848): Failed to proxy response from daemon., referer: http://vdzuggmrroo5k7e9.myfritz.net:32228/ [Mon Feb 06 20:57:46.621804 2023] [wsgi:info] [pid 25977:tid 140714434877312] mod_wsgi (pid=25977): Attach interpreter ''. [Mon Feb 06 20:57:46.633564 2023] [wsgi:info] [pid 25977:tid 140714434877312] mod_wsgi (pid=25977): Adding '/home/carsten/HallCam/web' to path. [Mon Feb 06 21:00:01.811479 2023] [wsgi:info] [pid 25846:tid 140714360796736] mod_wsgi (pid=25846): Create interpreter '192.168.1.222:32228|'. [Mon Feb 06 21:00:01.824795 2023] [wsgi:info] [pid 25846:tid 140714360796736] mod_wsgi (pid=25846): Adding '/home/carsten/HallCam/web' to path. [Mon Feb 06 21:00:01.825535 2023] [wsgi:info] [pid 25846:tid 140714360796736] [remote 37.81.109.237:49942] mod_wsgi (pid=25846, process='cf-hallcam-site', application='192.168.1.222:32228|'): Loading Python script file '/home/carsten/HallCam/web/HallCam/wsgi.py'. [Mon Feb 06 21:00:02.506063 2023] [wsgi:info] [pid 25977:tid 140714402760256] mod_wsgi (pid=25977): Create interpreter '192.168.1.222:32228|'. [Mon Feb 06 21:00:02.519453 2023] [wsgi:info] [pid 25977:tid 140714402760256] mod_wsgi (pid=25977): Adding '/home/carsten/HallCam/web' to path. [Mon Feb 06 21:00:02.520239 2023] [wsgi:info] [pid 25977:tid 140714402760256] [remote 88.75.25.178:43650] mod_wsgi (pid=25977, process='cf-hallcam-site', application='192.168.1.222:32228|'): Loading Python script file '/home/carsten/HallCam/web/HallCam/wsgi.py'. [Mon Feb 06 21:00:03.299821 2023] [core:info] [pid 25847:tid 140714151155264] [client 88.75.25.178:43652] AH00128: File does not exist: /var/www/HallCam-media/thumbs/camera-2/pic_20230206_205532_4.jpg, referer: http://vdzuggmrroo5k7e9.myfritz.net:32228/ [Mon Feb 06 21:05:02.996169 2023] [wsgi:info] [pid 25977:tid 140714419545664] mod_wsgi (pid=25977): Daemon process deadlock timer expired, stopping process 'cf-hallcam-site'. [Mon Feb 06 21:05:02.996308 2023] [wsgi:info] [pid 25977:tid 140714434877312] mod_wsgi (pid=25977): Shutdown requested 'cf-hallcam-site'. [Mon Feb 06 21:05:07.996544 2023] [wsgi:info] [pid 25977:tid 140714177934912] mod_wsgi (pid=25977): Aborting process 'cf-hallcam-site'. [Mon Feb 06 21:05:07.996587 2023] [wsgi:info] [pid 25977:tid 140714177934912] mod_wsgi (pid=25977): Exiting process 'cf-hallcam-site'. [Mon Feb 06 21:05:08.002106 2023] [wsgi:error] [pid 25848:tid 140713647920704] [client 37.81.109.237:49944] Truncated or oversized response headers received from daemon process 'cf-hallcam-site': /home/carsten/HallCam/web/HallCam/wsgi.py [Mon Feb 06 21:05:08.002137 2023] [wsgi:error] [pid 25848:tid 140714025395776] (104)Connection reset by peer: [client 88.75.25.178:43650] mod_wsgi (pid=25848): Failed to proxy response from daemon., referer: http://vdzuggmrroo5k7e9.myfritz.net:32228/ [Mon Feb 06 21:05:09.015715 2023] [wsgi:info] [pid 26028:tid 140714434877312] mod_wsgi (pid=26028): Attach interpreter ''. [Mon Feb 06 21:05:09.027591 2023] [wsgi:info] [pid 26028:tid 140714434877312] mod_wsgi (pid=26028): Adding '/home/carsten/HallCam/web' to path. [Mon Feb 06 21:05:29.082057 2023] [wsgi:info] [pid 25846:tid 140714419545664] mod_wsgi (pid=25846): Daemon process deadlock timer expired, stopping process 'cf-hallcam-site'. [Mon Feb 06 21:05:29.082193 2023] [wsgi:info] [pid 25846:tid 140714434877312] mod_wsgi (pid=25846): Shutdown requested 'cf-hallcam-site'. [Mon Feb 06 21:05:34.082447 2023] [wsgi:info] [pid 25846:tid 140714177934912] mod_wsgi (pid=25846): Aborting process 'cf-hallcam-site'. [Mon Feb 06 21:05:34.082493 2023] [wsgi:info] [pid 25846:tid 140714177934912] mod_wsgi (pid=25846): Exiting process 'cf-hallcam-site'. [Mon Feb 06 21:05:35.038614 2023] [wsgi:info] [pid 26047:tid 140714434877312] mod_wsgi (pid=26047): Attach interpreter ''. [Mon Feb 06 21:05:35.050453 2023] [wsgi:info] [pid 26047:tid 140714434877312] mod_wsgi (pid=26047): Adding '/home/carsten/HallCam/web' to path. Am 05.02.23 um 23:32 schrieb Graham Dumpleton: > Two points here to clarify. > > In your case the final error is: > > Daemon process deadlock timer expired > > This means that the full Python interpreter locked up. In this case the > request timeout may not apply and the feature where by stack traces can be > dumped might not happen. Depends on what lead up to the issue. > > By default the deadlock timeout is 300 seconds. > > *deadlock-timeout=sss* > > Defines the maximum number of seconds allowed to pass before the daemon > process is shutdown and restarted after a potential deadlock on the Python > GIL has been detected. The default is 300 seconds. > > This option exists to combat the problem of a daemon process freezing as > the result of a rogue Python C extension module which doesn’t properly > release the Python GIL when entering into a blocking or long running > operation. > > This can occur when you are using third party Python packages which aren't > designed to work in Python sub interpreters. More details in: > > Application Issues — mod_wsgi 4.9.4 documentation > <https://modwsgi.readthedocs.io/en/master/user-guides/application-issues.html#python-simplified-gil-state-api> > modwsgi.readthedocs.io > <https://modwsgi.readthedocs.io/en/master/user-guides/application-issues.html#python-simplified-gil-state-api> > favicon.ico > <https://modwsgi.readthedocs.io/en/master/user-guides/application-issues.html#python-simplified-gil-state-api> > > <https://modwsgi.readthedocs.io/en/master/user-guides/application-issues.html#python-simplified-gil-state-api> > > The solution as you found is to set: > > WSGIApplicationGroup %{GLOBAL} > > So likely when you updated Python versions, some third party package you are > using has shifted to a newer version which breaks in this respect, or which > runs code different when using newer Python version. > > As to request timeout if it were coming into play, the timeout is 30 seconds > when you have daemon processes which are single threaded. > > For multithreaded daemon process the timeout can trigger after 30 seconds as > uses an average across all active request handler threads. > > *request-timeout=sss* > > Defines the maximum number of seconds that a request is allowed to run > before the daemon process is restarted. This can be used to recover from a > scenario where a request blocks indefinitely, and where if all request > threads were consumed in this way, would result in the whole WSGI application > process being blocked. > > How this option is seen to behave is different depending on whether a > daemon process uses only one thread, or more than one thread for handling > requests, as set by the |threads| option. > > If there is only a single thread, and so the process can only handle one > request at a time, as soon as the timeout has passed, a restart of the > process will be initiated. > > If there is more than one thread, the request timeout is applied to the > average running time for any requests, across all threads. This means that a > request can run longer than the request timeout. This is done to reduce the > possibility of interupting other running requests, and causing a user to see > a failure. So where there is still capacity to handle more requests, > restarting of the process will be delayed if possible. > > > In your case though because hitting a full lock up of the Python interpreter, > even though the request timeout may still have triggered, it couldn't dump > stack traces as doing so requires getting the global Python interpreter lock, > which wasn't being released and thus threads to dump stack traces got stuck. > > To understand the cause further and identify which third party package may be > the problem, I would need to see what extra Python packages you are > installing. Note that numpy can cause this, so if using anything which relies > on that, that could be the reason. > > Graham > >> On 6 Feb 2023, at 3:35 am, Carsten Fuchs <[email protected]> wrote: >> >> Adding to my recent post: >> >> It seems that the `request-timeout=30` is effective, after all: The error >> messages have changed, but there is no stack trace. >> For completeness, here is the site config and error log excerpt: >> >> Site config: >> >> <VirtualHost *:80> >> ServerAdmin webmaster@localhost >> DocumentRoot /var/www/html >> >> # Available loglevels: trace8, ..., trace1, debug, info, notice, warn, >> # error, crit, alert, emerg. >> # It is also possible to configure the loglevel for particular >> # modules, e.g. >> #LogLevel info ssl:warn >> LogLevel info >> >> ErrorLog ${APACHE_LOG_DIR}/error.log >> CustomLog ${APACHE_LOG_DIR}/access.log combined >> >> # Siehe https://bz.apache.org/bugzilla/show_bug.cgi?id=45023 >> # Hierfür muss mod_headers aktiv sein: sudo a2enmod headers >> RequestHeader edit "If-None-Match" '^"((.*)-gzip)"$' '"$1", "$2"' >> >> Alias /static/ /var/www/HallCam-static/ >> <Directory /var/www/HallCam-static> >> Require all granted >> </Directory> >> >> Alias /media/ /var/www/HallCam-media/ >> <Directory /var/www/HallCam-media> >> Require all granted >> </Directory> >> >> WSGIDaemonProcess cf-hallcam-site request-timeout=30 user=carsten >> group=carsten processes=2 display-name=%{GROUP} >> python-home=/home/carsten/.virtualenvs/HallCam-web >> python-path=/home/carsten/HallCam/web >> WSGIProcessGroup cf-hallcam-site >> # WSGIApplicationGroup %{GLOBAL} >> >> WSGIScriptAlias / /home/carsten/HallCam/web/HallCam/wsgi.py >> <Directory /home/carsten/HallCam/web/HallCam> >> <Files wsgi.py> >> Require all granted >> </Files> >> </Directory> >> </VirtualHost> >> >> >> From `/var/log/apache2/error.log`: >> >> [Sun Feb 05 17:18:55.470532 2023] [mpm_event:notice] [pid 635:tid >> 140277991982976] AH00489: Apache/2.4.52 (Ubuntu) mod_wsgi/4.9.0 Python/3.10 >> configured -- resuming normal operations >> [Sun Feb 05 17:18:55.690430 2023] [core:notice] [pid 635:tid >> 140277991982976] AH00094: Command line: '/usr/sbin/apache2' >> [Sun Feb 05 17:18:56.338443 2023] [wsgi:info] [pid 638:tid 140277991982976] >> mod_wsgi (pid=638): Attach interpreter ''. >> [Sun Feb 05 17:18:56.342866 2023] [wsgi:info] [pid 636:tid 140277991982976] >> mod_wsgi (pid=636): Attach interpreter ''. >> [Sun Feb 05 17:18:56.366079 2023] [wsgi:info] [pid 636:tid 140277991982976] >> mod_wsgi (pid=636): Adding '/home/carsten/HallCam/web' to path. >> [Sun Feb 05 17:18:56.371777 2023] [wsgi:info] [pid 638:tid 140277991982976] >> mod_wsgi (pid=638): Adding '/home/carsten/HallCam/web' to path. >> [Sun Feb 05 17:19:24.823860 2023] [wsgi:info] [pid 636:tid 140277959865920] >> mod_wsgi (pid=636): Create interpreter '192.168.1.222:32228|'. >> [Sun Feb 05 17:19:24.837012 2023] [wsgi:info] [pid 636:tid 140277959865920] >> mod_wsgi (pid=636): Adding '/home/carsten/HallCam/web' to path. >> [Sun Feb 05 17:19:24.837752 2023] [wsgi:info] [pid 636:tid 140277959865920] >> [remote 88.75.25.178:50558] mod_wsgi (pid=636, process='cf-hallcam-site', >> application='192.168.1.222:32228|'): Loading Python script file >> '/home/carsten/HallCam/web/HallCam/wsgi.py'. >> [Sun Feb 05 17:19:43.356895 2023] [wsgi:info] [pid 638:tid 140277867546176] >> mod_wsgi (pid=638): Create interpreter '192.168.1.222:32228|'. >> [Sun Feb 05 17:19:43.369787 2023] [wsgi:info] [pid 638:tid 140277867546176] >> mod_wsgi (pid=638): Adding '/home/carsten/HallCam/web' to path. >> [Sun Feb 05 17:19:43.370532 2023] [wsgi:info] [pid 638:tid 140277867546176] >> [remote 88.75.25.178:48210] mod_wsgi (pid=638, process='cf-hallcam-site', >> application='192.168.1.222:32228|'): Loading Python script file >> '/home/carsten/HallCam/web/HallCam/wsgi.py'. >> [Sun Feb 05 17:23:21.631286 2023] [wsgi:info] [pid 636:tid 140277976651328] >> mod_wsgi (pid=636): Daemon process request time limit exceeded, stopping >> process 'cf-hallcam-site'. >> [Sun Feb 05 17:23:21.631405 2023] [wsgi:info] [pid 636:tid 140277991982976] >> mod_wsgi (pid=636): Shutdown requested 'cf-hallcam-site'. >> [Sun Feb 05 17:23:26.631650 2023] [wsgi:info] [pid 636:tid 140277591307840] >> mod_wsgi (pid=636): Aborting process 'cf-hallcam-site'. >> [Sun Feb 05 17:23:26.631699 2023] [wsgi:info] [pid 636:tid 140277591307840] >> mod_wsgi (pid=636): Exiting process 'cf-hallcam-site'. >> [Sun Feb 05 17:23:26.714616 2023] [wsgi:error] [pid 639:tid 140277725460032] >> [client 88.75.25.178:48224] Truncated or oversized response headers received >> from daemon process 'cf-hallcam-site': >> /home/carsten/HallCam/web/HallCam/wsgi.py, referer: >> http://vdzuggmrroo5k7e9.myfritz.net:32228/upload/ >> [Sun Feb 05 17:23:26.714952 2023] [wsgi:error] [pid 639:tid 140277959865920] >> (104)Connection reset by peer: [client 88.75.25.178:50558] mod_wsgi >> (pid=639): Failed to proxy response from daemon., referer: >> http://vdzuggmrroo5k7e9.myfritz.net:32228/upload/ >> [Sun Feb 05 17:23:26.983714 2023] [wsgi:info] [pid 885:tid 140277991982976] >> mod_wsgi (pid=885): Attach interpreter ''. >> [Sun Feb 05 17:23:26.994980 2023] [wsgi:info] [pid 885:tid 140277991982976] >> mod_wsgi (pid=885): Adding '/home/carsten/HallCam/web' to path. >> [Sun Feb 05 17:23:37.641476 2023] [wsgi:info] [pid 638:tid 140277976651328] >> mod_wsgi (pid=638): Daemon process request time limit exceeded, stopping >> process 'cf-hallcam-site'. >> [Sun Feb 05 17:23:37.641609 2023] [wsgi:info] [pid 638:tid 140277991982976] >> mod_wsgi (pid=638): Shutdown requested 'cf-hallcam-site'. >> [Sun Feb 05 17:23:42.641863 2023] [wsgi:info] [pid 638:tid 140277591307840] >> mod_wsgi (pid=638): Aborting process 'cf-hallcam-site'. >> [Sun Feb 05 17:23:42.641910 2023] [wsgi:info] [pid 638:tid 140277591307840] >> mod_wsgi (pid=638): Exiting process 'cf-hallcam-site'. >> [Sun Feb 05 17:23:42.648248 2023] [wsgi:error] [pid 639:tid 140277717067328] >> [client 37.81.109.237:49336] Truncated or oversized response headers >> received from daemon process 'cf-hallcam-site': >> /home/carsten/HallCam/web/HallCam/wsgi.py >> [Sun Feb 05 17:23:42.648624 2023] [wsgi:error] [pid 639:tid 140277733852736] >> (104)Connection reset by peer: [client 88.75.25.178:48210] mod_wsgi >> (pid=639): Failed to proxy response from daemon., referer: >> http://vdzuggmrroo5k7e9.myfritz.net:32228/ >> [Sun Feb 05 17:23:42.997522 2023] [wsgi:info] [pid 906:tid 140277991982976] >> mod_wsgi (pid=906): Attach interpreter ''. >> [Sun Feb 05 17:23:43.039478 2023] [wsgi:info] [pid 906:tid 140277991982976] >> mod_wsgi (pid=906): Adding '/home/carsten/HallCam/web' to path. >> [Sun Feb 05 17:25:01.761551 2023] [wsgi:info] [pid 885:tid 140277959865920] >> mod_wsgi (pid=885): Create interpreter '192.168.1.222:32228|'. >> [Sun Feb 05 17:25:01.774488 2023] [wsgi:info] [pid 885:tid 140277959865920] >> mod_wsgi (pid=885): Adding '/home/carsten/HallCam/web' to path. >> [Sun Feb 05 17:25:01.775225 2023] [wsgi:info] [pid 885:tid 140277959865920] >> [remote 37.81.109.237:49338] mod_wsgi (pid=885, process='cf-hallcam-site', >> application='192.168.1.222:32228|'): Loading Python script file >> '/home/carsten/HallCam/web/HallCam/wsgi.py'. >> [Sun Feb 05 17:25:03.155261 2023] [wsgi:error] [pid 885:tid 140277959865920] >> [remote 37.81.109.237:49338] Picture saved to >> /var/www/HallCam-media/pictures/camera-1/pic_20230205_172500_4.jpg >> (image/jpeg, 896262 bytes, camera camera-1) >> [Sun Feb 05 17:30:03.323110 2023] [wsgi:info] [pid 885:tid 140277976651328] >> mod_wsgi (pid=885): Daemon process deadlock timer expired, stopping process >> 'cf-hallcam-site'. >> [Sun Feb 05 17:30:03.323253 2023] [wsgi:info] [pid 885:tid 140277991982976] >> mod_wsgi (pid=885): Shutdown requested 'cf-hallcam-site'. >> >> >> Carsten Fuchs schrieb am Sonntag, 5. Februar 2023 um 17:23:29 UTC+1: >> >> Dear Graham, >> >> I experienced the same timeout errors after having upgraded a server >> from Ubuntu 20.04 LTS to Ubuntu 22.04 LTS, thereby also upgrading from >> Python 3.8 to Python 3.10. The application is a relatively simple Django >> project that used to work well until the upgrade. After the upgrade, I >> deleted the old virtualenv and built a new one, using `pip install >> --no-cache-dir -r requirements.txt` to install it. However, I experience the >> same problem. >> >> Adding `WSGIApplicationGroup %{GLOBAL}` solved the problem, but I am >> still concerned because the site worked well with the older Ubuntu 20.04 LTS >> and I would prefer to not mask a potential problem and rather find its root. >> >> Therefore, I added the `request-timeout=30` option to >> `WSGIDaemonProcess` (and temporarily commented `WSGIApplicationGroup` out >> again) in order to get a stack trace, however it doesn't seem to have any >> effect: Requests time out only much later than 30 seconds. >> >> Can you please advise what may have caused the problem when upgrading >> from Ubuntu 20.04 LTS to Ubuntu 22.04 LTS and why `request-timeout=30` may >> not have any effect? >> >> Best regards, >> Carsten >> -- You received this message because you are subscribed to the Google Groups "modwsgi" 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/modwsgi/deb900d2-ebf6-68a2-3ec9-c2386f5ca2d9%40cafu.de.
