You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@perl.apache.org by Christopher Shumway <cs...@titan-project.org> on 2007/03/01 22:36:01 UTC
[mp1] Segfaults in ap_table_get (Apache::Registry corruption?)
Hi folks,
Sorry to bug the dev modperl list, but I could really use some expert advice
on this problem.
About once every 15-45 minutes or so a httpd process will segfault when
serving a modperl page. I've built apache httpd, modperl and perl with
debuging symbols, and have gotten a few core images.
Here are the relvent software versions:
FreeBSD 6.1-RELEASE-p14 running an SMP kernel
Perl 5.8.8 built for i386-freebsd-64int
apache+mod_ssl-1.3.37+2.8.28
mod_perl-1.29
Here's the gdb backtrace:
#0 0x08050c55 in ap_table_get (t=0x31412d38, key=0x9d67a88 "Expires") atalloc.c:1444
#1 0x2850a6df in XS_Apache_cgi_header_out (cv=0x8899c34) at Apache.c:2662
#2 0x285c5f88 in Perl_pp_entersub () at pp_hot.c:2913
#3 0x285a5ecb in Perl_runops_debug () at dump.c:1459
#4 0x2854bf19 in S_call_body (myop=0xbfbfead0, is_eval=0 '\0') atperl.c:2731
#5 0x2854bacb in Perl_call_sv (sv=0x889a258, flags=4) at perl.c:2646
#6 0x284f6497 in perl_call_handler (sv=0x889a258, r=0x88e0038, args=0x0) atmod_perl.c:1668
#7 0x284f5b24 in perl_run_stacked_handlers (hook=0x2851fd2f "PerlHandler",r=0x88e0038, handlers=0x889a090) at mod_perl.c:1381
#8 0x284f3bb1 in perl_handler (r=0x88e0038) at mod_perl.c:904
#9 0x08054d96 in ap_invoke_handler (r=0x88e0038) at http_config.c:476
#10 0x0806a3ed in process_request_internal (r=0x88e0038) athttp_request.c:1299
#11 0x0806a44c in ap_process_request (r=0x88e0038) at http_request.c:1315
#12 0x08061177 in child_main (child_num_arg=8) at http_main.c:4898
#13 0x0806146c in make_child (s=0x8099038, slot=8, now=1172591147) athttp_main.c:5077
#14 0x080617a8 in perform_idle_server_maintenance () at http_main.c:5262
#15 0x08061d6d in standalone_main (argc=2, argv=0xbfbfeeec) athttp_main.c:5525
#16 0x08062391 in main (argc=2, argv=0xbfbfeeec) at http_main.c:5793
What looks like is happening is the table being passed to ap_table_get() is
bogus.
(gdb) frame 0
#0 0x08050c55 in ap_table_get (t=0x31412d38, key=0x9d67a88 "Expires") at
alloc.c:1444
1444 table_entry *elts = (table_entry *) t->a.elts;
(gdb) list
1439 t->a.nelts = 0;
1440 }
1441
1442 API_EXPORT(const char *) ap_table_get(const table *t, constchar *key)
1443 {
1444 table_entry *elts = (table_entry *) t->a.elts;
1445 int i;
1446
1447 if (key == NULL)
1448 return NULL;
(gdb) print *t
Cannot access memory at address 0x31412d38
I'm not sure why, but the data structure Apache r doesn't appear to be
getting populated correctly:
#1 0x2850a6df in XS_Apache_cgi_header_out (cv=0x8899c34) at Apache.c:2662
2662 if((val = (char *)table_get(r->headers_out, key))) (gdb) list
2657 char *val;
2658
2659 SV * RETVAL;
2660
2661 r = sv2request_rec(ST(0), "Apache", cv);
2662 if((val = (char *)table_get(r->headers_out, key))) 2663 RETVAL =
newSVpv(val, 0);
2664 else
2665 RETVAL = newSV(0);
2666 (gdb) print *r->headers_out
$5 = {a = {pool = 0x31412d38, elt_size = 0, nelts = 0, nalloc = 0, elts =
0x0}}
(gdb)
I'd love to get to the bottom of this one, but I could use some insight.
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@perl.apache.org
For additional commands, e-mail: dev-help@perl.apache.org
Re: [mp1] Segfaults in ap_table_get (Apache::Registry corruption?)
Posted by "Philip M. Gollucci" <pg...@p6m7g8.com>.
Christopher Shumway wrote:
> On Thu, 1 Mar 2007, Christopher Shumway wrote:
>
>>> This seems to be the 'HTTP Headers', whats the output of a curl -I
>>> when this happens ?
I'm a bit busy lately.... All I can tell is its definitely in the
headers generation code. Its probably very unlikely the code is at
fault, but some header is breaking an RFC or something.
I wish I had more time.
>
> After over 72 hours of looping several curl -I fetching various modperl
> pages, I still haven't been able to directly reproduce the problem. So,
> I've enabled mod_log_forensic in hopes it might shed some light on the
> problem.
>
> Here's a backtrace from a recently crashed httpd:
>
> (gdb) bt
> #0 0x08050c55 in ap_table_get (t=0x0, key=0x9cb5b28 "Set-Cookie") at
> alloc.c:1444
> #1 0x285106df in XS_Apache_cgi_header_out (cv=0x88c9c34) at Apache.c:2662
> #2 0x285cbf88 in Perl_pp_entersub () at pp_hot.c:2913
> #3 0x285abecb in Perl_runops_debug () at dump.c:1459
> #4 0x28551f19 in S_call_body (myop=0xbfbfeb70, is_eval=0 '\0') at
> perl.c:2731
> #5 0x28551acb in Perl_call_sv (sv=0x88ca258, flags=4) at perl.c:2646
> #6 0x284fc497 in perl_call_handler (sv=0x88ca258, r=0x890a038,
> args=0x0) at mod_perl.c:1668
> #7 0x284fbb24 in perl_run_stacked_handlers (hook=0x28525d2f
> "PerlHandler", r=0x890a038, handlers=0x88ca090) at mod_perl.c:1381
> #8 0x284f9bb1 in perl_handler (r=0x890a038) at mod_perl.c:904
> #9 0x08054d96 in ap_invoke_handler (r=0x890a038) at http_config.c:476
> #10 0x0806a3ed in process_request_internal (r=0x890a038) at
> http_request.c:1299
> #11 0x0806a44c in ap_process_request (r=0x890a038) at http_request.c:1315
> #12 0x08061177 in child_main (child_num_arg=7) at http_main.c:4898
> #13 0x0806146c in make_child (s=0x8099038, slot=7, now=1173127181) at
> http_main.c:5077
> #14 0x08061513 in startup_children (number_to_start=3) at http_main.c:5104
> #15 0x08061b5e in standalone_main (argc=2, argv=0xbfbfeee4) at
> http_main.c:5436
> #16 0x08062391 in main (argc=2, argv=0xbfbfeee4) at http_main.c:5793
>
> And the corresponding forensic entry:
>
> # grep ReyC1c8hFowAABfzJoU forensic.log
> +ReyC1c8hFowAABfzJoU|GET /modperl/achievement/fl/1858
> HTTP/1.0|Accept-Encoding:gzip|Host:www.greatschools.net|Max-Forwards:10|User-Agent:Mediapartners-Google/2.1|X-Forwarded-For:66.249.65.51|X-Forwarded-Host:www.greatschools.net|X-Forwarded-Server:proxy2.greatschools.net
>
>
> And another, just in case a pattern can be identified:
>
> (gdb) bt
> #0 0x08050c8f in ap_table_get (t=0x80df010, key=0x9c78d08 "Set-Cookie")
> at alloc.c:1451
> #1 0x285106df in XS_Apache_cgi_header_out (cv=0x88c9c34) at Apache.c:2662
> #2 0x285cbf88 in Perl_pp_entersub () at pp_hot.c:2913
> #3 0x285abecb in Perl_runops_debug () at dump.c:1459
> #4 0x28551f19 in S_call_body (myop=0xbfbfeb70, is_eval=0 '\0') at
> perl.c:2731
> #5 0x28551acb in Perl_call_sv (sv=0x88ca258, flags=4) at perl.c:2646
> #6 0x284fc497 in perl_call_handler (sv=0x88ca258, r=0x890a038,
> args=0x0) at mod_perl.c:1668
> #7 0x284fbb24 in perl_run_stacked_handlers (hook=0x28525d2f
> "PerlHandler", r=0x890a038, handlers=0x88ca090) at mod_perl.c:1381
> #8 0x284f9bb1 in perl_handler (r=0x890a038) at mod_perl.c:904
> #9 0x08054d96 in ap_invoke_handler (r=0x890a038) at http_config.c:476
> #10 0x0806a3ed in process_request_internal (r=0x890a038) at
> http_request.c:1299
> #11 0x0806a44c in ap_process_request (r=0x890a038) at http_request.c:1315
> #12 0x08061177 in child_main (child_num_arg=0) at http_main.c:4898
> #13 0x0806146c in make_child (s=0x8099038, slot=0, now=1173127181) at
> http_main.c:5077
> #14 0x08061513 in startup_children (number_to_start=10) at http_main.c:5104
> #15 0x08061b5e in standalone_main (argc=2, argv=0xbfbfeee4) at
> http_main.c:5436
> #16 0x08062391 in main (argc=2, argv=0xbfbfeee4) at http_main.c:5793
>
> corresponding forensic.log entry:
>
> # grep ReyEes8hFowAABfsHIw forensic.log
>
> +ReyEes8hFowAABfsHIw|GET /modperl/districts/NM
> HTTP/1.0|Host:www.greatschools.net|Max-Forwards:10|User-Agent:Mozilla/4.0
> (compatible ; MSIE 6.0; Windows NT
> 5.1)|X-Forwarded-For:70.154.49.7|X-Forwarded-Host:www.greatschools.net|X-Forwarded-Server:proxy1.greatschools.net
>
>
>
> Is there anything useful that I could produce from this data that might
> help get to he bottom of this problem?
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: dev-unsubscribe@perl.apache.org
> For additional commands, e-mail: dev-help@perl.apache.org
--
------------------------------------------------------------------------
Philip M. Gollucci (pgollucci@p6m7g8.com) 323.219.4708
Consultant / http://p6m7g8.net/Resume/resume.shtml
Senior Software Engineer - TicketMaster - http://ticketmaster.com
1024D/EC88A0BF 0DE5 C55C 6BF3 B235 2DAB B89E 1324 9B4F EC88 A0BF
Work like you don't need the money,
love like you'll never get hurt,
and dance like nobody's watching.
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@perl.apache.org
For additional commands, e-mail: dev-help@perl.apache.org
Re: [mp1] Segfaults in ap_table_get (Apache::Registry corruption?)
Posted by Christopher Shumway <cs...@titan-project.org>.
On Mon, 5 Mar 2007, Christopher Shumway wrote:
> On Thu, 1 Mar 2007, Christopher Shumway wrote:
>
>>> This seems to be the 'HTTP Headers', whats the output of a curl -I when
>>> this happens ?
>
> After over 72 hours of looping several curl -I fetching various modperl
> pages, I still haven't been able to directly reproduce the problem.
I managed to capture a TCP stream with a segfaulting httpd with tcpdump on the
server. It doesn't look like its going to reveal much.
Here's the entire contents of the stream:
GET /modperl/parents/ca/5637 HTTP/1.1
Host: www.greatschools.net
User-Agent: Mediapartners-Google/2.1
Accept-Encoding: gzip
Max-Forwards: 10
X-Forwarded-For: 66.249.65.11
X-Forwarded-Host: www.greatschools.net
X-Forwarded-Server: proxy1.greatschools.net
Connection: close
It looks like no headers where ever outputted. Heres a look at the TCP
session flow:
16:05:25.087871 IP proxy1.greatschools.net.61997 >
backend.greatschools.net.80:S 1294232215:1294232215(0) win 65535 <mss
1460,nop,wscale 1,nop,nop,timestamp 3696164069 0,sackOK,eol> (DF)
16:05:25.087910 IP backend.greatschools.net.80 >
proxy1.greatschools.net.61997:S 1689629712:1689629712(0) ack 1294232216 win
65535 <mss 1460,nop,wscale 1,nop,nop,timestamp 954835601
3696164069,sackOK,eol> (DF)
16:05:25.088189 IP proxy1.greatschools.net.61997 >
backend.greatschools.net.80:. ack 1 win 33304 <nop,nop,timestamp 3696164069
954835601> (DF)
16:05:25.088318 IP proxy1.greatschools.net.61997 >
backend.greatschools.net.80:P 1:284(283) ack 1 win 33304 <nop,nop,timestamp
3696164069 954835601> (DF)
16:05:25.187537 IP backend.greatschools.net.80 >
proxy1.greatschools.net.61997:. ack 284 win 33304 <nop,nop,timestamp 954835701
3696164069> (DF)
16:05:26.009585 IP backend.greatschools.net.80 >
proxy1.greatschools.net.61997:F 1:1(0) ack 284 win 33304 <nop,nop,timestamp
954836522 3696164069> (DF)
16:05:26.009873 IP proxy1.greatschools.net.61997 >
backend.greatschools.net.80:. ack 2 win 33304 <nop,nop,timestamp 3696164991
954836522> (DF)
16:05:26.009932 IP proxy1.greatschools.net.61997 >
backend.greatschools.net.80:F 284:284(0) ack 2 win 33304 <nop,nop,timestamp
3696164991 954836522> (DF)
16:05:26.009975 IP backend.greatschools.net.80 >
proxy1.greatschools.net.61997:. ack 285 win 33303 <nop,nop,timestamp 954836523
3696164991> (DF)
The server is backend.greatschools.net and the client is
proxy1.greatschools.net, which is a reverse-caching proxy server running
Apache httpd 2.2.
>From the looks of it, httpd on the server closed the connection before any
data was sent in responce.
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@perl.apache.org
For additional commands, e-mail: dev-help@perl.apache.org
Re: [mp1] Segfaults in ap_table_get (Apache::Registry corruption?)
Posted by Christopher Shumway <cs...@titan-project.org>.
On Thu, 1 Mar 2007, Christopher Shumway wrote:
>> This seems to be the 'HTTP Headers', whats the output of a curl -I when
>> this happens ?
After over 72 hours of looping several curl -I fetching various modperl
pages, I still haven't been able to directly reproduce the problem. So, I've
enabled mod_log_forensic in hopes it might shed some light on the problem.
Here's a backtrace from a recently crashed httpd:
(gdb) bt
#0 0x08050c55 in ap_table_get (t=0x0, key=0x9cb5b28 "Set-Cookie") at alloc.c:1444
#1 0x285106df in XS_Apache_cgi_header_out (cv=0x88c9c34) at Apache.c:2662
#2 0x285cbf88 in Perl_pp_entersub () at pp_hot.c:2913
#3 0x285abecb in Perl_runops_debug () at dump.c:1459
#4 0x28551f19 in S_call_body (myop=0xbfbfeb70, is_eval=0 '\0') at perl.c:2731
#5 0x28551acb in Perl_call_sv (sv=0x88ca258, flags=4) at perl.c:2646
#6 0x284fc497 in perl_call_handler (sv=0x88ca258, r=0x890a038, args=0x0) at mod_perl.c:1668
#7 0x284fbb24 in perl_run_stacked_handlers (hook=0x28525d2f "PerlHandler", r=0x890a038, handlers=0x88ca090) at mod_perl.c:1381
#8 0x284f9bb1 in perl_handler (r=0x890a038) at mod_perl.c:904
#9 0x08054d96 in ap_invoke_handler (r=0x890a038) at http_config.c:476
#10 0x0806a3ed in process_request_internal (r=0x890a038) at http_request.c:1299
#11 0x0806a44c in ap_process_request (r=0x890a038) at http_request.c:1315
#12 0x08061177 in child_main (child_num_arg=7) at http_main.c:4898
#13 0x0806146c in make_child (s=0x8099038, slot=7, now=1173127181) at http_main.c:5077
#14 0x08061513 in startup_children (number_to_start=3) at http_main.c:5104
#15 0x08061b5e in standalone_main (argc=2, argv=0xbfbfeee4) at http_main.c:5436
#16 0x08062391 in main (argc=2, argv=0xbfbfeee4) at http_main.c:5793
And the corresponding forensic entry:
# grep ReyC1c8hFowAABfzJoU forensic.log
+ReyC1c8hFowAABfzJoU|GET /modperl/achievement/fl/1858 HTTP/1.0|Accept-Encoding:gzip|Host:www.greatschools.net|Max-Forwards:10|User-Agent:Mediapartners-Google/2.1|X-Forwarded-For:66.249.65.51|X-Forwarded-Host:www.greatschools.net|X-Forwarded-Server:proxy2.greatschools.net
And another, just in case a pattern can be identified:
(gdb) bt
#0 0x08050c8f in ap_table_get (t=0x80df010, key=0x9c78d08 "Set-Cookie") at alloc.c:1451
#1 0x285106df in XS_Apache_cgi_header_out (cv=0x88c9c34) at Apache.c:2662
#2 0x285cbf88 in Perl_pp_entersub () at pp_hot.c:2913
#3 0x285abecb in Perl_runops_debug () at dump.c:1459
#4 0x28551f19 in S_call_body (myop=0xbfbfeb70, is_eval=0 '\0') at perl.c:2731
#5 0x28551acb in Perl_call_sv (sv=0x88ca258, flags=4) at perl.c:2646
#6 0x284fc497 in perl_call_handler (sv=0x88ca258, r=0x890a038, args=0x0) at mod_perl.c:1668
#7 0x284fbb24 in perl_run_stacked_handlers (hook=0x28525d2f "PerlHandler", r=0x890a038, handlers=0x88ca090) at mod_perl.c:1381
#8 0x284f9bb1 in perl_handler (r=0x890a038) at mod_perl.c:904
#9 0x08054d96 in ap_invoke_handler (r=0x890a038) at http_config.c:476
#10 0x0806a3ed in process_request_internal (r=0x890a038) at http_request.c:1299
#11 0x0806a44c in ap_process_request (r=0x890a038) at http_request.c:1315
#12 0x08061177 in child_main (child_num_arg=0) at http_main.c:4898
#13 0x0806146c in make_child (s=0x8099038, slot=0, now=1173127181) at http_main.c:5077
#14 0x08061513 in startup_children (number_to_start=10) at http_main.c:5104
#15 0x08061b5e in standalone_main (argc=2, argv=0xbfbfeee4) at http_main.c:5436
#16 0x08062391 in main (argc=2, argv=0xbfbfeee4) at http_main.c:5793
corresponding forensic.log entry:
# grep ReyEes8hFowAABfsHIw forensic.log
+ReyEes8hFowAABfsHIw|GET /modperl/districts/NM HTTP/1.0|Host:www.greatschools.net|Max-Forwards:10|User-Agent:Mozilla/4.0 (compatible ; MSIE 6.0; Windows NT 5.1)|X-Forwarded-For:70.154.49.7|X-Forwarded-Host:www.greatschools.net|X-Forwarded-Server:proxy1.greatschools.net
Is there anything useful that I could produce from this data that might help
get to he bottom of this problem?
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@perl.apache.org
For additional commands, e-mail: dev-help@perl.apache.org
Re: [mp1] Segfaults in ap_table_get (Apache::Registry corruption?)
Posted by Christopher Shumway <cs...@titan-project.org>.
On Thu, 1 Mar 2007, Philip M. Gollucci wrote:
> Christopher Shumway wrote:
>> Hi folks,
>>
>> Sorry to bug the dev modperl list, but I could really use some expert
>> advice on this problem.
>>
>> About once every 15-45 minutes or so a httpd process will segfault when
>> serving a modperl page. I've built apache httpd, modperl and perl with
>> debuging symbols, and have gotten a few core images.
>>
>> Here are the relvent software versions:
>> FreeBSD 6.1-RELEASE-p14 running an SMP kernel
>> Perl 5.8.8 built for i386-freebsd-64int
>> apache+mod_ssl-1.3.37+2.8.28
>> mod_perl-1.29
> This seems to be the 'HTTP Headers', whats the output of a curl -I when this
> happens ?
Unforantally I haven't been able to directly reproduce the problem, but here
are the headers from a normal request:
GET /modperl/achievement/il/1506 HTTP/1.1
Host: testweb6.greatschools.net
User-Agent: Mozilla/5.0 (Windows; U; Windows NT 5.1; en-US; rv:1.8.1.2)
Gecko/20070219 Firefox/2.0.0.2
Accept: text/xml,application/xml,application/xhtml+xml,text/html;q=0.9,text/plain;q=0.8,image/png,*/*;q=0.5
Accept-Language: en-us,en;q=0.5
Accept-Encoding: gzip,deflate
Accept-Charset: ISO-8859-1,utf-8;q=0.7,*;q=0.7
Keep-Alive: 300
Connection: keep-alive
Cookie: RMID=c690cd8a4547d910; OAX=xpDNikVH2RAABjmi;
s_vi=[CS]v1|4547D10300004AA5-A160B130000042F[CE];
TRNO=1168387446.198.144.205.138; STATE=CA; hoverNewsMss=Fri, 23 Feb 2007
01:37:34 GMT; s_cc=true; s_sq=%5B%5BB%5D%5D; NumAd=-1
HTTP/1.x 200 OK
Date: Thu, 01 Mar 2007 22:25:49 GMT
Server: Apache/1.3.37 (Unix) mod_perl/1.29 mod_ssl/2.8.28 OpenSSL/0.9.7e-p1 mod_jk/1.2.19
Set-Cookie: STATE=IL; path=/; expires=Sat, 28-Feb-2009 22:25:49 GMT
Expires: Wed, 28 Feb 2007 22:25:49 GMT
Cache-Control: no-cache
P3P: policyref="http://www.greatschools.net/w3c/p3p.xml", CP="ALL DSP COR CUR DEVi PSA IVAi IVDi CONi OUR IND UNI"
Connection: close
Transfer-Encoding: chunked
Content-Type: text/html; charset=ISO-8859-1
I'll setup curl in a loop repeatedly fetching a modperl page to see if I can
capture a request when httpd segfaults.
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@perl.apache.org
For additional commands, e-mail: dev-help@perl.apache.org
Re: [mp1] Segfaults in ap_table_get (Apache::Registry corruption?)
Posted by "Philip M. Gollucci" <pg...@p6m7g8.com>.
Christopher Shumway wrote:
> Hi folks,
>
> Sorry to bug the dev modperl list, but I could really use some expert
> advice on this problem.
>
> About once every 15-45 minutes or so a httpd process will segfault when
> serving a modperl page. I've built apache httpd, modperl and perl with
> debuging symbols, and have gotten a few core images.
>
> Here are the relvent software versions:
> FreeBSD 6.1-RELEASE-p14 running an SMP kernel
> Perl 5.8.8 built for i386-freebsd-64int
> apache+mod_ssl-1.3.37+2.8.28
> mod_perl-1.29
This seems to be the 'HTTP Headers', whats the output of a curl -I when
this happens ?
--
------------------------------------------------------------------------
Philip M. Gollucci (pgollucci@p6m7g8.com) 323.219.4708
Consultant / http://p6m7g8.net/Resume/resume.shtml
Senior Software Engineer - TicketMaster - http://ticketmaster.com
1024D/EC88A0BF 0DE5 C55C 6BF3 B235 2DAB B89E 1324 9B4F EC88 A0BF
I never had a dream come true
'Til the day that I found you.
Even though I pretend that I've moved on
You'll always be my baby.
I never found the words to say
You're the one I think about each day
And I know no matter where life takes me to
A part of me will always be...
A part of me will always be with you.
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@perl.apache.org
For additional commands, e-mail: dev-help@perl.apache.org