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