Bug 867276 - mod_wsgi crashes after httpd restart
mod_wsgi crashes after httpd restart
Status: CLOSED CURRENTRELEASE
Product: Fedora
Classification: Fedora
Component: mod_wsgi (Show other bugs)
18
Unspecified Unspecified
unspecified Severity unspecified
: ---
: ---
Assigned To: Matthias Runge
Fedora Extras Quality Assurance
:
Depends On:
Blocks:
  Show dependency treegraph
 
Reported: 2012-10-17 04:22 EDT by Martin Kosek
Modified: 2012-12-14 07:17 EST (History)
5 users (show)

See Also:
Fixed In Version: mod_wsgi-3.4-3.fc19
Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of:
Environment:
Last Closed: 2012-12-14 07:17:16 EST
Type: Bug
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:
Category: ---
oVirt Team: ---
RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: ---


Attachments (Terms of Use)

  None (edit)
Description Martin Kosek 2012-10-17 04:22:50 EDT
Description of problem:

This issue may be related to Bug 831701. When I restart httpd and run an FreeIPA command (which generates an XML-RPC request for Python application running on mod_wsgi), I get a mod_wsgi crash.

Additional commands run after the crash seems to be OK:

httpd error log:
[Wed Oct 17 04:14:06.729121 2012] [core:notice] [pid 12040] SELinux policy enabled; httpd running as context system_u:system_r:httpd_t:s0
[Wed Oct 17 04:14:06.731499 2012] [suexec:notice] [pid 12040] AH01232: suEXEC mechanism enabled (wrapper: /usr/sbin/suexec)
[Wed Oct 17 04:14:07.272325 2012] [auth_digest:notice] [pid 12042] AH01757: generating secret for digest authentication ...
[Wed Oct 17 04:14:08.001072 2012] [lbmethod_heartbeat:notice] [pid 12042] AH02282: No slotmem from mod_heartmonitor
[Wed Oct 17 04:14:08.134728 2012] [mpm_prefork:notice] [pid 12042] AH00163: Apache/2.4.2 (Unix) mod_auth_kerb/5.4 mod_nss/2.4.2 NSS/3.13.5.0 mod_wsgi/3.4 Python/2.7.3 configured -- resuming normal operations
[Wed Oct 17 04:14:08.142091 2012] [core:notice] [pid 12042] AH00094: Command line: '/usr/sbin/httpd'
[Wed Oct 17 04:14:13.154273 2012] [:error] [pid 12044] ipa: INFO: *** PROCESS START ***
[Wed Oct 17 04:14:13.159429 2012] [:error] [pid 12043] ipa: INFO: *** PROCESS START ***
[Wed Oct 17 04:14:51.346852 2012] [:error] [pid 12044] ipa: INFO: admin@IDM.LAB.BOS.REDHAT.COM: ping(): SUCCESS
[Wed Oct 17 04:14:51.793089 2012] [:error] [pid 12043] ipa: INFO: admin@IDM.LAB.BOS.REDHAT.COM: user_find(None, whoami=False, all=False, raw=False, version=u'2.44', pkey_only=False): SUCCESS

[Wed Oct 17 04:14:52.190700 2012] [core:notice] [pid 12042] AH00052: child pid 12044 exit signal Segmentation fault (11)

[Wed Oct 17 04:14:54.596847 2012] [:error] [pid 12088] ipa: INFO: *** PROCESS START ***

[Wed Oct 17 04:17:43.378503 2012] [core:notice] [pid 12042] AH00052: child pid 12043 exit signal Segmentation fault (11)

[Wed Oct 17 04:17:45.452093 2012] [:error] [pid 12106] ipa: INFO: *** PROCESS START ***
[Wed Oct 17 04:17:52.649147 2012] [:error] [pid 12088] ipa: INFO: admin@IDM.LAB.BOS.REDHAT.COM: ping(): SUCCESS
[Wed Oct 17 04:17:53.001259 2012] [:error] [pid 12106] ipa: INFO: admin@IDM.LAB.BOS.REDHAT.COM: user_find(None, whoami=False, all=False, raw=False, version=u'2.44', pkey_only=False): SUCCESS
[Wed Oct 17 04:17:56.795844 2012] [:error] [pid 12088] ipa: INFO: admin@IDM.LAB.BOS.REDHAT.COM: ping(): SUCCESS
[Wed Oct 17 04:17:56.930904 2012] [:error] [pid 12106] ipa: INFO: admin@IDM.LAB.BOS.REDHAT.COM: user_find(None, whoami=False, all=False, raw=False, version=u'2.44', pkey_only=False): SUCCESS


gdb stacktrace for crashed process:

# gdb -p $MOD_WSGI_PID
...
(gdb) continue
Continuing.
warning: cannot close "/usr/lib/krb5/plugins/libkrb5/sssd_krb5_locator_plugin.so": Invalid operation

Program received signal SIGSEGV, Segmentation fault.
[Switching to Thread 0xb39f1b40 (LWP 12066)]
0xb771ee4d in update_child_status_internal (child_num=-1, thread_num=0, status=8, c=0x0, r=0x0)
    at scoreboard.c:460
460	    ws = &ap_scoreboard_image->servers[child_num][thread_num];
(gdb) where
#0  0xb771ee4d in update_child_status_internal (child_num=-1, thread_num=0, status=8, c=0x0, r=0x0)
    at scoreboard.c:460
#1  0xb771faf3 in ap_update_child_status (sbh=0x8, status=0, status@entry=8, r=r@entry=0x0)
    at scoreboard.c:526
#2  0xb774256c in ap_start_lingering_close (c=c@entry=0xb81e12c8) at connection.c:106
#3  0xb7742607 in ap_lingering_close (c=c@entry=0xb81e12c8) at connection.c:147
#4  0xb6b3bb37 in wsgi_process_socket (bucket_alloc=0xb81e5ca8, sock=<optimized out>, 
    p=<optimized out>, daemon=<optimized out>) at mod_wsgi.c:10672
#5  wsgi_daemon_worker (thread=0xb81d8268, p=0xb81df018) at mod_wsgi.c:10993
#6  wsgi_daemon_thread (thd=0xb81d8300, data=0xb81d8268) at mod_wsgi.c:11026
#7  0xb73fe1d5 in dummy_worker (opaque=0xb81d8300) at threadproc/unix/thread.c:142
#8  0xb73c5aff in start_thread (arg=0xb39f1b40) at pthread_create.c:308
#9  0xb72f9d4e in clone () at ../sysdeps/unix/sysv/linux/i386/clone.S:132


Version-Release number of selected component (if applicable):
httpd-2.4.2-23.fc18.i686
mod_wsgi-3.4-1.fc18.i686
mod_auth_kerb-5.4-19.fc18.i686

How reproducible:

Steps to Reproduce:
1. Install freeipa-server package
2. Run "ipa-server-install"
3. Run "kinit admin" with password configured during FreeIPA installation
4. Run "ipa user-find" command and watch /var/log/httpd/error_log
  
Actual results:
mod_wsgi process crashes and restarts

Expected results:
mod_wsgi process does not crash

Additional info:
Comment 1 Martin Kosek 2012-10-17 04:32:29 EDT
Tried with a fresh build of mod_wsgi:
httpd-2.4.2-23.fc18.i686
mod_wsgi-3.4-2.fc18.i686
mod_auth_kerb-5.4-19.fc18.i686


I still see the crash.


/var/log/httpd/error_log:
...
[Wed Oct 17 04:27:27.140123 2012] [mpm_prefork:notice] [pid 12303] AH00163: Apache/2.4.2 (Unix) mod_auth_kerb/5.4 mod_nss/2.4.2 NSS/3.13.5.0 mod_wsgi/3.4 Python/2.7.3 configured -- resuming normal operations
[Wed Oct 17 04:27:27.140382 2012] [core:notice] [pid 12303] AH00094: Command line: '/usr/sbin/httpd'
[Wed Oct 17 04:27:31.977125 2012] [:error] [pid 12305] ipa: INFO: *** PROCESS START ***
[Wed Oct 17 04:27:31.978811 2012] [:error] [pid 12304] ipa: INFO: *** PROCESS START ***
[Wed Oct 17 04:28:31.274524 2012] [:error] [pid 12304] ipa: INFO: admin@IDM.LAB.BOS.REDHAT.COM: ping(): SUCCESS
[Wed Oct 17 04:28:51.227986 2012] [core:notice] [pid 12303] AH00052: child pid 12304 exit signal Segmentation fault (11)
[Wed Oct 17 04:28:51.788078 2012] [:error] [pid 12305] ipa: INFO: admin@IDM.LAB.BOS.REDHAT.COM: user_find(None, whoami=False, all=False, raw=False, version=u'2.44', pkey_only=False): SUCCESS

[Wed Oct 17 04:28:52.233842 2012] [core:notice] [pid 12303] AH00052: child pid 12305 exit signal Segmentation fault (11)

[Wed Oct 17 04:28:55.215162 2012] [:error] [pid 12351] ipa: INFO: *** PROCESS START ***
[Wed Oct 17 04:28:55.683228 2012] [:error] [pid 12357] ipa: INFO: *** PROCESS START ***


gdb output:
(gdb) continue
Continuing.
warning: cannot close "/usr/lib/krb5/plugins/libkrb5/sssd_krb5_locator_plugin.so": Invalid operation

Program received signal SIGSEGV, Segmentation fault.
[Switching to Thread 0xb39f8b40 (LWP 12323)]
0xb7725e4d in update_child_status_internal (child_num=-1, thread_num=0, status=8, c=0x0, r=0x0)
    at scoreboard.c:460
460	    ws = &ap_scoreboard_image->servers[child_num][thread_num];
(gdb) where
#0  0xb7725e4d in update_child_status_internal (child_num=-1, thread_num=0, status=8, c=0x0, r=0x0)
    at scoreboard.c:460
#1  0xb7726af3 in ap_update_child_status (sbh=0x8, status=0, status@entry=8, r=r@entry=0x0)
    at scoreboard.c:526
#2  0xb774956c in ap_start_lingering_close (c=c@entry=0xb8ef62c8) at connection.c:106
#3  0xb7749607 in ap_lingering_close (c=c@entry=0xb8ef62c8) at connection.c:147
#4  0xb6b42b37 in wsgi_process_socket (bucket_alloc=0xb8efaca8, sock=<optimized out>, 
    p=<optimized out>, daemon=<optimized out>) at mod_wsgi.c:10672
#5  wsgi_daemon_worker (thread=0xb8eed268, p=0xb8ef4018) at mod_wsgi.c:10993
#6  wsgi_daemon_thread (thd=0xb8eed300, data=0xb8eed268) at mod_wsgi.c:11026
#7  0xb74051d5 in dummy_worker (opaque=0xb8eed300) at threadproc/unix/thread.c:142
#8  0xb73ccaff in start_thread (arg=0xb39f8b40) at pthread_create.c:308
#9  0xb7300d4e in clone () at ../sysdeps/unix/sysv/linux/i386/clone.S:132
Comment 3 Joe Orton 2012-10-17 05:35:58 EDT
It looks like mod_wsgi's fake connection_rec handling needs updating for httpd 2.4.

Can somebody try this build?

http://koji.fedoraproject.org/koji/buildinfo?buildID=360604
Comment 4 Martin Kosek 2012-10-17 05:59:06 EDT
(In reply to comment #3)
> It looks like mod_wsgi's fake connection_rec handling needs updating for
> httpd 2.4.
> 
> Can somebody try this build?
> 
> http://koji.fedoraproject.org/koji/buildinfo?buildID=360604

I tested the new build and it seems that it fixes the bug, I can no longer reproduce the crash. Thanks Joe!

Note You need to log in before you can comment on or make changes to this bug.