first time debugging apache/mod_perl Seg fault

Hey folks,

I'm running CentOS 5.2 with a custom built apache not from Yum.

I am following instructions here
http://perl.apache.org/docs/2.0/devel/debug/c.html#Getting_t he_core_File_Du=
mped

and here :
http://perl.apache.org/docs/2.0/devel/debug/c.html#Analyzing _Dumped_Core_Fi=
les

I have mod_perl built with symbols and reproduce my problem, but I'm
not having much luck with gdb. I really have no experience with this
aspect of Linux so am shooting in the dark a bit here.

I also have no idea whether I'm "threaded" or "unthreaded", so I tried
both of the "curinfo" macros with no luck.

Here is the output of "bt full" which clearly shows a few "my_perl"
entries. But I'm just not clear how to find out what part of our
Perl code is causing the issue.

(gdb) bt full
#0 0x0044e172 in Perl_cv_const_sv () from
/usr/lib/perl5/5.8.8/i386-linux-thread-multi/CORE/libperl.so
No symbol table info available.
#1 0x00442a7c in Perl_yylex () from
/usr/lib/perl5/5.8.8/i386-linux-thread-multi/CORE/libperl.so
No symbol table info available.
#2 0x0044b295 in Perl_yyparse () from
/usr/lib/perl5/5.8.8/i386-linux-thread-multi/CORE/libperl.so
No symbol table info available.
#3 0x004b8200 in Perl_pp_range () from
/usr/lib/perl5/5.8.8/i386-linux-thread-multi/CORE/libperl.so
No symbol table info available.
#4 0x004ba0b2 in Perl_pp_require () from
/usr/lib/perl5/5.8.8/i386-linux-thread-multi/CORE/libperl.so
No symbol table info available.
#5 0x004ba7ad in Perl_pp_dofile () from
/usr/lib/perl5/5.8.8/i386-linux-thread-multi/CORE/libperl.so
No symbol table info available.
#6 0x0048488f in Perl_runops_standard () from
/usr/lib/perl5/5.8.8/i386-linux-thread-multi/CORE/libperl.so
No symbol table info available.
#7 0x00424ffe in Perl_magicname () from
/usr/lib/perl5/5.8.8/i386-linux-thread-multi/CORE/libperl.so
No symbol table info available.
#8 0x00429806 in Perl_call_sv () from
/usr/lib/perl5/5.8.8/i386-linux-thread-multi/CORE/libperl.so
No symbol table info available.
#9 0x00140a7f in modperl_callback (my_perl=3D0x9476458,
handler=3D0xaccc268, p=3D0xaf2a840, r=3D0xaf2a880, s=3D0xad0bad0,
args=3D0xbd473e8) at modperl_callback.c:101
items =3D
cv =3D
sp =3D (SV **) 0xafead24
status =3D 0
#10 0x0014117a in modperl_callback_run_handlers (idx=3D6, type=3D4,
r=3D0xaf2a880, c=3D0x0, s=3D0xad0bad0, pconf=3D0x0, plog=3D0x0, ptemp=3D0x0=
,
run_mode=3DMP_HOOK_RUN_FIRST)
at modperl_callback.c:262
my_perl =3D (PerlInterpreter *) 0x9476458
interp =3D (modperl_interp_t *) 0xa965888
scfg =3D (modperl_config_srv_t *) 0x8d437b8
dcfg =3D (modperl_config_dir_t *) 0xaf2a2e0
rcfg =3D (modperl_config_req_t *) 0xaf2b5f0
handlers =3D (modperl_handler_t **) 0xaccc298
p =3D (apr_pool_t *) 0xaf2a840
av =3D (MpAV *) 0xaccc280
avp =3D
i =3D 0
status =3D 0
desc =3D 0x158cd3 "PerlResponseHandler"
av_args =3D (AV *) 0xbd473e8
#11 0x0014180a in modperl_callback_per_dir (idx=3D6, r=3D0xaf2a880,
run_mode=3DMP_HOOK_RUN_FIRST) at modperl_callback.c:369
No locals.
#12 0x0013a79f in modperl_response_handler_run (r=3D0xaf2a880, finish=3D0)
at mod_perl.c:1000
retval =3D
#13 0x0013a96b in modperl_response_handler_cgi (r=3D0xaf2a880) at mod_perl.=
c:1100
dcfg =3D (modperl_config_dir_t *) 0xaf2a2e0
h_stdin =3D (GV *) 0xc2d7a20
h_stdout =3D (GV *) 0xb4ba144
retval =3D -1
rc =3D
rcfg =3D (modperl_config_req_t *) 0xaf2b5f0
my_perl =3D (PerlInterpreter *) 0x9476458
interp =3D (modperl_interp_t *) 0xa965888
#14 0x08076a79 in ap_run_handler (r=3D0xaf2a880) at config.c:157
n =3D 6
rv =3D 40
#15 0x08079be7 in ap_invoke_handler (r=3D0xaf2a880) at config.c:372
handler =3D 0x0
result =3D
old_handler =3D 0xaccbe38 "perl-script"
ignore =3D
#16 0x08090798 in ap_process_request (r=3D0xaf2a880) at http_request.c:258
---Type to continue, or q to quit---
access_status =3D 0
#17 0x0808da3b in ap_process_http_connection (c=3D0xaf1a9d8) at http_core.c=
:190
r =3D (request_rec *) 0xaf2a880
csd =3D (apr_socket_t *) 0x0
#18 0x0807dab9 in ap_run_process_connection (c=3D0xaf1a9d8) at connection.c=
:43
n =3D 1
rv =3D 40
#19 0x080a3dc5 in child_main (child_num_arg=3D) at
prefork.c:650
numdesc =3D 0
pdesc =3D (const apr_pollfd_t *) 0x0
current_conn =3D (conn_rec *) 0xaf1a9d8
csd =3D (void *) 0xaf1a840
ptrans =3D (apr_pool_t *) 0xaf1a800
allocator =3D (apr_allocator_t *) 0x9301738
status =3D
i =3D
lr =3D
pollset =3D (apr_pollset_t *) 0xaf18850
sbh =3D (ap_sb_handle_t *) 0xaf18848
bucket_alloc =3D (apr_bucket_alloc_t *) 0xaf1c808
last_poll_idx =3D 0
#20 0x080a4087 in make_child (s=3D0x8d2fd70, slot=3D28) at prefork.c:746
pid =3D 0
#21 0x080a49e0 in ap_mpm_run (_pconf=3D0x8d070a8, plog=3D0x8d451a0,
s=3D0x8d2fd70) at prefork.c:881
status =3D 0
pid =3D {pid =3D -1, in =3D 0x8d01250, out =3D 0x2, err =3D 0xd070a=
8}
child_slot =3D
exitwhy =3D APR_PROC_EXIT
processed_status =3D
index =3D
remaining_children_to_start =3D 0
rv =3D
#22 0x08064645 in main (argc=3D147869856, argv=3D0xaf187f8) at main.c:740
c =3D 0 '\0'
configtestonly =3D 0
confname =3D 0x80ae357 "conf/httpd.conf"
def_server_root =3D 0x80ae367 "/usr/local/apache2"
temp_error_log =3D 0x0
error =3D
process =3D (process_rec *) 0x8d05130
server_conf =3D
pglobal =3D (apr_pool_t *) 0x8d050a0
pconf =3D (apr_pool_t *) 0x8d070a8
plog =3D (apr_pool_t *) 0x8d451a0
ptemp =3D (apr_pool_t *) 0x8d491b0
pcommands =3D (apr_pool_t *) 0x8d090b0
opt =3D (apr_getopt_t *) 0x8d09150
rv =3D 0
optarg =3D 0x3b6ff4 "\234m;"
(gdb)


--=20
=93Don't eat anything you've ever seen advertised on TV=94
- Michael Pollan, author of "In Defense of Food"

Re: first time debugging apache/mod_perl Seg fault

On Mon, Jul 13, 2009 at 12:15 PM, Alan McKay wrote:
> Hey folks,
>
> I'm running CentOS 5.2 with a custom built apache not from Yum.
>
> I am following instructions here
> http://perl.apache.org/docs/2.0/devel/debug/c.html#Getting_t he_core_File_=
Dumped
>
> and here :
> http://perl.apache.org/docs/2.0/devel/debug/c.html#Analyzing _Dumped_Core_=
Files
>
> I have mod_perl built with symbols and reproduce my problem, but I'm
> not having much luck with gdb. =A0I really have no experience with this
> aspect of Linux so am shooting in the dark a bit here.
>
> I also have no idea whether I'm "threaded" or "unthreaded", so I tried
> both of the "curinfo" macros with no luck.

> /usr/lib/perl5/5.8.8/i386-linux-thread-multi/CORE/libperl.so

You're threaded.

What version of Apache and mod_perl are you running here?

What configuration options are you using to build apache?



> Here is the output of "bt full" which clearly shows a few "my_perl"
> entries. =A0 But I'm just not clear how to find out what part of our
> Perl code is causing the issue.
>
> (gdb) bt full
> #0 =A00x0044e172 in Perl_cv_const_sv () from
> /usr/lib/perl5/5.8.8/i386-linux-thread-multi/CORE/libperl.so
> No symbol table info available.
> #1 =A00x00442a7c in Perl_yylex () from
> /usr/lib/perl5/5.8.8/i386-linux-thread-multi/CORE/libperl.so
> No symbol table info available.
> #2 =A00x0044b295 in Perl_yyparse () from
> /usr/lib/perl5/5.8.8/i386-linux-thread-multi/CORE/libperl.so
> No symbol table info available.
> #3 =A00x004b8200 in Perl_pp_range () from
> /usr/lib/perl5/5.8.8/i386-linux-thread-multi/CORE/libperl.so
> No symbol table info available.
> #4 =A00x004ba0b2 in Perl_pp_require () from
> /usr/lib/perl5/5.8.8/i386-linux-thread-multi/CORE/libperl.so
> No symbol table info available.
> #5 =A00x004ba7ad in Perl_pp_dofile () from
> /usr/lib/perl5/5.8.8/i386-linux-thread-multi/CORE/libperl.so
> No symbol table info available.
> #6 =A00x0048488f in Perl_runops_standard () from
> /usr/lib/perl5/5.8.8/i386-linux-thread-multi/CORE/libperl.so
> No symbol table info available.
> #7 =A00x00424ffe in Perl_magicname () from
> /usr/lib/perl5/5.8.8/i386-linux-thread-multi/CORE/libperl.so
> No symbol table info available.
> #8 =A00x00429806 in Perl_call_sv () from
> /usr/lib/perl5/5.8.8/i386-linux-thread-multi/CORE/libperl.so
> No symbol table info available.
> #9 =A00x00140a7f in modperl_callback (my_perl=3D0x9476458,
> handler=3D0xaccc268, p=3D0xaf2a840, r=3D0xaf2a880, s=3D0xad0bad0,
> args=3D0xbd473e8) at modperl_callback.c:101
> =A0 =A0 =A0 =A0items =3D
> =A0 =A0 =A0 =A0cv =3D
> =A0 =A0 =A0 =A0sp =3D (SV **) 0xafead24
> =A0 =A0 =A0 =A0status =3D 0
> #10 0x0014117a in modperl_callback_run_handlers (idx=3D6, type=3D4,
> r=3D0xaf2a880, c=3D0x0, s=3D0xad0bad0, pconf=3D0x0, plog=3D0x0, ptemp=3D0=
x0,
> run_mode=3DMP_HOOK_RUN_FIRST)
> =A0 =A0at modperl_callback.c:262
> =A0 =A0 =A0 =A0my_perl =3D (PerlInterpreter *) 0x9476458
> =A0 =A0 =A0 =A0interp =3D (modperl_interp_t *) 0xa965888
> =A0 =A0 =A0 =A0scfg =3D (modperl_config_srv_t *) 0x8d437b8
> =A0 =A0 =A0 =A0dcfg =3D (modperl_config_dir_t *) 0xaf2a2e0
> =A0 =A0 =A0 =A0rcfg =3D (modperl_config_req_t *) 0xaf2b5f0
> =A0 =A0 =A0 =A0handlers =3D (modperl_handler_t **) 0xaccc298
> =A0 =A0 =A0 =A0p =3D (apr_pool_t *) 0xaf2a840
> =A0 =A0 =A0 =A0av =3D (MpAV *) 0xaccc280
> =A0 =A0 =A0 =A0avp =3D
> =A0 =A0 =A0 =A0i =3D 0
> =A0 =A0 =A0 =A0status =3D 0
> =A0 =A0 =A0 =A0desc =3D 0x158cd3 "PerlResponseHandler"
> =A0 =A0 =A0 =A0av_args =3D (AV *) 0xbd473e8
> #11 0x0014180a in modperl_callback_per_dir (idx=3D6, r=3D0xaf2a880,
> run_mode=3DMP_HOOK_RUN_FIRST) at modperl_callback.c:369
> No locals.
> #12 0x0013a79f in modperl_response_handler_run (r=3D0xaf2a880, finish=3D0=
)
> at mod_perl.c:1000
> =A0 =A0 =A0 =A0retval =3D
> #13 0x0013a96b in modperl_response_handler_cgi (r=3D0xaf2a880) at mod_per=
l.c:1100
> =A0 =A0 =A0 =A0dcfg =3D (modperl_config_dir_t *) 0xaf2a2e0
> =A0 =A0 =A0 =A0h_stdin =3D (GV *) 0xc2d7a20
> =A0 =A0 =A0 =A0h_stdout =3D (GV *) 0xb4ba144
> =A0 =A0 =A0 =A0retval =3D -1
> =A0 =A0 =A0 =A0rc =3D
> =A0 =A0 =A0 =A0rcfg =3D (modperl_config_req_t *) 0xaf2b5f0
> =A0 =A0 =A0 =A0my_perl =3D (PerlInterpreter *) 0x9476458
> =A0 =A0 =A0 =A0interp =3D (modperl_interp_t *) 0xa965888
> #14 0x08076a79 in ap_run_handler (r=3D0xaf2a880) at config.c:157
> =A0 =A0 =A0 =A0n =3D 6
> =A0 =A0 =A0 =A0rv =3D 40
> #15 0x08079be7 in ap_invoke_handler (r=3D0xaf2a880) at config.c:372
> =A0 =A0 =A0 =A0handler =3D 0x0
> =A0 =A0 =A0 =A0result =3D
> =A0 =A0 =A0 =A0old_handler =3D 0xaccbe38 "perl-script"
> =A0 =A0 =A0 =A0ignore =3D
> #16 0x08090798 in ap_process_request (r=3D0xaf2a880) at http_request.c:25=
8
> ---Type to continue, or q to quit---
> =A0 =A0 =A0 =A0access_status =3D 0
> #17 0x0808da3b in ap_process_http_connection (c=3D0xaf1a9d8) at http_core=
..c:190
> =A0 =A0 =A0 =A0r =3D (request_rec *) 0xaf2a880
> =A0 =A0 =A0 =A0csd =3D (apr_socket_t *) 0x0
> #18 0x0807dab9 in ap_run_process_connection (c=3D0xaf1a9d8) at connection=
..c:43
> =A0 =A0 =A0 =A0n =3D 1
> =A0 =A0 =A0 =A0rv =3D 40
> #19 0x080a3dc5 in child_main (child_num_arg=3D) at
> prefork.c:650
> =A0 =A0 =A0 =A0numdesc =3D 0
> =A0 =A0 =A0 =A0pdesc =3D (const apr_pollfd_t *) 0x0
> =A0 =A0 =A0 =A0current_conn =3D (conn_rec *) 0xaf1a9d8
> =A0 =A0 =A0 =A0csd =3D (void *) 0xaf1a840
> =A0 =A0 =A0 =A0ptrans =3D (apr_pool_t *) 0xaf1a800
> =A0 =A0 =A0 =A0allocator =3D (apr_allocator_t *) 0x9301738
> =A0 =A0 =A0 =A0status =3D
> =A0 =A0 =A0 =A0i =3D
> =A0 =A0 =A0 =A0lr =3D
> =A0 =A0 =A0 =A0pollset =3D (apr_pollset_t *) 0xaf18850
> =A0 =A0 =A0 =A0sbh =3D (ap_sb_handle_t *) 0xaf18848
> =A0 =A0 =A0 =A0bucket_alloc =3D (apr_bucket_alloc_t *) 0xaf1c808
> =A0 =A0 =A0 =A0last_poll_idx =3D 0
> #20 0x080a4087 in make_child (s=3D0x8d2fd70, slot=3D28) at prefork.c:746
> =A0 =A0 =A0 =A0pid =3D 0
> #21 0x080a49e0 in ap_mpm_run (_pconf=3D0x8d070a8, plog=3D0x8d451a0,
> s=3D0x8d2fd70) at prefork.c:881
> =A0 =A0 =A0 =A0status =3D 0
> =A0 =A0 =A0 =A0pid =3D {pid =3D -1, in =3D 0x8d01250, out =3D 0x2, err =
=3D 0xd070a8}
> =A0 =A0 =A0 =A0child_slot =3D
> =A0 =A0 =A0 =A0exitwhy =3D APR_PROC_EXIT
> =A0 =A0 =A0 =A0processed_status =3D
> =A0 =A0 =A0 =A0index =3D
> =A0 =A0 =A0 =A0remaining_children_to_start =3D 0
> =A0 =A0 =A0 =A0rv =3D
> #22 0x08064645 in main (argc=3D147869856, argv=3D0xaf187f8) at main.c:740
> =A0 =A0 =A0 =A0c =3D 0 '\0'
> =A0 =A0 =A0 =A0configtestonly =3D 0
> =A0 =A0 =A0 =A0confname =3D 0x80ae357 "conf/httpd.conf"
> =A0 =A0 =A0 =A0def_server_root =3D 0x80ae367 "/usr/local/apache2"
> =A0 =A0 =A0 =A0temp_error_log =3D 0x0
> =A0 =A0 =A0 =A0error =3D
> =A0 =A0 =A0 =A0process =3D (process_rec *) 0x8d05130
> =A0 =A0 =A0 =A0server_conf =3D
> =A0 =A0 =A0 =A0pglobal =3D (apr_pool_t *) 0x8d050a0
> =A0 =A0 =A0 =A0pconf =3D (apr_pool_t *) 0x8d070a8
> =A0 =A0 =A0 =A0plog =3D (apr_pool_t *) 0x8d451a0
> =A0 =A0 =A0 =A0ptemp =3D (apr_pool_t *) 0x8d491b0
> =A0 =A0 =A0 =A0pcommands =3D (apr_pool_t *) 0x8d090b0
> =A0 =A0 =A0 =A0opt =3D (apr_getopt_t *) 0x8d09150
> =A0 =A0 =A0 =A0rv =3D 0
> =A0 =A0 =A0 =A0optarg =3D 0x3b6ff4 "\234m;"
> (gdb)
>
>
> --
> =93Don't eat anything you've ever seen advertised on TV=94
> =A0 =A0 =A0 =A0 - Michael Pollan, author of "In Defense of Food"
>

Re: first time debugging apache/mod_perl Seg fault

> You're threaded.

Thanks

> What version of Apache and mod_perl are you running here?

httpd-2.2.10
mod_perl-2.0.4

> What configuration options are you using to build apache?

I didn't build it, and the guy who did is not in today, but we seem to
still have the config.log on-hand and it says simply :

$ ./configure



--=20
=93Don't eat anything you've ever seen advertised on TV=94
- Michael Pollan, author of "In Defense of Food"

Re: first time debugging apache/mod_perl Seg fault

Alan,

We fought a tiny issue last week that effected both worker (threaded) and p=
re-
fork (non-threaded) machines that used DBI for mysql connections.

Symptom were segmentation faults at seemingly random times over the past fe=
w=20
months, especially in the early morning hours on some slow weekends, in=20
certain applications. They ultimately produced proxy errors at the load=20
balancer.

http://rt.cpan.org/Public/Bug/Display.html?id=3D37027


So, our core dump was producing the following with gdb:
(gdb) #0 =A00x00002b8c60fae5ee in mysql_ping ()
from /usr/lib/libmysqlclient_r.so.15

A simple fix was to just upgrade affected machine's DBI from CPAN.

Anyway, recompiling perl to trap and dump (with meaningful info) per the=20
documents you cite below was a big help - with core dumping in place,=20
discovering the actual cause was kind of like tiger hunting with big gun; w=
e=20
set the trap, waited in the bushes... then BAM!.


Bryan


http://www.shiftboard.com
Online Scheduling


On Monday 13 July 2009 12:15:55 Alan McKay wrote:
> Hey folks,
>
> I'm running CentOS 5.2 with a custom built apache not from Yum.
>
> I am following instructions here
> http://perl.apache.org/docs/2.0/devel/debug/c.html#Getting_t he_core_File_=
Du
>mped
>
> and here :
> http://perl.apache.org/docs/2.0/devel/debug/c.html#Analyzing _Dumped_Core_=
=46i
>les
>
> I have mod_perl built with symbols and reproduce my problem, but I'm
> not having much luck with gdb. I really have no experience with this
> aspect of Linux so am shooting in the dark a bit here.
>
> I also have no idea whether I'm "threaded" or "unthreaded", so I tried
> both of the "curinfo" macros with no luck.
>
> Here is the output of "bt full" which clearly shows a few "my_perl"
> entries. But I'm just not clear how to find out what part of our
> Perl code is causing the issue.
>
> (gdb) bt full
> #0 0x0044e172 in Perl_cv_const_sv () from
> /usr/lib/perl5/5.8.8/i386-linux-thread-multi/CORE/libperl.so
> No symbol table info available.
> #1 0x00442a7c in Perl_yylex () from
> /usr/lib/perl5/5.8.8/i386-linux-thread-multi/CORE/libperl.so
> No symbol table info available.
> #2 0x0044b295 in Perl_yyparse () from
> /usr/lib/perl5/5.8.8/i386-linux-thread-multi/CORE/libperl.so
> No symbol table info available.
> #3 0x004b8200 in Perl_pp_range () from
> /usr/lib/perl5/5.8.8/i386-linux-thread-multi/CORE/libperl.so
> No symbol table info available.
> #4 0x004ba0b2 in Perl_pp_require () from
> /usr/lib/perl5/5.8.8/i386-linux-thread-multi/CORE/libperl.so
> No symbol table info available.
> #5 0x004ba7ad in Perl_pp_dofile () from
> /usr/lib/perl5/5.8.8/i386-linux-thread-multi/CORE/libperl.so
> No symbol table info available.
> #6 0x0048488f in Perl_runops_standard () from
> /usr/lib/perl5/5.8.8/i386-linux-thread-multi/CORE/libperl.so
> No symbol table info available.
> #7 0x00424ffe in Perl_magicname () from
> /usr/lib/perl5/5.8.8/i386-linux-thread-multi/CORE/libperl.so
> No symbol table info available.
> #8 0x00429806 in Perl_call_sv () from
> /usr/lib/perl5/5.8.8/i386-linux-thread-multi/CORE/libperl.so
> No symbol table info available.
> #9 0x00140a7f in modperl_callback (my_perl=3D0x9476458,
> handler=3D0xaccc268, p=3D0xaf2a840, r=3D0xaf2a880, s=3D0xad0bad0,
> args=3D0xbd473e8) at modperl_callback.c:101
> items =3D
> cv =3D
> sp =3D (SV **) 0xafead24
> status =3D 0
> #10 0x0014117a in modperl_callback_run_handlers (idx=3D6, type=3D4,
> r=3D0xaf2a880, c=3D0x0, s=3D0xad0bad0, pconf=3D0x0, plog=3D0x0, ptemp=3D0=
x0,
> run_mode=3DMP_HOOK_RUN_FIRST)
> at modperl_callback.c:262
> my_perl =3D (PerlInterpreter *) 0x9476458
> interp =3D (modperl_interp_t *) 0xa965888
> scfg =3D (modperl_config_srv_t *) 0x8d437b8
> dcfg =3D (modperl_config_dir_t *) 0xaf2a2e0
> rcfg =3D (modperl_config_req_t *) 0xaf2b5f0
> handlers =3D (modperl_handler_t **) 0xaccc298
> p =3D (apr_pool_t *) 0xaf2a840
> av =3D (MpAV *) 0xaccc280
> avp =3D
> i =3D 0
> status =3D 0
> desc =3D 0x158cd3 "PerlResponseHandler"
> av_args =3D (AV *) 0xbd473e8
> #11 0x0014180a in modperl_callback_per_dir (idx=3D6, r=3D0xaf2a880,
> run_mode=3DMP_HOOK_RUN_FIRST) at modperl_callback.c:369
> No locals.
> #12 0x0013a79f in modperl_response_handler_run (r=3D0xaf2a880, finish=3D0)
> at mod_perl.c:1000
> retval =3D
> #13 0x0013a96b in modperl_response_handler_cgi (r=3D0xaf2a880) at
> mod_perl.c:1100 dcfg =3D (modperl_config_dir_t *) 0xaf2a2e0
> h_stdin =3D (GV *) 0xc2d7a20
> h_stdout =3D (GV *) 0xb4ba144
> retval =3D -1
> rc =3D
> rcfg =3D (modperl_config_req_t *) 0xaf2b5f0
> my_perl =3D (PerlInterpreter *) 0x9476458
> interp =3D (modperl_interp_t *) 0xa965888
> #14 0x08076a79 in ap_run_handler (r=3D0xaf2a880) at config.c:157
> n =3D 6
> rv =3D 40
> #15 0x08079be7 in ap_invoke_handler (r=3D0xaf2a880) at config.c:372
> handler =3D 0x0
> result =3D
> old_handler =3D 0xaccbe38 "perl-script"
> ignore =3D
> #16 0x08090798 in ap_process_request (r=3D0xaf2a880) at http_request.c:258
> ---Type to continue, or q to quit---
> access_status =3D 0
> #17 0x0808da3b in ap_process_http_connection (c=3D0xaf1a9d8) at
> http_core.c:190 r =3D (request_rec *) 0xaf2a880
> csd =3D (apr_socket_t *) 0x0
> #18 0x0807dab9 in ap_run_process_connection (c=3D0xaf1a9d8) at
> connection.c:43 n =3D 1
> rv =3D 40
> #19 0x080a3dc5 in child_main (child_num_arg=3D) at
> prefork.c:650
> numdesc =3D 0
> pdesc =3D (const apr_pollfd_t *) 0x0
> current_conn =3D (conn_rec *) 0xaf1a9d8
> csd =3D (void *) 0xaf1a840
> ptrans =3D (apr_pool_t *) 0xaf1a800
> allocator =3D (apr_allocator_t *) 0x9301738
> status =3D
> i =3D
> lr =3D
> pollset =3D (apr_pollset_t *) 0xaf18850
> sbh =3D (ap_sb_handle_t *) 0xaf18848
> bucket_alloc =3D (apr_bucket_alloc_t *) 0xaf1c808
> last_poll_idx =3D 0
> #20 0x080a4087 in make_child (s=3D0x8d2fd70, slot=3D28) at prefork.c:746
> pid =3D 0
> #21 0x080a49e0 in ap_mpm_run (_pconf=3D0x8d070a8, plog=3D0x8d451a0,
> s=3D0x8d2fd70) at prefork.c:881
> status =3D 0
> pid =3D {pid =3D -1, in =3D 0x8d01250, out =3D 0x2, err =3D 0xd07=
0a8}
> child_slot =3D
> exitwhy =3D APR_PROC_EXIT
> processed_status =3D
> index =3D
> remaining_children_to_start =3D 0
> rv =3D
> #22 0x08064645 in main (argc=3D147869856, argv=3D0xaf187f8) at main.c:740
> c =3D 0 '\0'
> configtestonly =3D 0
> confname =3D 0x80ae357 "conf/httpd.conf"
> def_server_root =3D 0x80ae367 "/usr/local/apache2"
> temp_error_log =3D 0x0
> error =3D
> process =3D (process_rec *) 0x8d05130
> server_conf =3D
> pglobal =3D (apr_pool_t *) 0x8d050a0
> pconf =3D (apr_pool_t *) 0x8d070a8
> plog =3D (apr_pool_t *) 0x8d451a0
> ptemp =3D (apr_pool_t *) 0x8d491b0
> pcommands =3D (apr_pool_t *) 0x8d090b0
> opt =3D (apr_getopt_t *) 0x8d09150
> rv =3D 0
> optarg =3D 0x3b6ff4 "\234m;"
> (gdb)

Re: first time debugging apache/mod_perl Seg fault

Oh, the symptoms sound very, very similar to mine!

I'll try upgrading the module - thanks!


--=20
=93Don't eat anything you've ever seen advertised on TV=94
- Michael Pollan, author of "In Defense of Food"

Re: first time debugging apache/mod_perl Seg fault

Unfortunately it seems we are already up to the latest and greatest :

Bundle Bundle::DBI (T/TI/TIMB/DBI-1.609.tar.gz)
Module DBI (T/TI/TIMB/DBI-1.609.tar.gz)

Any further help on slugging through this?

On Mon, Jul 13, 2009 at 8:22 PM, Alan McKay wrote:
> Oh, the symptoms sound very, very similar to mine!
>
> I'll try upgrading the module - thanks!
>
>
> --
> =93Don't eat anything you've ever seen advertised on TV=94
> =A0 =A0 =A0 =A0 - Michael Pollan, author of "In Defense of Food"
>



--=20
=93Don't eat anything you've ever seen advertised on TV=94
- Michael Pollan, author of "In Defense of Food"

Re: first time debugging apache/mod_perl Seg fault

Here is what I am doing based on the mod-perl debugging page I
referred to in my first email. I basically load the core dump in
gdb, and then alternately do "up" and "curinfo" on each line shown.
Sometimes I end up with what I got here where I get to a certain point
and it says "cannot access memory at ...", and sometimes I can get
through the whole back trace in the "up/curinfo" manner without that.
But never does it tell me it found a my_perl

Not sure why sometimes I get that error and sometimes not. To the
best of my knowledge I'm doing the same thing every time.

> end
(gdb) bt
#0 0x0044e172 in Perl_cv_const_sv () from
/usr/lib/perl5/5.8.8/i386-linux-thread-multi/CORE/libperl.so
#1 0x00442a7c in Perl_yylex () from
/usr/lib/perl5/5.8.8/i386-linux-thread-multi/CORE/libperl.so
#2 0x0044b295 in Perl_yyparse () from
/usr/lib/perl5/5.8.8/i386-linux-thread-multi/CORE/libperl.so
#3 0x004b8200 in Perl_pp_range () from
/usr/lib/perl5/5.8.8/i386-linux-thread-multi/CORE/libperl.so
#4 0x004ba0b2 in Perl_pp_require () from
/usr/lib/perl5/5.8.8/i386-linux-thread-multi/CORE/libperl.so
#5 0x004ba7ad in Perl_pp_dofile () from
/usr/lib/perl5/5.8.8/i386-linux-thread-multi/CORE/libperl.so
#6 0x0048488f in Perl_runops_standard () from
/usr/lib/perl5/5.8.8/i386-linux-thread-multi/CORE/libperl.so
#7 0x00424ffe in Perl_magicname () from
/usr/lib/perl5/5.8.8/i386-linux-thread-multi/CORE/libperl.so
#8 0x00429806 in Perl_call_sv () from
/usr/lib/perl5/5.8.8/i386-linux-thread-multi/CORE/libperl.so
#9 0x00140a7f in modperl_callback (my_perl=3D0x9476458,
handler=3D0xaccc268, p=3D0xaf2a840, r=3D0xaf2a880, s=3D0xad0bad0,
args=3D0xbd473e8) at modperl_callback.c:101
#10 0x0014117a in modperl_callback_run_handlers (idx=3D6, type=3D4,
r=3D0xaf2a880, c=3D0x0, s=3D0xad0bad0, pconf=3D0x0, plog=3D0x0, ptemp=3D0x0=
,
run_mode=3DMP_HOOK_RUN_FIRST)
at modperl_callback.c:262
#11 0x0014180a in modperl_callback_per_dir (idx=3D6, r=3D0xaf2a880,
run_mode=3DMP_HOOK_RUN_FIRST) at modperl_callback.c:369
#12 0x0013a79f in modperl_response_handler_run (r=3D0xaf2a880, finish=3D0)
at mod_perl.c:1000
#13 0x0013a96b in modperl_response_handler_cgi (r=3D0xaf2a880) at mod_perl.=
c:1100
#14 0x08076a79 in ap_run_handler (r=3D0xaf2a880) at config.c:157
#15 0x08079be7 in ap_invoke_handler (r=3D0xaf2a880) at config.c:372
#16 0x08090798 in ap_process_request (r=3D0xaf2a880) at http_request.c:258
#17 0x0808da3b in ap_process_http_connection (c=3D0xaf1a9d8) at http_core.c=
:190
#18 0x0807dab9 in ap_run_process_connection (c=3D0xaf1a9d8) at connection.c=
:43
#19 0x080a3dc5 in child_main (child_num_arg=3D) at
prefork.c:650
#20 0x080a4087 in make_child (s=3D0x8d2fd70, slot=3D28) at prefork.c:746
#21 0x080a49e0 in ap_mpm_run (_pconf=3D0x8d070a8, plog=3D0x8d451a0,
s=3D0x8d2fd70) at prefork.c:881
#22 0x08064645 in main (argc=3D147869856, argv=3D0xaf187f8) at main.c:740
(gdb) curinfo
No symbol "my_perl" in current context.
(gdb) up
#1 0x00442a7c in Perl_yylex () from
/usr/lib/perl5/5.8.8/i386-linux-thread-multi/CORE/libperl.so
(gdb) curinfo
No symbol "my_perl" in current context.
(gdb) up
#2 0x0044b295 in Perl_yyparse () from
/usr/lib/perl5/5.8.8/i386-linux-thread-multi/CORE/libperl.so
(gdb) curinfo
No symbol "my_perl" in current context.
(gdb) up
#3 0x004b8200 in Perl_pp_range () from
/usr/lib/perl5/5.8.8/i386-linux-thread-multi/CORE/libperl.so
(gdb) curinfo
No symbol "my_perl" in current context.
(gdb) up
#4 0x004ba0b2 in Perl_pp_require () from
/usr/lib/perl5/5.8.8/i386-linux-thread-multi/CORE/libperl.so
(gdb) curinfo
No symbol "my_perl" in current context.
(gdb) up
#5 0x004ba7ad in Perl_pp_dofile () from
/usr/lib/perl5/5.8.8/i386-linux-thread-multi/CORE/libperl.so
(gdb) curinfo
No symbol "my_perl" in current context.
(gdb) up
#6 0x0048488f in Perl_runops_standard () from
/usr/lib/perl5/5.8.8/i386-linux-thread-multi/CORE/libperl.so
(gdb) curinfo
No symbol "my_perl" in current context.
(gdb) up
#7 0x00424ffe in Perl_magicname () from
/usr/lib/perl5/5.8.8/i386-linux-thread-multi/CORE/libperl.so
(gdb) curinfo
No symbol "my_perl" in current context.
(gdb) up
#8 0x00429806 in Perl_call_sv () from
/usr/lib/perl5/5.8.8/i386-linux-thread-multi/CORE/libperl.so
(gdb) curinfo
No symbol "my_perl" in current context.
(gdb) up
#9 0x00140a7f in modperl_callback (my_perl=3D0x9476458,
handler=3D0xaccc268, p=3D0xaf2a840, r=3D0xaf2a880, s=3D0xad0bad0,
args=3D0xbd473e8) at modperl_callback.c:101
101 modperl_callback.c: No such file or directory.
in modperl_callback.c
(gdb) curinfo
0Cannot access memory at address 0x600d
(gdb) up
#10 0x0014117a in modperl_callback_run_handlers (idx=3D6, type=3D4,
r=3D0xaf2a880, c=3D0x0, s=3D0xad0bad0, pconf=3D0x0, plog=3D0x0, ptemp=3D0x0=
,
run_mode=3DMP_HOOK_RUN_FIRST)
at modperl_callback.c:262
262 in modperl_callback.c
(gdb) curinfo
0Cannot access memory at address 0x600d
(gdb)


On Tue, Jul 14, 2009 at 9:08 AM, Alan McKay wrote:
> Unfortunately it seems we are already up to the latest and greatest :
>
> Bundle =A0 =A0 =A0 =A0 =A0Bundle::DBI =A0 =A0 (T/TI/TIMB/DBI-1.609.tar.gz=
)
> Module =A0 =A0 =A0 =A0 =A0DBI =A0 =A0 =A0 =A0 =A0 =A0 (T/TI/TIMB/DBI-1.60=
9.tar.gz)
>
> Any further help on slugging through this?
>
> On Mon, Jul 13, 2009 at 8:22 PM, Alan McKay wrote:
>> Oh, the symptoms sound very, very similar to mine!
>>
>> I'll try upgrading the module - thanks!
>>
>>
>> --
>> =93Don't eat anything you've ever seen advertised on TV=94
>> =A0 =A0 =A0 =A0 - Michael Pollan, author of "In Defense of Food"
>>
>
>
>
> --
> =93Don't eat anything you've ever seen advertised on TV=94
> =A0 =A0 =A0 =A0 - Michael Pollan, author of "In Defense of Food"
>



--=20
=93Don't eat anything you've ever seen advertised on TV=94
- Michael Pollan, author of "In Defense of Food"

Re: first time debugging apache/mod_perl Seg fault

OK, not much response from the list :-(

More googling and I'm trying this now :

http://modperlbook.org/html/21-5-8-Noninteractive-Perl-Debug ging-Under-mod_=
perl.html

Will keep y'all posted ...


--=20
=93Don't eat anything you've ever seen advertised on TV=94
- Michael Pollan, author of "In Defense of Food"

Re: first time debugging apache/mod_perl Seg fault

Alan McKay writes:

> Here is what I am doing based on the mod-perl debugging page I
> referred to in my first email. I basically load the core dump in
> gdb, and then alternately do "up" and "curinfo" on each line shown.
> Sometimes I end up with what I got here where I get to a certain point
> and it says "cannot access memory at ...", and sometimes I can get
> through the whole back trace in the "up/curinfo" manner without that.
> But never does it tell me it found a my_perl
>
> Not sure why sometimes I get that error and sometimes not. To the
> best of my knowledge I'm doing the same thing every time.
>
>> end
> (gdb) bt
> #0 0x0044e172 in Perl_cv_const_sv () from
> /usr/lib/perl5/5.8.8/i386-linux-thread-multi/CORE/libperl.so
> #1 0x00442a7c in Perl_yylex () from

It looks like maybe it's dying in the parser...

> /usr/lib/perl5/5.8.8/i386-linux-thread-multi/CORE/libperl.so
> #2 0x0044b295 in Perl_yyparse () from
> /usr/lib/perl5/5.8.8/i386-linux-thread-multi/CORE/libperl.so
> #3 0x004b8200 in Perl_pp_range () from
> /usr/lib/perl5/5.8.8/i386-linux-thread-multi/CORE/libperl.so
> #4 0x004ba0b2 in Perl_pp_require () from

....while parsing an external file. Maybe sticking some debugging
information around your require/use/do statements (inside of BEGIN
blocks) would help you narrow down what file it is.

I have had to debug these things before, and they're very painful! I
usually end up commenting out half the code at a time to narrow things
down, and it's never what I expect. Usually it's a module with a
compiled library, i.e. not a pure-Perl module.

Good luck!

----Scott.

Re: first time debugging apache/mod_perl Seg fault

> I have had to debug these things before, and they're very painful! =A0I
> usually end up commenting out half the code at a time to narrow things
> down, and it's never what I expect. =A0Usually it's a module with a
> compiled library, i.e. not a pure-Perl module.

Well, the really crummy thing is that it is sporadic. Our application
is in production and gets thousands of successful uses a day with no
problems. The core dumps are seemingly random and sporadic, and do
not greatly negatively affect the user.

But still we really want to get to the bottom of it.

Another issue with the matter of commenting stuff out is that our code
is MASSIVE, so that won't be easy.

But as per my other email, I'm now taking a slightly different
approach so we'll see where that gets me.


--=20
=93Don't eat anything you've ever seen advertised on TV=94
- Michael Pollan, author of "In Defense of Food"

Re: first time debugging apache/mod_perl Seg fault

> http://modperlbook.org/html/21-5-8-Noninteractive-Perl-Debug ging-Under-mo=
d_perl.html

OK, I'm doing this, but it seems that the file it produces only ever
gets up to 7.3M and that's it.

I'm guessing it is because when httpd forks off all the children, they
do not record to this file anymore.

So I try the -X option to prevent apache from forking, but our
application does not like that very much at all for some reason.

Also, the above link does not show me how to determine from the log
file where Apache crashed. All it says is "We will show only the part
that actually executes the handler created on the fly by
Apache::Registry:". OK, so what? That quote means nothing to me.
Can someone translate it into something that I understand (assuming it
is actually something to do with where Apache core dumps)

thanks,
-Alan


--=20
=93Don't eat anything you've ever seen advertised on TV=94
- Michael Pollan, author of "In Defense of Food"

Re: first time debugging apache/mod_perl Seg fault

Alan,

You might want to try mod_log_forensic to see what the request was
that crashed it.

- Perrin

On Tue, Jul 14, 2009 at 3:29 PM, Alan McKay wrote:
>> http://modperlbook.org/html/21-5-8-Noninteractive-Perl-Debug ging-Under-m=
od_perl.html
>
> OK, I'm doing this, but it seems that the file it produces only ever
> gets up to 7.3M and that's it.
>
> I'm guessing it is because when httpd forks off all the children, they
> do not record to this file anymore.
>
> So I try the -X option to prevent apache from forking, but our
> application does not like that very much at all for some reason.
>
> Also, the above link does not show me how to determine from the log
> file where Apache crashed. =A0All it says is "We will show only the part
> that actually executes the handler created on the fly by
> Apache::Registry:". =A0 OK, so what? =A0 That quote means nothing to me.
> Can someone translate it into something that I understand (assuming it
> is actually something to do with where Apache core dumps)
>
> thanks,
> -Alan
>
>
> --
> =93Don't eat anything you've ever seen advertised on TV=94
> =A0 =A0 =A0 =A0 - Michael Pollan, author of "In Defense of Food"
>

Re: first time debugging apache/mod_perl Seg fault

On Tue, Jul 14, 2009 at 4:56 PM, Perrin Harkins wrote:
> You might want to try mod_log_forensic to see what the request was
> that crashed it.

cool! Will look into that tomorrow (at home now)

thanks!


--=20
=93Don't eat anything you've ever seen advertised on TV=94
- Michael Pollan, author of "In Defense of Food"

Re: first time debugging apache/mod_perl Seg fault

Nope, I send a snippet of the log it produces to my front-end guy and
he told me that this would not really tell us anything more than we
already know.

Too high level.

Off to do more googling - unless anyone as any further suggestions.

I have a number of outstanding questions now in this thread that
nobody seems to be able to answer :-(

I'd really like to get back to my original method of using gdb ...

On Tue, Jul 14, 2009 at 5:19 PM, Alan McKay wrote:
> On Tue, Jul 14, 2009 at 4:56 PM, Perrin Harkins wrote=
:
>> You might want to try mod_log_forensic to see what the request was
>> that crashed it.
>
> cool! =A0Will look into that tomorrow (at home now)
>
> thanks!
>
>
> --
> =93Don't eat anything you've ever seen advertised on TV=94
> =A0 =A0 =A0 =A0 - Michael Pollan, author of "In Defense of Food"
>



--=20
=93Don't eat anything you've ever seen advertised on TV=94
- Michael Pollan, author of "In Defense of Food"

Re: first time debugging apache/mod_perl Seg fault

On Wed, Jul 15, 2009 at 12:31 PM, Alan McKay wrote:
> Nope, I send a snippet of the log it produces to my front-end guy and
> he told me that this would not really tell us anything more than we
> already know.
>
> Too high level.

Are you saying that you can't reproduce the crash by running the same
request again then?

- Perrin

Re: first time debugging apache/mod_perl Seg fault

> Are you saying that you can't reproduce the crash by running the same
> request again then?

The crash is very spurious - no - it cannot be reproduced every time.

Which is why getting down into the gdb level would seem to be the best
way about this problem


--=20
=93Don't eat anything you've ever seen advertised on TV=94
- Michael Pollan, author of "In Defense of Food"

Re: first time debugging apache/mod_perl Seg fault

On Tue, Jul 14, 2009 at 3:29 PM, Alan McKay wrote:
>> http://modperlbook.org/html/21-5-8-Noninteractive-Perl-Debug ging-Under-m=
od_perl.html
>
> OK, I'm doing this, but it seems that the file it produces only ever
> gets up to 7.3M and that's it.
>
> I'm guessing it is because when httpd forks off all the children, they
> do not record to this file anymore.
>
> So I try the -X option to prevent apache from forking, but our
> application does not like that very much at all for some reason.
>
> Also, the above link does not show me how to determine from the log
> file where Apache crashed. =A0All it says is "We will show only the part
> that actually executes the handler created on the fly by
> Apache::Registry:". =A0 OK, so what? =A0 That quote means nothing to me.
> Can someone translate it into something that I understand (assuming it
> is actually something to do with where Apache core dumps)

I haven't used this tracing feature, but the quote in the book is just
saying that he's showing only the beginning of the trace because it's
too long to reproduce there. You would be able to see where the crash
happened because the trace would simply end.there.

- Perrin

Re: first time debugging apache/mod_perl Seg fault

>>> http://modperlbook.org/html/21-5-8-Noninteractive-Perl-Debug ging-Under-=
mod_perl.html
>>
>> OK, I'm doing this, but it seems that the file it produces only ever
>> gets up to 7.3M and that's it.

OK, the reason the file only ever got to 7.3M was indeed because
apache would of course fork a bunch of processes.

The way to get around this is to start it in debug mode with the -X option.

We did this last night, and also figured out a way to get our load
tool to deal with it properly We use a product called Neo Load which
allows us to record a web session and then play it back but in playing
back you can change a whole whack of different options. In this case
we set it to 1 user, and only 1 connection. It worked!

We got a crash overnight and now have a good trace. My front-end guy
won't be in for another 3 hours to look at it, so I'll let y'all know
at that time whether or not we've caught it. But it sure is looking
good at least!

--=20
=93Don't eat anything you've ever seen advertised on TV=94
- Michael Pollan, author of "In Defense of Food"