Long running requests don't send respond.
29 views
Skip to first unread message
Maximilian Sommer
Jun 23, 2025, 5:12:40 PMJun 23
to modwsgi
Dear Graham,
I inherited a service from my predecessor using mod_wsgi. The service itself is functional, but longer running requests (~10 min) don't end up in a response to the client, even though logs don't really hint to any bigger issues. My best guess is some kind of timeout issue, but I am at my wits end which config that should be.
The server runs in a docker container where it starts an apache server with mod_wsgi configured and python using flask to handle the requests.
I inherited a service from my predecessor using mod_wsgi. The service itself is functional, but longer running requests (~10 min) don't end up in a response to the client, even though logs don't really hint to any bigger issues. My best guess is some kind of timeout issue, but I am at my wits end which config that should be.
The server runs in a docker container where it starts an apache server with mod_wsgi configured and python using flask to handle the requests.
It runs with theses versions:
Due to forking of the process using the multiprocessing package I switched to the prefork MPM. In the current long running requests that don't respond this forking doesn't happen, so it shouldn't be an issue here.
I had a look here https://groups.google.com/g/modwsgi/c/zuhFREjOE8M and massively increased all timeouts to test if this is the issue, but that doesn't seem to be the case.
<VirtualHost *:443>
ServerName someservice.de
WSGIDaemonProcess python_service processes=10 threads=1 display-name=someservice maximum-requests=200 python-home=/var/www/someservice/venv socket-timeout=1800 connect-timeout=1800 request-timeout=1800 graceful-timeout=1800 eviction-timeout=1800 queue-timeout=1800
WSGIScriptAlias /python_service /var/www/someservice/someservice_service/someservice_service_controller.py process-group=python_service application-group=%{GLOBAL}
WSGIApplicationGroup %{GLOBAL}
SSLEngine On
SSLCertificateFile /opt/pki/certs.crt
SSLCertificateKeyFile /opt/pki/certs.key
SSLCertificateChainFile /opt/pki/certs.pem
<Directory /var/www/someservice/someservice_service>
</Directory>
<Location /python_service>
WSGIProcessGroup python_service
</Location>
</VirtualHost>
I also increased Timeout and SSLSessionCacheTimeout in the apache2.conf in the entrypoint.sh which the docker container calls on startup:
sed -i "s/Timeout 300/Timeout 1800/g" /etc/apache2/apache2.conf
sed -i "s/SSLSessionCacheTimeout 300/SSLSessionCacheTimeout 1800/g" /etc/apache2/mods-available/ssl.conf
apachectl -D FOREGROUND
I did a run with maximum trace logs below. I shortened / censored some logs.
Date,Message
"2025-06-23T08:05:01.804Z","[Mon Jun 23 08:05:01.804413 2025] [wsgi:error] [pid 28:tid 410] [remote <client-ip>:58971] INFO in someservice_service_controller: Last log here"
"2025-06-23T08:05:01.804Z","[Mon Jun 23 08:05:01.804779 2025] [core:trace6] [pid 28:tid 410] core_filters.c(828): [remote <client-ip>:58971] writev_nonblocking: 229/229"
"2025-06-23T08:05:01.804Z","[Mon Jun 23 08:05:01.804806 2025] [filter:trace4] [pid 30:tid 36] mod_filter.c(168): [client <client-ip>:58971] Content-Type 'application/json' ..."
"2025-06-23T08:05:01.804Z","[Mon Jun 23 08:05:01.804822 2025] [filter:trace4] [pid 30:tid 36] mod_filter.c(180): [client <client-ip>:58971] ... did not match 'application/xml'"
"2025-06-23T08:05:01.804Z","[Mon Jun 23 08:05:01.804825 2025] [filter:trace2] [pid 30:tid 36] mod_filter.c(185): [client <client-ip>:58971] Content-Type condition for 'deflate' did not match"
"2025-06-23T08:05:01.804Z","[Mon Jun 23 08:05:01.804828 2025] [filter:trace4] [pid 30:tid 36] mod_filter.c(168): [client <client-ip>:58971] Content-Type 'application/json' ..."
"2025-06-23T08:05:01.804Z","[Mon Jun 23 08:05:01.804830 2025] [filter:trace4] [pid 30:tid 36] mod_filter.c(180): [client <client-ip>:58971] ... did not match 'application/wasm'"
"2025-06-23T08:05:01.804Z","[Mon Jun 23 08:05:01.804831 2025] [filter:trace2] [pid 30:tid 36] mod_filter.c(185): [client <client-ip>:58971] Content-Type condition for 'deflate' did not match"
"2025-06-23T08:05:01.804Z","[Mon Jun 23 08:05:01.804833 2025] [filter:trace4] [pid 30:tid 36] mod_filter.c(168): [client <client-ip>:58971] Content-Type 'application/json' ..."
"2025-06-23T08:05:01.804Z","[Mon Jun 23 08:05:01.804835 2025] [filter:trace4] [pid 30:tid 36] mod_filter.c(180): [client <client-ip>:58971] ... did not match 'application/rss+xml'"
"2025-06-23T08:05:01.804Z","[Mon Jun 23 08:05:01.804837 2025] [filter:trace2] [pid 30:tid 36] mod_filter.c(185): [client <client-ip>:58971] Content-Type condition for 'deflate' did not match"
"2025-06-23T08:05:01.804Z","[Mon Jun 23 08:05:01.804839 2025] [filter:trace4] [pid 30:tid 36] mod_filter.c(168): [client <client-ip>:58971] Content-Type 'application/json' ..."
"2025-06-23T08:05:01.804Z","[Mon Jun 23 08:05:01.804841 2025] [filter:trace4] [pid 30:tid 36] mod_filter.c(180): [client <client-ip>:58971] ... did not match 'application/x-javascript'"
"2025-06-23T08:05:01.804Z","[Mon Jun 23 08:05:01.804843 2025] [filter:trace4] [pid 30:tid 36] mod_filter.c(180): [client <client-ip>:58971] ... did not match 'application/javascript'"
"2025-06-23T08:05:01.804Z","[Mon Jun 23 08:05:01.804844 2025] [filter:trace4] [pid 30:tid 36] mod_filter.c(180): [client <client-ip>:58971] ... did not match 'application/ecmascript'"
"2025-06-23T08:05:01.804Z","[Mon Jun 23 08:05:01.804846 2025] [filter:trace2] [pid 30:tid 36] mod_filter.c(185): [client <client-ip>:58971] Content-Type condition for 'deflate' did not match"
"2025-06-23T08:05:01.804Z","[Mon Jun 23 08:05:01.804848 2025] [filter:trace4] [pid 30:tid 36] mod_filter.c(168): [client <client-ip>:58971] Content-Type 'application/json' ..."
"2025-06-23T08:05:01.804Z","[Mon Jun 23 08:05:01.804850 2025] [filter:trace4] [pid 30:tid 36] mod_filter.c(180): [client <client-ip>:58971] ... did not match 'text/html'"
"2025-06-23T08:05:01.804Z","[Mon Jun 23 08:05:01.804852 2025] [filter:trace4] [pid 30:tid 36] mod_filter.c(180): [client <client-ip>:58971] ... did not match 'text/plain'"
"2025-06-23T08:05:01.804Z","[Mon Jun 23 08:05:01.804854 2025] [filter:trace4] [pid 30:tid 36] mod_filter.c(180): [client <client-ip>:58971] ... did not match 'text/xml'"
"2025-06-23T08:05:01.804Z","[Mon Jun 23 08:05:01.804855 2025] [filter:trace4] [pid 30:tid 36] mod_filter.c(180): [client <client-ip>:58971] ... did not match 'text/css'"
"2025-06-23T08:05:01.804Z","[Mon Jun 23 08:05:01.804857 2025] [filter:trace4] [pid 30:tid 36] mod_filter.c(180): [client <client-ip>:58971] ... did not match 'text/javascript'"
"2025-06-23T08:05:01.804Z","[Mon Jun 23 08:05:01.804859 2025] [filter:trace2] [pid 30:tid 36] mod_filter.c(185): [client <client-ip>:58971] Content-Type condition for 'deflate' did not match"
"2025-06-23T08:05:01.804Z","[Mon Jun 23 08:05:01.804870 2025] [http:trace3] [pid 30:tid 36] http_filters.c(1141): [client <client-ip>:58971] Response sent with status 200, headers:"
"2025-06-23T08:05:01.804Z","[Mon Jun 23 08:05:01.804877 2025] [http:trace5] [pid 30:tid 36] http_filters.c(1150): [client <client-ip>:58971] Date: Mon, 23 Jun 2025 07:56:07 GMT"
"2025-06-23T08:05:01.804Z","[Mon Jun 23 08:05:01.804880 2025] [http:trace5] [pid 30:tid 36] http_filters.c(1153): [client <client-ip>:58971] Server: Apache/2.4.62 (Debian)"
"2025-06-23T08:05:01.804Z","[Mon Jun 23 08:05:01.804882 2025] [http:trace4] [pid 30:tid 36] http_filters.c(971): [client <client-ip>:58971] WWW-Authenticate: Negotiate YIGZBgkqhkiG9...<cut short>"
"2025-06-23T08:05:01.804Z","[Mon Jun 23 08:05:01.804885 2025] [http:trace4] [pid 30:tid 36] http_filters.c(971): [client <client-ip>:58971] Content-Length: 158"
"2025-06-23T08:05:01.804Z","[Mon Jun 23 08:05:01.804887 2025] [http:trace4] [pid 30:tid 36] http_filters.c(971): [client <client-ip>:58971] Content-Type: application/json"
"2025-06-23T08:05:01.804Z","[Mon Jun 23 08:05:01.804909 2025] [ssl:trace4] [pid 30:tid 36] ssl_engine_io.c(1856): [client <client-ip>:58971] coalesce: have 0 bytes, adding 379 more (buckets=1)"
"2025-06-23T08:05:01.804Z","[Mon Jun 23 08:05:01.804917 2025] [ssl:trace4] [pid 30:tid 36] ssl_engine_io.c(1856): [client <client-ip>:58971] coalesce: have 379 bytes, adding 158 more (buckets=1)"
"2025-06-23T08:05:01.804Z","[Mon Jun 23 08:05:01.804922 2025] [ssl:trace4] [pid 30:tid 36] ssl_engine_io.c(1919): [client <client-ip>:58971] coalesce: passing on 537 bytes"
"2025-06-23T08:05:01.804Z","[Mon Jun 23 08:05:01.804929 2025] [ssl:trace6] [pid 30:tid 36] ssl_engine_io.c(894): [client <client-ip>:58971] ssl_filter_write: 537 bytes"
"2025-06-23T08:05:01.804Z","[Mon Jun 23 08:05:01.804966 2025] [ssl:trace6] [pid 30:tid 36] ssl_engine_io.c(219): [client <client-ip>:58971] bio_filter_out_write: 566 bytes"
"2025-06-23T08:05:01.804Z","[Mon Jun 23 08:05:01.804974 2025] [ssl:trace4] [pid 30:tid 36] ssl_engine_io.c(2428): [client <client-ip>:58971] OpenSSL: write 566/566 bytes to BIO#7fdee0002c50 [mem: 7fdee000e633] (BIO dump follows)"
"2025-06-23T08:05:01.804Z","[Mon Jun 23 08:05:01.804978 2025] [ssl:trace7] [pid 30:tid 36] ssl_engine_io.c(2325): [client <client-ip>:58971] +-------------------------------------------------------------------------+"
"2025-06-23T08:05:01.805Z","[Mon Jun 23 08:05:01.805082 2025] [ssl:trace7] [pid 30:tid 36] ssl_engine_io.c(2362): [client <client-ip>:58971] | <some SSL key here>
"2025-06-23T08:05:01.805Z","[Mon Jun 23 08:05:01.805084 2025] [ssl:trace7] [pid 30:tid 36] ssl_engine_io.c(2367): [client <client-ip>:58971] +-------------------------------------------------------------------------+"
"2025-06-23T08:05:01.805Z","[Mon Jun 23 08:05:01.805086 2025] [ssl:trace6] [pid 30:tid 36] ssl_engine_io.c(894): [client <client-ip>:58971] ssl_filter_write: 0 bytes"
"2025-06-23T08:05:01.805Z","[Mon Jun 23 08:05:01.805147 2025] [core:trace6] [pid 30:tid 36] core_filters.c(828): [client <client-ip>:58971] writev_nonblocking: 566/566"
"2025-06-23T08:05:01.805Z","[Mon Jun 23 08:05:01.805221 2025] [ssl:trace4] [pid 30:tid 36] ssl_engine_io.c(2448): [client <client-ip>:58971] OpenSSL: I/O error, 5 bytes expected to write on BIO#7fdee0002d10 [mem: 7fdee000e633]"
"2025-06-23T08:05:01.805Z","[Mon Jun 23 08:05:01.805266 2025] [mpm_event:trace7] [pid 30:tid 83] event.c(1798): (4)Interrupted system call: polled with num=0 exit=0/0 conns=1 queues_timeout=4999969 timers_timeout=-1750665901805265"
"2025-06-23T08:05:01.805Z","[Mon Jun 23 08:05:01.805282 2025] [mpm_event:trace6] [pid 30:tid 83] event.c(1704): connections: 1 (clogged: 0 write-completion: 0 keep-alive: 1 lingering: 0 suspended: 0)"
"2025-06-23T08:05:01.805Z","[Mon Jun 23 08:05:01.805286 2025] [mpm_event:trace7] [pid 30:tid 83] event.c(1778): polling with timeout=5000000 queues_timeout=4999948 timers_timeout=-1750665901805286"
"2025-06-23T08:05:02.179Z","<client-ip> - sommer [23/Jun/2025:07:56:07 +0000] ""POST /python_service/queryV2 HTTP/1.1"" 200 158"
"2025-06-23T08:05:06.807Z","[Mon Jun 23 08:05:06.807754 2025] [mpm_event:trace7] [pid 30:tid 83] event.c(1798): (70007)The timeout specified has expired: polled with num=0 exit=0/0 conns=1 queues_timeout=-2518 timers_timeout=-1750665906807752"
"2025-06-23T08:05:06.807Z","[Mon Jun 23 08:05:06.807777 2025] [mpm_event:trace7] [pid 30:tid 83] event.c(1973): queues maintenance with timeout=-2543"
"2025-06-23T08:05:06.807Z","[Mon Jun 23 08:05:06.807787 2025] [mpm_event:trace6] [pid 30:tid 83] event.c(842): [remote <client-ip>:58971] deferring close from state 0"
"2025-06-23T08:05:06.807Z","[Mon Jun 23 08:05:06.807790 2025] [mpm_event:trace7] [pid 30:tid 83] event.c(2001): queues maintained with timeout=-1"
"2025-06-23T08:05:06.807Z","[Mon Jun 23 08:05:06.807804 2025] [mpm_event:trace6] [pid 30:tid 83] event.c(1704): connections: 1 (clogged: 0 write-completion: 0 keep-alive: 0 lingering: 1 suspended: 0)"
"2025-06-23T08:05:06.807Z","[Mon Jun 23 08:05:06.807806 2025] [mpm_event:trace7] [pid 30:tid 83] event.c(1778): polling with timeout=-1 queues_timeout=-1750665906807806 timers_timeout=-1750665906807806"
"2025-06-23T08:05:06.807Z","[Mon Jun 23 08:05:06.807815 2025] [mpm_event:trace6] [pid 30:tid 53] event.c(1489): [client <client-ip>:58971] lingering close from state 5"
"2025-06-23T08:05:06.807Z","[Mon Jun 23 08:05:06.807857 2025] [ssl:trace6] [pid 30:tid 53] ssl_engine_io.c(219): [client <client-ip>:58971] bio_filter_out_write: 31 bytes"
"2025-06-23T08:05:06.807Z","[Mon Jun 23 08:05:06.807870 2025] [ssl:trace4] [pid 30:tid 53] ssl_engine_io.c(2428): [client <client-ip>:58971] OpenSSL: write 31/31 bytes to BIO#7fdee0002c50 [mem: 7fdeac003023] (BIO dump follows)"
"2025-06-23T08:05:06.807Z","[Mon Jun 23 08:05:06.807873 2025] [ssl:trace7] [pid 30:tid 53] ssl_engine_io.c(2325): [client <client-ip>:58971] +-------------------------------------------------------------------------+"
"2025-06-23T08:05:06.807Z","[Mon Jun 23 08:05:06.807878 2025] [ssl:trace7] [pid 30:tid 53] ssl_engine_io.c(2362): [client <client-ip>:58971] | 0000: 15 03 03 00 1a e1 a8 f3-1f 7d 77 7c 05 19 ac 29 .........}w|...) |"
"2025-06-23T08:05:06.807Z","[Mon Jun 23 08:05:06.807889 2025] [ssl:trace7] [pid 30:tid 53] ssl_engine_io.c(2362): [client <client-ip>:58971] | 0010: 44 d0 fa 38 77 71 a7 54-35 57 bd ad 56 b8 19 D..8wq.T5W..V.. |"
"2025-06-23T08:05:06.807Z","[Mon Jun 23 08:05:06.807891 2025] [ssl:trace7] [pid 30:tid 53] ssl_engine_io.c(2367): [client <client-ip>:58971] +-------------------------------------------------------------------------+"
"2025-06-23T08:05:06.807Z","[Mon Jun 23 08:05:06.807894 2025] [ssl:trace6] [pid 30:tid 53] ssl_engine_io.c(154): [client <client-ip>:58971] bio_filter_out_write: flush"
"2025-06-23T08:05:06.807Z","[Mon Jun 23 08:05:06.807926 2025] [core:trace6] [pid 30:tid 53] core_filters.c(828): [client <client-ip>:58971] writev_nonblocking: 31/31"
"2025-06-23T08:05:06.807Z","[Mon Jun 23 08:05:06.807937 2025] [ssl:trace3] [pid 30:tid 53] ssl_engine_kernel.c(2220): [client <client-ip>:58971] OpenSSL: Write: SSL negotiation finished successfully"
"2025-06-23T08:05:06.807Z","[Mon Jun 23 08:05:06.807941 2025] [ssl:trace6] [pid 30:tid 53] ssl_engine_io.c(154): [client <client-ip>:58971] bio_filter_out_write: flush"
"2025-06-23T08:05:06.807Z","[Mon Jun 23 08:05:06.807944 2025] [ssl:debug] [pid 30:tid 53] ssl_engine_io.c(1150): [client <client-ip>:58971] AH02001: Connection closed to child 74 with standard shutdown (server someservice.de:443)"
"2025-06-23T08:05:06.808Z","[Mon Jun 23 08:05:06.808010 2025] [mpm_event:trace7] [pid 30:tid 83] event.c(1798): (4)Interrupted system call: polled with num=0 exit=0/0 conns=1 queues_timeout=1999972 timers_timeout=-1750665906808010"
"2025-06-23T08:05:06.808Z","[Mon Jun 23 08:05:06.808019 2025] [mpm_event:trace7] [pid 30:tid 83] event.c(1778): polling with timeout=2000000 queues_timeout=1999963 timers_timeout=-1750665906808019"
"2025-06-23T08:05:06.808Z","[Mon Jun 23 08:05:06.808340 2025] [mpm_event:trace7] [pid 30:tid 83] event.c(1798): polled with num=1 exit=0/0 conns=1 queues_timeout=1999642 timers_timeout=-1750665906808340"
"2025-06-23T08:05:06.808Z","[Mon Jun 23 08:05:06.808358 2025] [mpm_event:trace7] [pid 30:tid 83] event.c(1778): polling with timeout=2000000 queues_timeout=1999624 timers_timeout=-1750665906808358"
"2025-06-23T08:05:06.808Z","[Mon Jun 23 08:05:06.808368 2025] [mpm_event:trace6] [pid 30:tid 61] event.c(1489): [client <client-ip>:58971] lingering close from state 7"
"2025-06-23T08:05:06.808Z","[Mon Jun 23 08:05:06.808376 2025] [mpm_event:trace6] [pid 30:tid 61] event.c(872): [client <client-ip>:58971] closing connection from state 7"
"2025-06-23T08:05:06.808Z","[Mon Jun 23 08:05:06.808379 2025] [mpm_event:trace8] [pid 30:tid 61] event.c(544): closing socket 17/7fdeebd980b0 from close_connection:875"
"2025-06-23T08:05:06.808Z","[Mon Jun 23 08:05:06.808393 2025] [mpm_event:trace8] [pid 30:tid 61] event.c(789): [client <client-ip>:58971] cleanup connection from state 7"
"2025-06-23T08:05:08.810Z","[Mon Jun 23 08:05:08.810398 2025] [mpm_event:trace7] [pid 30:tid 83] event.c(1798): (70007)The timeout specified has expired: polled with num=0 exit=0/0 conns=0 queues_timeout=-2413 timers_timeout=-1750665908810395"
"2025-06-23T08:05:08.810Z","[Mon Jun 23 08:05:08.810436 2025] [mpm_event:trace7] [pid 30:tid 83] event.c(1973): queues maintenance with timeout=-2454"
"2025-06-23T08:05:08.810Z","[Mon Jun 23 08:05:08.810443 2025] [mpm_event:trace7] [pid 30:tid 83] event.c(2001): queues maintained with timeout=-1"
"2025-06-23T08:05:08.810Z","[Mon Jun 23 08:05:08.810447 2025] [mpm_event:trace6] [pid 30:tid 83] event.c(1704): connections: 0 (clogged: 0 write-completion: 0 keep-alive: 0 lingering: 0 suspended: 0)"
"2025-06-23T08:05:08.810Z","[Mon Jun 23 08:05:08.810452 2025] [mpm_event:trace7] [pid 30:tid 83] event.c(1778): polling with timeout=-1 queues_timeout=-1750665908810451 timers_timeout=-1750665908810451"
"2025-06-23T08:05:09.295Z","[Mon Jun 23 08:05:09.295204 2025] [mpm_event:trace7] [pid 30:tid 83] event.c(1798): polled with num=1 exit=0/0 conns=0 queues_timeout=-1750665909295201 timers_timeout=-1750665909295201"
"2025-06-23T08:05:09.295Z","[Mon Jun 23 08:05:09.295212 2025] [mpm_event:trace7] [pid 29:tid 84] event.c(1798): polled with num=1 exit=0/0 conns=0 queues_timeout=10421374 timers_timeout=-1750665909295210"
"2025-06-23T08:05:09.295Z","[Mon Jun 23 08:05:09.295252 2025] [mpm_event:trace7] [pid 30:tid 83] event.c(1778): polling with timeout=-1 queues_timeout=-1750665909295252 timers_timeout=-1750665909295252"
"2025-06-23T08:05:09.295Z","[Mon Jun 23 08:05:09.295269 2025] [mpm_event:trace6] [pid 29:tid 84] event.c(1704): connections: 0 (clogged: 0 write-completion: 0 keep-alive: 0 lingering: 0 suspended: 0)"
"2025-06-23T08:05:09.295Z","[Mon Jun 23 08:05:09.295275 2025] [mpm_event:trace7] [pid 29:tid 84] event.c(1778): polling with timeout=10422000 queues_timeout=10421309 timers_timeout=-1750665909295275"
"2025-06-23T08:05:09.295Z","[Mon Jun 23 08:05:09.295340 2025] [ssl:trace2] [pid 29:tid 70] ssl_engine_rand.c(125): Server: Seeding PRNG with 656 bytes of entropy"
"2025-06-23T08:05:09.295Z","[Mon Jun 23 08:05:09.295613 2025] [socache_shmcb:debug] [pid 29:tid 70] mod_socache_shmcb.c(545): AH00835: socache_shmcb_retrieve (0x07 -> subcache 7)"
"2025-06-23T08:05:09.295Z","[Mon Jun 23 08:05:09.295622 2025] [socache_shmcb:debug] [pid 29:tid 70] mod_socache_shmcb.c(929): AH00851: shmcb_subcache_retrieve found no match"
"2025-06-23T08:05:09.295Z","[Mon Jun 23 08:05:09.295625 2025] [socache_shmcb:debug] [pid 29:tid 70] mod_socache_shmcb.c(556): AH00836: leaving socache_shmcb_retrieve successfully"
"2025-06-23T08:05:09.295Z","[Mon Jun 23 08:05:09.295628 2025] [ssl:trace2] [pid 29:tid 70] ssl_engine_kernel.c(2058): Inter-Process Session Cache: request=GET status=MISSED id=07ee34a6580badff1e74a55dae0a23423c8263dc7b7e256af5519df8d7eb567f (session renewal)"
"2025-06-23T08:05:09.342Z","[Mon Jun 23 08:05:09.342211 2025] [mpm_event:trace7] [pid 29:tid 84] event.c(1798): polled with num=1 exit=0/0 conns=1 queues_timeout=10374374 timers_timeout=-1750665909342210"
"2025-06-23T08:05:09.342Z","[Mon Jun 23 08:05:09.342233 2025] [mpm_event:trace7] [pid 29:tid 84] event.c(1778): polling with timeout=10375000 queues_timeout=10374351 timers_timeout=-1750665909342233"
"2025-06-23T08:05:09.342Z","[Mon Jun 23 08:05:09.342262 2025] [mpm_event:trace8] [pid 29:tid 77] event.c(544): closing socket 17/7fdee87900b0 from close_connection:875"
- Apache 2.4.62
- mod_wsgi: 4.7.1
- Python: 3.8
Due to forking of the process using the multiprocessing package I switched to the prefork MPM. In the current long running requests that don't respond this forking doesn't happen, so it shouldn't be an issue here.
I had a look here https://groups.google.com/g/modwsgi/c/zuhFREjOE8M and massively increased all timeouts to test if this is the issue, but that doesn't seem to be the case.
<VirtualHost *:443>
ServerName someservice.de
WSGIDaemonProcess python_service processes=10 threads=1 display-name=someservice maximum-requests=200 python-home=/var/www/someservice/venv socket-timeout=1800 connect-timeout=1800 request-timeout=1800 graceful-timeout=1800 eviction-timeout=1800 queue-timeout=1800
WSGIScriptAlias /python_service /var/www/someservice/someservice_service/someservice_service_controller.py process-group=python_service application-group=%{GLOBAL}
WSGIApplicationGroup %{GLOBAL}
SSLEngine On
SSLCertificateFile /opt/pki/certs.crt
SSLCertificateKeyFile /opt/pki/certs.key
SSLCertificateChainFile /opt/pki/certs.pem
<Directory /var/www/someservice/someservice_service>
</Directory>
<Location /python_service>
WSGIProcessGroup python_service
</Location>
</VirtualHost>
I also increased Timeout and SSLSessionCacheTimeout in the apache2.conf in the entrypoint.sh which the docker container calls on startup:
sed -i "s/Timeout 300/Timeout 1800/g" /etc/apache2/apache2.conf
sed -i "s/SSLSessionCacheTimeout 300/SSLSessionCacheTimeout 1800/g" /etc/apache2/mods-available/ssl.conf
apachectl -D FOREGROUND
I did a run with maximum trace logs below. I shortened / censored some logs.
Date,Message
"2025-06-23T08:05:01.804Z","[Mon Jun 23 08:05:01.804413 2025] [wsgi:error] [pid 28:tid 410] [remote <client-ip>:58971] INFO in someservice_service_controller: Last log here"
"2025-06-23T08:05:01.804Z","[Mon Jun 23 08:05:01.804779 2025] [core:trace6] [pid 28:tid 410] core_filters.c(828): [remote <client-ip>:58971] writev_nonblocking: 229/229"
"2025-06-23T08:05:01.804Z","[Mon Jun 23 08:05:01.804806 2025] [filter:trace4] [pid 30:tid 36] mod_filter.c(168): [client <client-ip>:58971] Content-Type 'application/json' ..."
"2025-06-23T08:05:01.804Z","[Mon Jun 23 08:05:01.804822 2025] [filter:trace4] [pid 30:tid 36] mod_filter.c(180): [client <client-ip>:58971] ... did not match 'application/xml'"
"2025-06-23T08:05:01.804Z","[Mon Jun 23 08:05:01.804825 2025] [filter:trace2] [pid 30:tid 36] mod_filter.c(185): [client <client-ip>:58971] Content-Type condition for 'deflate' did not match"
"2025-06-23T08:05:01.804Z","[Mon Jun 23 08:05:01.804828 2025] [filter:trace4] [pid 30:tid 36] mod_filter.c(168): [client <client-ip>:58971] Content-Type 'application/json' ..."
"2025-06-23T08:05:01.804Z","[Mon Jun 23 08:05:01.804830 2025] [filter:trace4] [pid 30:tid 36] mod_filter.c(180): [client <client-ip>:58971] ... did not match 'application/wasm'"
"2025-06-23T08:05:01.804Z","[Mon Jun 23 08:05:01.804831 2025] [filter:trace2] [pid 30:tid 36] mod_filter.c(185): [client <client-ip>:58971] Content-Type condition for 'deflate' did not match"
"2025-06-23T08:05:01.804Z","[Mon Jun 23 08:05:01.804833 2025] [filter:trace4] [pid 30:tid 36] mod_filter.c(168): [client <client-ip>:58971] Content-Type 'application/json' ..."
"2025-06-23T08:05:01.804Z","[Mon Jun 23 08:05:01.804835 2025] [filter:trace4] [pid 30:tid 36] mod_filter.c(180): [client <client-ip>:58971] ... did not match 'application/rss+xml'"
"2025-06-23T08:05:01.804Z","[Mon Jun 23 08:05:01.804837 2025] [filter:trace2] [pid 30:tid 36] mod_filter.c(185): [client <client-ip>:58971] Content-Type condition for 'deflate' did not match"
"2025-06-23T08:05:01.804Z","[Mon Jun 23 08:05:01.804839 2025] [filter:trace4] [pid 30:tid 36] mod_filter.c(168): [client <client-ip>:58971] Content-Type 'application/json' ..."
"2025-06-23T08:05:01.804Z","[Mon Jun 23 08:05:01.804841 2025] [filter:trace4] [pid 30:tid 36] mod_filter.c(180): [client <client-ip>:58971] ... did not match 'application/x-javascript'"
"2025-06-23T08:05:01.804Z","[Mon Jun 23 08:05:01.804843 2025] [filter:trace4] [pid 30:tid 36] mod_filter.c(180): [client <client-ip>:58971] ... did not match 'application/javascript'"
"2025-06-23T08:05:01.804Z","[Mon Jun 23 08:05:01.804844 2025] [filter:trace4] [pid 30:tid 36] mod_filter.c(180): [client <client-ip>:58971] ... did not match 'application/ecmascript'"
"2025-06-23T08:05:01.804Z","[Mon Jun 23 08:05:01.804846 2025] [filter:trace2] [pid 30:tid 36] mod_filter.c(185): [client <client-ip>:58971] Content-Type condition for 'deflate' did not match"
"2025-06-23T08:05:01.804Z","[Mon Jun 23 08:05:01.804848 2025] [filter:trace4] [pid 30:tid 36] mod_filter.c(168): [client <client-ip>:58971] Content-Type 'application/json' ..."
"2025-06-23T08:05:01.804Z","[Mon Jun 23 08:05:01.804850 2025] [filter:trace4] [pid 30:tid 36] mod_filter.c(180): [client <client-ip>:58971] ... did not match 'text/html'"
"2025-06-23T08:05:01.804Z","[Mon Jun 23 08:05:01.804852 2025] [filter:trace4] [pid 30:tid 36] mod_filter.c(180): [client <client-ip>:58971] ... did not match 'text/plain'"
"2025-06-23T08:05:01.804Z","[Mon Jun 23 08:05:01.804854 2025] [filter:trace4] [pid 30:tid 36] mod_filter.c(180): [client <client-ip>:58971] ... did not match 'text/xml'"
"2025-06-23T08:05:01.804Z","[Mon Jun 23 08:05:01.804855 2025] [filter:trace4] [pid 30:tid 36] mod_filter.c(180): [client <client-ip>:58971] ... did not match 'text/css'"
"2025-06-23T08:05:01.804Z","[Mon Jun 23 08:05:01.804857 2025] [filter:trace4] [pid 30:tid 36] mod_filter.c(180): [client <client-ip>:58971] ... did not match 'text/javascript'"
"2025-06-23T08:05:01.804Z","[Mon Jun 23 08:05:01.804859 2025] [filter:trace2] [pid 30:tid 36] mod_filter.c(185): [client <client-ip>:58971] Content-Type condition for 'deflate' did not match"
"2025-06-23T08:05:01.804Z","[Mon Jun 23 08:05:01.804870 2025] [http:trace3] [pid 30:tid 36] http_filters.c(1141): [client <client-ip>:58971] Response sent with status 200, headers:"
"2025-06-23T08:05:01.804Z","[Mon Jun 23 08:05:01.804877 2025] [http:trace5] [pid 30:tid 36] http_filters.c(1150): [client <client-ip>:58971] Date: Mon, 23 Jun 2025 07:56:07 GMT"
"2025-06-23T08:05:01.804Z","[Mon Jun 23 08:05:01.804880 2025] [http:trace5] [pid 30:tid 36] http_filters.c(1153): [client <client-ip>:58971] Server: Apache/2.4.62 (Debian)"
"2025-06-23T08:05:01.804Z","[Mon Jun 23 08:05:01.804882 2025] [http:trace4] [pid 30:tid 36] http_filters.c(971): [client <client-ip>:58971] WWW-Authenticate: Negotiate YIGZBgkqhkiG9...<cut short>"
"2025-06-23T08:05:01.804Z","[Mon Jun 23 08:05:01.804885 2025] [http:trace4] [pid 30:tid 36] http_filters.c(971): [client <client-ip>:58971] Content-Length: 158"
"2025-06-23T08:05:01.804Z","[Mon Jun 23 08:05:01.804887 2025] [http:trace4] [pid 30:tid 36] http_filters.c(971): [client <client-ip>:58971] Content-Type: application/json"
"2025-06-23T08:05:01.804Z","[Mon Jun 23 08:05:01.804909 2025] [ssl:trace4] [pid 30:tid 36] ssl_engine_io.c(1856): [client <client-ip>:58971] coalesce: have 0 bytes, adding 379 more (buckets=1)"
"2025-06-23T08:05:01.804Z","[Mon Jun 23 08:05:01.804917 2025] [ssl:trace4] [pid 30:tid 36] ssl_engine_io.c(1856): [client <client-ip>:58971] coalesce: have 379 bytes, adding 158 more (buckets=1)"
"2025-06-23T08:05:01.804Z","[Mon Jun 23 08:05:01.804922 2025] [ssl:trace4] [pid 30:tid 36] ssl_engine_io.c(1919): [client <client-ip>:58971] coalesce: passing on 537 bytes"
"2025-06-23T08:05:01.804Z","[Mon Jun 23 08:05:01.804929 2025] [ssl:trace6] [pid 30:tid 36] ssl_engine_io.c(894): [client <client-ip>:58971] ssl_filter_write: 537 bytes"
"2025-06-23T08:05:01.804Z","[Mon Jun 23 08:05:01.804966 2025] [ssl:trace6] [pid 30:tid 36] ssl_engine_io.c(219): [client <client-ip>:58971] bio_filter_out_write: 566 bytes"
"2025-06-23T08:05:01.804Z","[Mon Jun 23 08:05:01.804974 2025] [ssl:trace4] [pid 30:tid 36] ssl_engine_io.c(2428): [client <client-ip>:58971] OpenSSL: write 566/566 bytes to BIO#7fdee0002c50 [mem: 7fdee000e633] (BIO dump follows)"
"2025-06-23T08:05:01.804Z","[Mon Jun 23 08:05:01.804978 2025] [ssl:trace7] [pid 30:tid 36] ssl_engine_io.c(2325): [client <client-ip>:58971] +-------------------------------------------------------------------------+"
"2025-06-23T08:05:01.805Z","[Mon Jun 23 08:05:01.805082 2025] [ssl:trace7] [pid 30:tid 36] ssl_engine_io.c(2362): [client <client-ip>:58971] | <some SSL key here>
"2025-06-23T08:05:01.805Z","[Mon Jun 23 08:05:01.805084 2025] [ssl:trace7] [pid 30:tid 36] ssl_engine_io.c(2367): [client <client-ip>:58971] +-------------------------------------------------------------------------+"
"2025-06-23T08:05:01.805Z","[Mon Jun 23 08:05:01.805086 2025] [ssl:trace6] [pid 30:tid 36] ssl_engine_io.c(894): [client <client-ip>:58971] ssl_filter_write: 0 bytes"
"2025-06-23T08:05:01.805Z","[Mon Jun 23 08:05:01.805147 2025] [core:trace6] [pid 30:tid 36] core_filters.c(828): [client <client-ip>:58971] writev_nonblocking: 566/566"
"2025-06-23T08:05:01.805Z","[Mon Jun 23 08:05:01.805221 2025] [ssl:trace4] [pid 30:tid 36] ssl_engine_io.c(2448): [client <client-ip>:58971] OpenSSL: I/O error, 5 bytes expected to write on BIO#7fdee0002d10 [mem: 7fdee000e633]"
"2025-06-23T08:05:01.805Z","[Mon Jun 23 08:05:01.805266 2025] [mpm_event:trace7] [pid 30:tid 83] event.c(1798): (4)Interrupted system call: polled with num=0 exit=0/0 conns=1 queues_timeout=4999969 timers_timeout=-1750665901805265"
"2025-06-23T08:05:01.805Z","[Mon Jun 23 08:05:01.805282 2025] [mpm_event:trace6] [pid 30:tid 83] event.c(1704): connections: 1 (clogged: 0 write-completion: 0 keep-alive: 1 lingering: 0 suspended: 0)"
"2025-06-23T08:05:01.805Z","[Mon Jun 23 08:05:01.805286 2025] [mpm_event:trace7] [pid 30:tid 83] event.c(1778): polling with timeout=5000000 queues_timeout=4999948 timers_timeout=-1750665901805286"
"2025-06-23T08:05:02.179Z","<client-ip> - sommer [23/Jun/2025:07:56:07 +0000] ""POST /python_service/queryV2 HTTP/1.1"" 200 158"
"2025-06-23T08:05:06.807Z","[Mon Jun 23 08:05:06.807754 2025] [mpm_event:trace7] [pid 30:tid 83] event.c(1798): (70007)The timeout specified has expired: polled with num=0 exit=0/0 conns=1 queues_timeout=-2518 timers_timeout=-1750665906807752"
"2025-06-23T08:05:06.807Z","[Mon Jun 23 08:05:06.807777 2025] [mpm_event:trace7] [pid 30:tid 83] event.c(1973): queues maintenance with timeout=-2543"
"2025-06-23T08:05:06.807Z","[Mon Jun 23 08:05:06.807787 2025] [mpm_event:trace6] [pid 30:tid 83] event.c(842): [remote <client-ip>:58971] deferring close from state 0"
"2025-06-23T08:05:06.807Z","[Mon Jun 23 08:05:06.807790 2025] [mpm_event:trace7] [pid 30:tid 83] event.c(2001): queues maintained with timeout=-1"
"2025-06-23T08:05:06.807Z","[Mon Jun 23 08:05:06.807804 2025] [mpm_event:trace6] [pid 30:tid 83] event.c(1704): connections: 1 (clogged: 0 write-completion: 0 keep-alive: 0 lingering: 1 suspended: 0)"
"2025-06-23T08:05:06.807Z","[Mon Jun 23 08:05:06.807806 2025] [mpm_event:trace7] [pid 30:tid 83] event.c(1778): polling with timeout=-1 queues_timeout=-1750665906807806 timers_timeout=-1750665906807806"
"2025-06-23T08:05:06.807Z","[Mon Jun 23 08:05:06.807815 2025] [mpm_event:trace6] [pid 30:tid 53] event.c(1489): [client <client-ip>:58971] lingering close from state 5"
"2025-06-23T08:05:06.807Z","[Mon Jun 23 08:05:06.807857 2025] [ssl:trace6] [pid 30:tid 53] ssl_engine_io.c(219): [client <client-ip>:58971] bio_filter_out_write: 31 bytes"
"2025-06-23T08:05:06.807Z","[Mon Jun 23 08:05:06.807870 2025] [ssl:trace4] [pid 30:tid 53] ssl_engine_io.c(2428): [client <client-ip>:58971] OpenSSL: write 31/31 bytes to BIO#7fdee0002c50 [mem: 7fdeac003023] (BIO dump follows)"
"2025-06-23T08:05:06.807Z","[Mon Jun 23 08:05:06.807873 2025] [ssl:trace7] [pid 30:tid 53] ssl_engine_io.c(2325): [client <client-ip>:58971] +-------------------------------------------------------------------------+"
"2025-06-23T08:05:06.807Z","[Mon Jun 23 08:05:06.807878 2025] [ssl:trace7] [pid 30:tid 53] ssl_engine_io.c(2362): [client <client-ip>:58971] | 0000: 15 03 03 00 1a e1 a8 f3-1f 7d 77 7c 05 19 ac 29 .........}w|...) |"
"2025-06-23T08:05:06.807Z","[Mon Jun 23 08:05:06.807889 2025] [ssl:trace7] [pid 30:tid 53] ssl_engine_io.c(2362): [client <client-ip>:58971] | 0010: 44 d0 fa 38 77 71 a7 54-35 57 bd ad 56 b8 19 D..8wq.T5W..V.. |"
"2025-06-23T08:05:06.807Z","[Mon Jun 23 08:05:06.807891 2025] [ssl:trace7] [pid 30:tid 53] ssl_engine_io.c(2367): [client <client-ip>:58971] +-------------------------------------------------------------------------+"
"2025-06-23T08:05:06.807Z","[Mon Jun 23 08:05:06.807894 2025] [ssl:trace6] [pid 30:tid 53] ssl_engine_io.c(154): [client <client-ip>:58971] bio_filter_out_write: flush"
"2025-06-23T08:05:06.807Z","[Mon Jun 23 08:05:06.807926 2025] [core:trace6] [pid 30:tid 53] core_filters.c(828): [client <client-ip>:58971] writev_nonblocking: 31/31"
"2025-06-23T08:05:06.807Z","[Mon Jun 23 08:05:06.807937 2025] [ssl:trace3] [pid 30:tid 53] ssl_engine_kernel.c(2220): [client <client-ip>:58971] OpenSSL: Write: SSL negotiation finished successfully"
"2025-06-23T08:05:06.807Z","[Mon Jun 23 08:05:06.807941 2025] [ssl:trace6] [pid 30:tid 53] ssl_engine_io.c(154): [client <client-ip>:58971] bio_filter_out_write: flush"
"2025-06-23T08:05:06.807Z","[Mon Jun 23 08:05:06.807944 2025] [ssl:debug] [pid 30:tid 53] ssl_engine_io.c(1150): [client <client-ip>:58971] AH02001: Connection closed to child 74 with standard shutdown (server someservice.de:443)"
"2025-06-23T08:05:06.808Z","[Mon Jun 23 08:05:06.808010 2025] [mpm_event:trace7] [pid 30:tid 83] event.c(1798): (4)Interrupted system call: polled with num=0 exit=0/0 conns=1 queues_timeout=1999972 timers_timeout=-1750665906808010"
"2025-06-23T08:05:06.808Z","[Mon Jun 23 08:05:06.808019 2025] [mpm_event:trace7] [pid 30:tid 83] event.c(1778): polling with timeout=2000000 queues_timeout=1999963 timers_timeout=-1750665906808019"
"2025-06-23T08:05:06.808Z","[Mon Jun 23 08:05:06.808340 2025] [mpm_event:trace7] [pid 30:tid 83] event.c(1798): polled with num=1 exit=0/0 conns=1 queues_timeout=1999642 timers_timeout=-1750665906808340"
"2025-06-23T08:05:06.808Z","[Mon Jun 23 08:05:06.808358 2025] [mpm_event:trace7] [pid 30:tid 83] event.c(1778): polling with timeout=2000000 queues_timeout=1999624 timers_timeout=-1750665906808358"
"2025-06-23T08:05:06.808Z","[Mon Jun 23 08:05:06.808368 2025] [mpm_event:trace6] [pid 30:tid 61] event.c(1489): [client <client-ip>:58971] lingering close from state 7"
"2025-06-23T08:05:06.808Z","[Mon Jun 23 08:05:06.808376 2025] [mpm_event:trace6] [pid 30:tid 61] event.c(872): [client <client-ip>:58971] closing connection from state 7"
"2025-06-23T08:05:06.808Z","[Mon Jun 23 08:05:06.808379 2025] [mpm_event:trace8] [pid 30:tid 61] event.c(544): closing socket 17/7fdeebd980b0 from close_connection:875"
"2025-06-23T08:05:06.808Z","[Mon Jun 23 08:05:06.808393 2025] [mpm_event:trace8] [pid 30:tid 61] event.c(789): [client <client-ip>:58971] cleanup connection from state 7"
"2025-06-23T08:05:08.810Z","[Mon Jun 23 08:05:08.810398 2025] [mpm_event:trace7] [pid 30:tid 83] event.c(1798): (70007)The timeout specified has expired: polled with num=0 exit=0/0 conns=0 queues_timeout=-2413 timers_timeout=-1750665908810395"
"2025-06-23T08:05:08.810Z","[Mon Jun 23 08:05:08.810436 2025] [mpm_event:trace7] [pid 30:tid 83] event.c(1973): queues maintenance with timeout=-2454"
"2025-06-23T08:05:08.810Z","[Mon Jun 23 08:05:08.810443 2025] [mpm_event:trace7] [pid 30:tid 83] event.c(2001): queues maintained with timeout=-1"
"2025-06-23T08:05:08.810Z","[Mon Jun 23 08:05:08.810447 2025] [mpm_event:trace6] [pid 30:tid 83] event.c(1704): connections: 0 (clogged: 0 write-completion: 0 keep-alive: 0 lingering: 0 suspended: 0)"
"2025-06-23T08:05:08.810Z","[Mon Jun 23 08:05:08.810452 2025] [mpm_event:trace7] [pid 30:tid 83] event.c(1778): polling with timeout=-1 queues_timeout=-1750665908810451 timers_timeout=-1750665908810451"
"2025-06-23T08:05:09.295Z","[Mon Jun 23 08:05:09.295204 2025] [mpm_event:trace7] [pid 30:tid 83] event.c(1798): polled with num=1 exit=0/0 conns=0 queues_timeout=-1750665909295201 timers_timeout=-1750665909295201"
"2025-06-23T08:05:09.295Z","[Mon Jun 23 08:05:09.295212 2025] [mpm_event:trace7] [pid 29:tid 84] event.c(1798): polled with num=1 exit=0/0 conns=0 queues_timeout=10421374 timers_timeout=-1750665909295210"
"2025-06-23T08:05:09.295Z","[Mon Jun 23 08:05:09.295252 2025] [mpm_event:trace7] [pid 30:tid 83] event.c(1778): polling with timeout=-1 queues_timeout=-1750665909295252 timers_timeout=-1750665909295252"
"2025-06-23T08:05:09.295Z","[Mon Jun 23 08:05:09.295269 2025] [mpm_event:trace6] [pid 29:tid 84] event.c(1704): connections: 0 (clogged: 0 write-completion: 0 keep-alive: 0 lingering: 0 suspended: 0)"
"2025-06-23T08:05:09.295Z","[Mon Jun 23 08:05:09.295275 2025] [mpm_event:trace7] [pid 29:tid 84] event.c(1778): polling with timeout=10422000 queues_timeout=10421309 timers_timeout=-1750665909295275"
"2025-06-23T08:05:09.295Z","[Mon Jun 23 08:05:09.295340 2025] [ssl:trace2] [pid 29:tid 70] ssl_engine_rand.c(125): Server: Seeding PRNG with 656 bytes of entropy"
"2025-06-23T08:05:09.295Z","[Mon Jun 23 08:05:09.295613 2025] [socache_shmcb:debug] [pid 29:tid 70] mod_socache_shmcb.c(545): AH00835: socache_shmcb_retrieve (0x07 -> subcache 7)"
"2025-06-23T08:05:09.295Z","[Mon Jun 23 08:05:09.295622 2025] [socache_shmcb:debug] [pid 29:tid 70] mod_socache_shmcb.c(929): AH00851: shmcb_subcache_retrieve found no match"
"2025-06-23T08:05:09.295Z","[Mon Jun 23 08:05:09.295625 2025] [socache_shmcb:debug] [pid 29:tid 70] mod_socache_shmcb.c(556): AH00836: leaving socache_shmcb_retrieve successfully"
"2025-06-23T08:05:09.295Z","[Mon Jun 23 08:05:09.295628 2025] [ssl:trace2] [pid 29:tid 70] ssl_engine_kernel.c(2058): Inter-Process Session Cache: request=GET status=MISSED id=07ee34a6580badff1e74a55dae0a23423c8263dc7b7e256af5519df8d7eb567f (session renewal)"
"2025-06-23T08:05:09.342Z","[Mon Jun 23 08:05:09.342211 2025] [mpm_event:trace7] [pid 29:tid 84] event.c(1798): polled with num=1 exit=0/0 conns=1 queues_timeout=10374374 timers_timeout=-1750665909342210"
"2025-06-23T08:05:09.342Z","[Mon Jun 23 08:05:09.342233 2025] [mpm_event:trace7] [pid 29:tid 84] event.c(1778): polling with timeout=10375000 queues_timeout=10374351 timers_timeout=-1750665909342233"
"2025-06-23T08:05:09.342Z","[Mon Jun 23 08:05:09.342262 2025] [mpm_event:trace8] [pid 29:tid 77] event.c(544): closing socket 17/7fdee87900b0 from close_connection:875"
Graham Dumpleton
Jun 23, 2025, 5:19:14 PMJun 23
to mod...@googlegroups.com
When you say "don't end up in a response to the client" do you mean the HTTP client connection just hangs forever, or it disconnects and the client gets a HTTP error message, or it disconnects with no error message?
Note that in general having long running requests is a bad idea when using any WSGI server as WSGI request consumes a process or thread per request and so ties up resources used for handling requests. For long running requests, an asynchronous web server model is usually better.
Graham
--
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 modwsgi+u...@googlegroups.com.
To view this discussion visit https://groups.google.com/d/msgid/modwsgi/8b12cf75-301d-4e0e-8a41-c239a89885c5n%40googlegroups.com.
Maximilian Sommer
Jun 24, 2025, 3:36:14 AMJun 24
to modwsgi
Thank you for your quick response!
With "don't end up in a response to the client" I mean the connection hangs forever. The client never receives a response or a closed connection.I agree that the current setup isn't optimal or even good, but sadly this can't be refactored without major effort.
Graham Dumpleton
Jun 24, 2025, 3:40:28 AMJun 24
to mod...@googlegroups.com
Is the request meant to run that long though?
It sounds like it is getting stuck (potential deadlock or waiting for backend service) in a bad way.
Instead of trying to increase timeouts and hope it eventually returns a response, you would be better off enabling a realistic request timeout and force it to be aborted, with the stack trace that is logged being used to work out where it gets stuck.
Does the WSGI application handle multiple URLs under /python-service? If yes, is this a single URL request handler that has this issue?
Graham
To view this discussion visit https://groups.google.com/d/msgid/modwsgi/e20f388d-9c15-493a-8c65-083d401d625fn%40googlegroups.com.
Maximilian Sommer
Jun 24, 2025, 4:53:43 AMJun 24
to modwsgi
Yes, the request is meant to run that long. The Python code itself is fully functional and runs as expected according to the logs.
The WSGI application has several endpoints / URLs, all of which are functional. The endpoint in question pulls data from a backend service and transforms it according the clients request. This can take anywhere between several seconds up to several minutes.
In the example I am running, pulling the data takes around 5 min and transforming it around 4 min, but faster requests run through without any issues.
I've seen requests taking ~ 2-3 min being handled successfully, so I guess the threshold is around 3-5 min somewhere where some timeout applies. I haven't run any tests accurately pinpointing the exact threshold though.
Maximilian Sommer
Jun 24, 2025, 10:25:41 AMJun 24
to modwsgi
Dear Graham,
After a more thorough investigation I noticed that the issue is not mod_wsgi related. The indefinite connection seems to stem from the network.
I thank you for your time and apologize for wasting it.
I thank you for your time and apologize for wasting it.
Many regards
Maximilian
Reply all
Reply to author
Forward
0 new messages