Created
February 26, 2022 18:17
-
-
Save adelton/b4cd3d59b3f315a19a8814dcd307c340 to your computer and use it in GitHub Desktop.
Debugging why Django under mod_wsgi hangs on Fedora 35 (with python 3.10)
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
The handling of the request produces output, sends it to client but then never gets to logging the request in the access_log. | |
python3-3.10.2-1.fc35.x86_64 | |
apr-1.7.0-14.fc35.x86_64 | |
httpd-2.4.52-1.fc35.x86_64 | |
python3-mod_wsgi-4.9.0-1.fc35.x86_64 | |
(gdb) r -X | |
The program being debugged has been started already. | |
Start it from the beginning? (y or n) y | |
Starting program: /usr/sbin/httpd -X | |
[Thread debugging using libthread_db enabled] | |
Using host libthread_db library "/lib64/libthread_db.so.1". | |
[Sat Feb 26 19:09:38.021296 2022] [core:notice] [pid 13180:tid 13180] SELinux policy enabled; httpd running as context unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 | |
[Sat Feb 26 19:09:38.021717 2022] [suexec:notice] [pid 13180:tid 13180] AH01232: suEXEC mechanism enabled (wrapper: /usr/sbin/suexec) | |
Invalid cast. | |
warning: Probes-based dynamic linker interface failed. | |
Reverting to original interface. | |
warning: Temporarily disabling breakpoints for unloaded shared library "/etc/httpd/modules/mod_wsgi_python3.so" | |
[Sat Feb 26 19:09:39.755132 2022] [lbmethod_heartbeat:notice] [pid 13180:tid 13180] AH02282: No slotmem from mod_heartmonitor | |
[Detaching after fork from child process 13181] | |
[Sat Feb 26 19:09:39.755758 2022] [core:warn] [pid 13180:tid 13180] AH00098: pid file /etc/httpd/run/httpd.pid overwritten -- Unclean shutdown of previous Apache run? | |
[New Thread 0x7ffff6b71640 (LWP 13182)] | |
[...] | |
[New Thread 0x7fff96ff5640 (LWP 13250)] | |
[Thread 0x7fffdd6da640 (LWP 13224) exited] | |
[Switching to Thread 0x7fffdced9640 (LWP 13225)] | |
Thread 45 "httpd" hit Breakpoint 3, Adapter_run (object=0x7fff967931c0, self=0x7fff96742e70) at src/server/mod_wsgi.c:3030 | |
3030 if (wsgi_idle_timeout && !self->config->ignore_activity) { | |
(gdb) i b | |
Num Type Disp Enb Address What | |
2 breakpoint keep y 0x00007ffff6fb2e90 in Adapter_output at src/server/mod_wsgi.c:2172 | |
3 breakpoint keep y 0x00007ffff6fba3c7 in Adapter_run at src/server/mod_wsgi.c:3030 | |
breakpoint already hit 1 time | |
(gdb) c | |
Continuing. | |
Thread 45 "httpd" hit Breakpoint 2, Adapter_output (self=self@entry=0x7fff96742e70, data=data@entry=0x7fffd0571200 "\n<html>\n <head>\n <link rel=\"icon\" type=\"image/png\" href=\"data:image/png;base64,iVBORw0KGgo=\" />\n <link rel=\"stylesheet\" type=\"text/css\" href=\"/static/admin/css/base.css\" />\n <style>\n #c"..., length=661, string_object=string_object@entry=0x7fffd05711e0, exception_when_aborted=exception_when_aborted@entry=0) at src/server/mod_wsgi.c:2172 | |
2172 { | |
(gdb) c | |
Continuing. | |
Thread 45 "httpd" hit Breakpoint 2, Adapter_output (self=self@entry=0x7fff96742e70, data=data@entry=0x7ffff6fd6ad6 "", length=length@entry=0, string_object=string_object@entry=0x0, exception_when_aborted=exception_when_aborted@entry=0) at src/server/mod_wsgi.c:2172 | |
2172 { | |
(gdb) s | |
2181 if (wsgi_idle_timeout && !self->config->ignore_activity) { | |
(gdb) n | |
2193 if (!self->status_line) { | |
(gdb) | |
2198 r = self->r; | |
(gdb) | |
2202 output_start = apr_time_now(); | |
(gdb) | |
2206 if (string_object) | |
(gdb) | |
2211 if (self->headers) { | |
(gdb) | |
2351 if (length) { | |
(gdb) | |
2469 output_finish = apr_time_now(); | |
(gdb) | |
2471 if (output_finish > output_start) | |
(gdb) | |
2472 self->output_time += (output_finish - output_start); | |
(gdb) | |
2485 if (r->connection->aborted) { | |
(gdb) | |
Adapter_run (object=0x7fff967931c0, self=<optimized out>) at src/server/mod_wsgi.c:3234 | |
3234 self->result = OK; | |
(gdb) | |
warning: Source file is more recent than executable. | |
566 if (op != NULL) { | |
(gdb) | |
3253 Py_XDECREF(iterator); | |
(gdb) | |
wsgi_execute_script (r=<optimized out>) at src/server/mod_wsgi.c:4215 | |
4215 status = Adapter_run(adapter, object); | |
(gdb) s | |
Adapter_run (object=<optimized out>, self=<optimized out>) at src/server/mod_wsgi.c:3253 | |
3253 Py_XDECREF(iterator); | |
(gdb) n | |
3262 if (self->content_length_set && ((!PyErr_Occurred() && !aborted && | |
(gdb) | |
3273 if (PyErr_Occurred()) { | |
(gdb) | |
3297 if (PyObject_HasAttrString(self->sequence, "close")) { | |
(gdb) | |
3301 close = PyObject_GetAttrString(self->sequence, "close"); | |
(gdb) | |
3303 args = Py_BuildValue("()"); | |
(gdb) | |
3304 data = PyObject_CallObject(close, args); | |
(gdb) s | |
PyObject_CallObject (callable=0x7fff9668ea00, args=0x7fffdd747c40) at /usr/src/debug/python3.10-3.10.2-1.fc35.x86_64/Objects/call.c:388 | |
388 { | |
(gdb) n | |
389 PyThreadState *tstate = _PyThreadState_GET(); | |
(gdb) | |
391 if (args == NULL) { | |
(gdb) | |
394 if (!PyTuple_Check(args)) { | |
(gdb) | |
399 return _PyObject_Call(tstate, callable, args, NULL); | |
(gdb) | |
_PyObject_Call (tstate=0x7fffd00288c0, callable=0x7fff9668ea00, args=0x7fffdd747c40, kwargs=0x0) at /usr/src/debug/python3.10-3.10.2-1.fc35.x86_64/Objects/call.c:278 | |
278 { | |
(gdb) | |
69 tp = Py_TYPE(callable); | |
(gdb) | |
289 if (PyVectorcall_Function(callable) != NULL) { | |
(gdb) | |
77 return ptr; | |
(gdb) | |
290 return PyVectorcall_Call(callable, args, kwargs); | |
(gdb) | |
PyVectorcall_Call (callable=0x7fff9668ea00, tuple=0x7fffdd747c40, kwargs=0x0) at /usr/src/debug/python3.10-3.10.2-1.fc35.x86_64/Objects/call.c:230 | |
230 { | |
(gdb) | |
231 PyThreadState *tstate = _PyThreadState_GET(); | |
(gdb) | |
236 Py_ssize_t offset = Py_TYPE(callable)->tp_vectorcall_offset; | |
(gdb) | |
237 if (offset <= 0) { | |
(gdb) | |
244 if (func == NULL) { | |
(gdb) | |
251 Py_ssize_t nargs = PyTuple_GET_SIZE(tuple); | |
(gdb) | |
254 if (kwargs == NULL || PyDict_GET_SIZE(kwargs) == 0) { | |
(gdb) | |
255 return func(callable, _PyTuple_ITEMS(tuple), nargs, NULL); | |
(gdb) | |
method_vectorcall (method=0x7fff9668ea00, args=0x7fffdd747c58, nargsf=0, kwnames=0x0) at /usr/src/debug/python3.10-3.10.2-1.fc35.x86_64/Objects/classobject.c:38 | |
38 { | |
(gdb) | |
44 Py_ssize_t nargs = PyVectorcall_NARGS(nargsf); | |
(gdb) | |
41 PyThreadState *tstate = _PyThreadState_GET(); | |
(gdb) | |
42 PyObject *self = PyMethod_GET_SELF(method); | |
(gdb) | |
47 if (nargsf & PY_VECTORCALL_ARGUMENTS_OFFSET) { | |
(gdb) | |
58 Py_ssize_t nkwargs = (kwnames == NULL) ? 0 : PyTuple_GET_SIZE(kwnames); | |
(gdb) | |
60 if (totalargs == 0) { | |
(gdb) | |
61 return _PyObject_VectorcallTstate(tstate, func, &self, 1, NULL); | |
(gdb) s | |
_PyObject_VectorcallTstate (kwnames=0x0, nargsf=1, args=0x7fffdced88b8, callable=0x7fffb07d4ee0, tstate=0x7fffd00288c0) | |
at /usr/src/debug/python3.10-3.10.2-1.fc35.x86_64/Include/cpython/abstract.h:109 | |
109 func = PyVectorcall_Function(callable); | |
(gdb) n | |
114 res = func(callable, args, nargsf, kwnames); | |
(gdb) s | |
_PyFunction_Vectorcall (kwnames=0x0, nargsf=1, stack=0x7fffdced88b8, func=0x7fffb07d4ee0) | |
at /usr/src/debug/python3.10-3.10.2-1.fc35.x86_64/Objects/call.c:339 | |
339 PyThreadState *tstate = _PyThreadState_GET(); | |
(gdb) s | |
_PyThreadState_GET () at /usr/src/debug/python3.10-3.10.2-1.fc35.x86_64/Include/internal/pycore_pystate.h:81 | |
Downloading 0.00 MB source file /usr/src/debug/python3.10-3.10.2-1.fc35.x86_64/Include/internal/pycore_pystate.h | |
81 return _PyRuntimeState_GetThreadState(&_PyRuntime); | |
(gdb) s | |
_PyRuntimeState_GetThreadState (runtime=<optimized out>) at /usr/src/debug/python3.10-3.10.2-1.fc35.x86_64/Objects/call.c:332 | |
332 _PyFunction_Vectorcall(PyObject *func, PyObject* const* stack, | |
(gdb) s | |
_PyEval_Vector (tstate=0x7fffd00288c0, con=0x7fffb07d4ef0, locals=0x0, args=0x7fffdced88b8, argcount=1, kwnames=0x0) at /usr/src/debug/python3.10-3.10.2-1.fc35.x86_64/Python/ceval.c:5056 | |
Downloading -0.00 MB source file /usr/src/debug/python3.10-3.10.2-1.fc35.x86_64/Python/ceval.c | |
5056 { | |
(gdb) n | |
5057 PyFrameObject *f = _PyEval_MakeFrameVector( | |
(gdb) n | |
5062 if (((PyCodeObject *)con->fc_code)->co_flags & (CO_GENERATOR | CO_COROUTINE | CO_ASYNC_GENERATOR)) { | |
(gdb) n | |
5065 PyObject *retval = _PyEval_EvalFrame(tstate, f, 0); | |
(gdb) n | |
... and this never returns | |
^C | |
Thread 70 "httpd" received signal SIGHUP, Hangup. | |
[Switching to Thread 0x7fff96ff5640 (LWP 13250)] | |
0x00007ffff7c71c2e in epoll_wait (epfd=8, events=0x55555581a400, maxevents=52, timeout=-1) at ../sysdeps/unix/sysv/linux/epoll_wait.c:30 | |
30 return SYSCALL_CANCEL (epoll_wait, epfd, events, maxevents, timeout); |
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment