modperl_filter.c bug causing hung httpd child? (w/backtraces)

[Jeff Ambrosino <jb...@gmail.com>]

I've observed recurring hung Apache children in my mod_perl http output filter.
The problem is intermittent, and while I can't cause it to happen, our site gets
alot of traffic and the problem is happening 10+ times per day.  The immediate
impact is that the page requested never gets served to the user, and the hung
httpd proc hogs CPU.

What I'd like to know from folks on this list is whether this could be
a mod_perl bug.
I've tried my darndest to narrow this problem through debugging.  See two gdb
backtraces below, from the running (hung) process as well as from the coredump
(after killing the hung process).

For my platform, I am using an Apache mod_proxy (reverse proxy) with a mod_perl
http output filter:

mod_perl-2.0.0-RC4
httpd-2.0.54
libapreq2-2.04_03-dev
perl-5.8.5 (precompiled Red Hat ES 4)

As part of my diagnostics, I wrapped all $f->read and $f->print statments in
alarm() statements (with appropriate signal handlers) to see if I could prevent
the hanging, but that hasn't helped.

Here's how my mod_perl handlers are set up:

PerlPostReadRequestHandler (initializes Apache::Request)
    --> mod_proxy (fetches page from back-end ala reverse proxy)
        --> PerlOutputFilterHandler (runs a regex on certain text/html pages)
            --> cleanup handler ($r->pool->cleanup_register - logs
info to database)

The functionality of my OutputFilterHandler is basically to filter the
contents of the web
page through a regular expression.  I also think (maybe) that this could even be
a problem with Perl's regular expression parser since the first
backtrace below has 118
frames in the Perl_regclass_swash function.


// ---------------------------------------------------------------------------------------------------------
// output from 'gdb --pid=27114' (attaches to hung process while still running)
// ---------------------------------------------------------------------------------------------------------
#1 ..(repeated118 times).. #118 0x0062651e in Perl_regclass_swash ()
from /usr/lib/perl5/5.8.5/i386-linux-thread-multi/CORE/libperl.so
#119 0x0062651e in Perl_regclass_swash () from
/usr/lib/perl5/5.8.5/i386-linux-thread-multi/CORE/libperl.so
#120 0x00628d6e in Perl_regclass_swash () from
/usr/lib/perl5/5.8.5/i386-linux-thread-multi/CORE/libperl.so
#121 0x0062ee43 in Perl_regexec_flags () from
/usr/lib/perl5/5.8.5/i386-linux-thread-multi/CORE/libperl.so
#122 0x005ca595 in Perl_pp_subst () from
/usr/lib/perl5/5.8.5/i386-linux-thread-multi/CORE/libperl.so
#123 0x005afddd in Perl_runops_debug () from
/usr/lib/perl5/5.8.5/i386-linux-thread-multi/CORE/libperl.so
#124 0x0055aae6 in Perl_get_cv () from
/usr/lib/perl5/5.8.5/i386-linux-thread-multi/CORE/libperl.so
#125 0x00560e6b in Perl_call_sv () from
/usr/lib/perl5/5.8.5/i386-linux-thread-multi/CORE/libperl.so
#126 0x0025c705 in modperl_callback (my_perl=0x8406268,
handler=0x82090e8, p=0x8696c98, r=0x8696cd0,
    s=0x8207c68, args=0x868284c) at modperl_callback.c:100
#127 0x00262e20 in modperl_run_filter (filter=0x8660a28) at modperl_filter.c:511
#128 0x002641fa in modperl_output_filter_handler (f=0x8698a10,
bb=0x86872f0) at modperl_filter.c:888
#129 0x0808bd03 in ap_proxy_http_handler (r=0x8696cd0, conf=0x8245458, 
    url=0x8687438 "/url/of/the/reverse/proxied/page.jsp",
proxyname=0x0, proxyport=0)
    at proxy_http.c:937
#130 0x08087aee in proxy_run_scheme_handler (r=0x8696cd0, conf=0x8245458, 
    url=0x8698986
"https://11.22.33.44/url/of/the/reverse/proxied/page.jsp",
proxyhost=0x0,
    proxyport=25192) at mod_proxy.c:1112
#131 0x08087dd6 in proxy_handler (r=0x8696cd0) at mod_proxy.c:420
#132 0x080a7576 in ap_run_handler (r=0x8696cd0) at config.c:152
#133 0x080a7941 in ap_invoke_handler (r=0x8696cd0) at config.c:364
#134 0x080a1e25 in ap_process_request (r=0x8696cd0) at http_request.c:249
#135 0x0809daf1 in ap_process_http_connection (c=0x8652910) at http_core.c:251
#136 0x080af992 in ap_run_process_connection (c=0x8652910) at connection.c:43
#137 0x080a5d51 in child_main (child_num_arg=141388532) at prefork.c:610
#138 0x080a5f7b in make_child (s=0xf, slot=39) at prefork.c:704
#139 0x080a690a in ap_mpm_run (_pconf=0x27, plog=0x81d31a8, s=0x0) at
prefork.c:1001
#140 0x080ab7af in main (argc=7, argv=0xbffff9a4) at main.c:618


// ---------------------------------------------------------------------------------------------------------
// output from 'gdb /var/httpd/bin/httpd /tmp/core.27114' after 'kill 27114'
// ---------------------------------------------------------------------------------------------------------
#0  apr_pool_cleanup_kill (p=0x8652810, data=0x868e1a0,
cleanup_fn=0x96e3b4 <brigade_cleanup>)
    at apr_pools.c:1905
#1  0x0096e3f8 in apr_brigade_destroy (b=0x868e1a0) at apr_brigade.c:58
#2  0x0026351b in modperl_run_filter (filter=0x86e9578) at modperl_filter.c:835
#3  0x002641fa in modperl_output_filter_handler (f=0x865e6c0,
bb=0x868e1a0) at modperl_filter.c:888
#4  0x0808bd03 in ap_proxy_http_handler (r=0x865ca18, conf=0x8245458, 
    url=0x868e2e8 "/url/of/the/reverse/proxied/page.jsp",
proxyname=0x0, proxyport=0)
    at proxy_http.c:937
#5  0x08087aee in proxy_run_scheme_handler (r=0x865ca18, conf=0x8245458, 
    url=0x865e636
"https://11.22.33.44/url/of/the/reverse/proxied/page.jsp",
proxyhost=0x0,
    proxyport=57760) at mod_proxy.c:1112
#6  0x08087dd6 in proxy_handler (r=0x865ca18) at mod_proxy.c:420
#7  0x080a7576 in ap_run_handler (r=0x865ca18) at config.c:152
#8  0x080a7941 in ap_invoke_handler (r=0x865ca18) at config.c:364
#9  0x080a1e25 in ap_process_request (r=0x865ca18) at http_request.c:249
#10 0x0809daf1 in ap_process_http_connection (c=0x8652910) at http_core.c:251
#11 0x080af992 in ap_run_process_connection (c=0x8652910) at connection.c:43
#12 0x080a5d51 in child_main (child_num_arg=1347703880) at prefork.c:610
#13 0x080a5f7b in make_child (s=0xf, slot=411) at prefork.c:704
#14 0x080a690a in ap_mpm_run (_pconf=0x19b, plog=0x81d31a8, s=0x0) at
prefork.c:1001
#15 0x080ab7af in main (argc=7, argv=0xbffff9a4) at main.c:618

Any help would be immensely appreciated.  This problem is really dogging me, and
I definitely need some help with folks familiar with mod_perl's construction.

thank you,
Jeff