Mailing List Archive: ModPerl: Dev

[mp2] frequent segfaults in APR::Table

Index | Next | Previous | View Threaded

tharper at livejournalinc

Dec 29, 2008, 3:56 PM

Post #1 of 4 (1612 views)
Permalink

[mp2] frequent segfaults in APR::Table

1. Problem Description:

I'm attempting to upgrade one of the largest (measured both by users and
lines of code, I suspect) mod_perl sites from mod_perl 1 to mod_perl 2,
and also from 32 bit OS to 64 bit at the same time. I converted our
calls to use the new API, and basic functionality started working.
However, I am experiencing frequent segfaults in APR::Table (stack trace
below) when loading pages. Somewhere betwen 1 out of every 2-4 page
loads will cause it. Identical problem occurs on:
64 bit Debian Lenny with stock mod_perl 2.0.4
64 bit Debian Lenny with hand-built mod_perl 2.0.5-dev from latest source.
64 bit Centos 5.2 with stock mod_perl 2.0.2.

Let me know if there is any other information you need. I have not yet
tried it with mod_perl 2 on a 32-bit OS.

2. Used Components and their Configuration:

*** mod_perl version 2.000004

*** using /root/modperl-2.0/lib/Apache2/BuildConfig.pm

*** Makefile.PL options:
MP_APR_LIB => aprext
MP_APXS => /usr/bin/apxs
MP_COMPAT_1X => 1
MP_DEBUG => 1
MP_GENERATE_XS => 1
MP_LIBNAME => mod_perl
MP_TRACE => 1
MP_USE_DSO => 1

*** The httpd binary was not found

*** (apr|apu)-config linking info

-L/usr/lib -laprutil-1
-L/usr/lib -lapr-1 -luuid -lrt -lcrypt -lpthread -ldl

*** /usr/bin/perl -V
Summary of my perl5 (revision 5 version 10 subversion 0) configuration:
Platform:
osname=linux, osvers=2.6.26-1-vserver-amd64,
archname=x86_64-linux-gnu-thread-multi
uname='linux excelsior 2.6.26-1-vserver-amd64 #1 smp sat nov 8
20:24:14 utc 2008 x86_64 gnulinux '
config_args='-Dusethreads -Duselargefiles -Dccflags=-DDEBIAN
-Dcccdlflags=-fPIC -Darchname=x86_64-linux-gnu -Dprefix=/usr
-Dprivlib=/usr/share/perl/5.10 -Darchlib=/usr/lib/perl/5.10
-Dvendorprefix=/usr -Dvendorlib=/usr/share/perl5
-Dvendorarch=/usr/lib/perl5 -Dsiteprefix=/usr/local
-Dsitelib=/usr/local/share/perl/5.10.0
-Dsitearch=/usr/local/lib/perl/5.10.0 -Dman1dir=/usr/share/man/man1
-Dman3dir=/usr/share/man/man3 -Dsiteman1dir=/usr/local/man/man1
-Dsiteman3dir=/usr/local/man/man3 -Dman1ext=1 -Dman3ext=3perl
-Dpager=/usr/bin/sensible-pager -Uafs -Ud_csh -Ud_ualarm -Uusesfio
-Uusenm -DDEBUGGING=-g -Doptimize=-O2 -Duseshrplib
-Dlibperl=libperl.so.5.10.0 -Dd_dosuid -des'
hint=recommended, useposix=true, d_sigaction=define
useithreads=define, usemultiplicity=define
useperlio=define, d_sfio=undef, uselargefiles=define, usesocks=undef
use64bitint=define, use64bitall=define, uselongdouble=undef
usemymalloc=n, bincompat5005=undef
Compiler:
cc='cc', ccflags ='-D_REENTRANT -D_GNU_SOURCE -DDEBIAN
-fno-strict-aliasing -pipe -I/usr/local/include -D_LARGEFILE_SOURCE
-D_FILE_OFFSET_BITS=64',
optimize='-O2 -g',
cppflags='-D_REENTRANT -D_GNU_SOURCE -DDEBIAN -fno-strict-aliasing
-pipe -I/usr/local/include'
ccversion='', gccversion='4.3.2', gccosandvers=''
intsize=4, longsize=8, ptrsize=8, doublesize=8, byteorder=12345678
d_longlong=define, longlongsize=8, d_longdbl=define, longdblsize=16
ivtype='long', ivsize=8, nvtype='double', nvsize=8, Off_t='off_t',
lseeksize=8
alignbytes=8, prototype=define
Linker and Libraries:
ld='cc', ldflags =' -L/usr/local/lib'
libpth=/usr/local/lib /lib /usr/lib /lib64 /usr/lib64
libs=-lgdbm -lgdbm_compat -ldb -ldl -lm -lpthread -lc -lcrypt
perllibs=-ldl -lm -lpthread -lc -lcrypt
libc=/lib/libc-2.7.so, so=so, useshrplib=true, libperl=libperl.so.5.10.0
gnulibc_version='2.7'
Dynamic Linking:
dlsrc=dl_dlopen.xs, dlext=so, d_dlsymun=undef, ccdlflags='-Wl,-E'
cccdlflags='-fPIC', lddlflags='-shared -O2 -g -L/usr/local/lib'

Characteristics of this binary (from libperl):
Compile-time options: MULTIPLICITY PERL_DONT_CREATE_GVSV
PERL_IMPLICIT_CONTEXT PERL_MALLOC_WRAP
USE_64_BIT_ALL
USE_64_BIT_INT USE_ITHREADS USE_LARGE_FILES
USE_PERLIO USE_REENTRANT_API
Built under linux
Compiled at Nov 27 2008 21:47:49
%ENV:
PERL_LWP_USE_HTTP_10="1"
@INC:
/etc/perl
/usr/local/lib/perl/5.10.0
/usr/local/share/perl/5.10.0
/usr/lib/perl5
/usr/share/perl5
/usr/lib/perl/5.10
/usr/share/perl/5.10
/usr/local/lib/site_perl
.

*** Packages of interest status:

Apache2 : -
Apache2::Request : 2.08
CGI : 3.29
ExtUtils::MakeMaker: 6.42, 6.48
LWP : 5.813
mod_perl : -
mod_perl2 : 2.000004

3. This is the core dump trace: (if you get a core dump):

#0 XS_APR__Table_FETCH (my_perl=0x1c04370, cv=<value optimized out>) at /root/.cpan/build/mod_perl-2.0.4-rIfY74/xs/APR/Table/APR__Table.h:186
#1 0x00007feb01ffde80 in Perl_pp_entersub (my_perl=0x1c04370) at pp_hot.c:2850
#2 0x00007feb01ffc362 in Perl_runops_standard (my_perl=0x1c04370) at run.c:38
#3 0x00007feb01ff67d8 in Perl_call_sv (my_perl=0x1c04370, sv=0x94a2bd0, flags=<value optimized out>) at perl.c:2638
#4 0x00007feb01fe638c in S_magic_methpack (my_perl=0x1c04370, sv=0x94a2ba0, mg=0x415b5a0, meth=0x7feb02097079 "FETCH") at mg.c:1635
#5 0x00007feb01fe651b in Perl_magic_getpack (my_perl=0x200000002, sv=0x94a2b88, mg=0x1) at mg.c:1650
#6 0x00007feb01fe9815 in Perl_mg_get (my_perl=0x1c04370, sv=0x94a2ba0) at mg.c:207
#7 0x00007feb0200f95b in Perl_sv_setsv_flags (my_perl=0x1c04370, dstr=0x94a2bb8, sstr=0x94a2ba0, flags=<value optimized out>) at sv.c:3507
#8 0x00007feb02010102 in Perl_sv_mortalcopy (my_perl=0x1c04370, oldstr=0x94a2ba0) at sv.c:6914
#9 0x00007feb02001a08 in Perl_pp_helem (my_perl=0x1c04370) at pp_hot.c:1823
#10 0x00007feb01ffc362 in Perl_runops_standard (my_perl=0x1c04370) at run.c:38
#11 0x00007feb01ff6b18 in Perl_call_sv (my_perl=0x1c04370, sv=0x72ed808, flags=4) at perl.c:2653
#12 0x00007feb022d8154 in modperl_callback () from /usr/lib/apache2/modules/mod_perl.so
#13 0x00007feb022d8864 in modperl_callback_run_handlers () from /usr/lib/apache2/modules/mod_perl.so
#14 0x00007feb022d8e5f in modperl_callback_per_dir () from /usr/lib/apache2/modules/mod_perl.so
#15 0x00007feb022d2900 in ?? () from /usr/lib/apache2/modules/mod_perl.so
#16 0x00007feb022d2ab9 in modperl_response_handler_cgi () from /usr/lib/apache2/modules/mod_perl.so
#17 0x0000000000438eb3 in ap_run_handler (r=0x934beb8) at /build/buildd/apache2-2.2.9/server/config.c:159
#18 0x000000000043c47f in ap_invoke_handler (r=0x934beb8) at /build/buildd/apache2-2.2.9/server/config.c:373
#19 0x000000000044962e in ap_process_request (r=0x934beb8) at /build/buildd/apache2-2.2.9/modules/http/http_request.c:258
#20 0x0000000000446748 in ap_process_http_connection (c=0x933e038) at /build/buildd/apache2-2.2.9/modules/http/http_core.c:190
#21 0x00000000004403d3 in ap_run_process_connection (c=0x933e038) at /build/buildd/apache2-2.2.9/server/connection.c:43
#22 0x000000000044dc20 in child_main (child_num_arg=<value optimized out>) at /build/buildd/apache2-2.2.9/server/mpm/prefork/prefork.c:672
#23 0x000000000044def8 in make_child (s=0x1b64968, slot=0) at /build/buildd/apache2-2.2.9/server/mpm/prefork/prefork.c:713
#24 0x000000000044e510 in ap_mpm_run (_pconf=<value optimized out>, plog=<value optimized out>, s=0x1b64968)
at /build/buildd/apache2-2.2.9/server/mpm/prefork/prefork.c:989
#25 0x0000000000425be5 in main (argc=2, argv=0x7fff116fa098) at /build/buildd/apache2-2.2.9/server/main.c:732

Method it crashes in:

/* Try to shortcut apr_table_get by fetching the key using the current
* iterator (unless it's inactive or points at different key).
*/
static MP_INLINE const char *mpxs_APR__Table_FETCH(pTHX_ SV *tsv,
const char *key)
{
SV* rv = modperl_hash_tied_object_rv(aTHX_ "APR::Table", tsv);
const int i = mpxs_apr_table_iterix(rv);
apr_table_t *t = INT2PTR(apr_table_t *, SvIVX(SvRV(rv)));
const apr_array_header_t *arr = apr_table_elts(t);
apr_table_entry_t *elts = (apr_table_entry_t *)arr->elts; <---crashing line 186

if (i > 0 && i <= arr->nelts && !strcasecmp(key, elts[i-1].key)) {
return elts[i-1].val;
}
else {
return apr_table_get(t, key);
}
}

This report was generated by ./t/REPORT on Mon Dec 29 23:20:20 2008 GMT.

-------------8<---------- End Bug Report --------------8<----------

---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe [at] perl
For additional commands, e-mail: dev-help [at] perl

gozer at ectoplasm

Dec 30, 2008, 7:05 PM

Post #2 of 4 (1504 views)
Permalink

Re: [mp2] frequent segfaults in APR::Table [In reply to]

On 29/12/08 18:56, Tupshin Harper wrote:
> 1. Problem Description:
>
> I'm attempting to upgrade one of the largest (measured both by users and
> lines of code, I suspect) mod_perl sites from mod_perl 1 to mod_perl 2,
> and also from 32 bit OS to 64 bit at the same time. I converted our
> calls to use the new API, and basic functionality started working.
> However, I am experiencing frequent segfaults in APR::Table (stack trace
> below) when loading pages.

Just out of curiosity, are you handling APR::Table objects directly ?

> Somewhere betwen 1 out of every 2-4 page
> loads will cause it. Identical problem occurs on:
> 64 bit Debian Lenny with stock mod_perl 2.0.4
> 64 bit Debian Lenny with hand-built mod_perl 2.0.5-dev from latest source.
> 64 bit Centos 5.2 with stock mod_perl 2.0.2.
>
> Let me know if there is any other information you need.

See below. Of course, a shorter, reproducible test case would be the ideal.

> I have not yet
> tried it with mod_perl 2 on a 32-bit OS.
>
> [...]
>
> Method it crashes in:
>
> /* Try to shortcut apr_table_get by fetching the key using the current
> * iterator (unless it's inactive or points at different key).
> */
> static MP_INLINE const char *mpxs_APR__Table_FETCH(pTHX_ SV *tsv,
> const char *key)
> {
> SV* rv = modperl_hash_tied_object_rv(aTHX_ "APR::Table", tsv);
> const int i = mpxs_apr_table_iterix(rv);
> apr_table_t *t = INT2PTR(apr_table_t *, SvIVX(SvRV(rv)));

Possibly smells like a 64 bit issue to me.

> const apr_array_header_t *arr = apr_table_elts(t);
> apr_table_entry_t *elts = (apr_table_entry_t *)arr->elts;<---crashing line 186

Can you get a little more information out of the current local variables.

i.e. I'd be interested in seeing the value of:

i
*t
*arr

Which you can easily do from withing gdb with

(gdb) display *t
(gdb) display *arr

--
Philippe M. Chiasson GPG: F9BFE0C2480E7680 1AE53631CB32A107 88C3A5A5
http://gozer.ectoplasm.org/ m/gozer\@(apache|cpan|ectoplasm)\.org/

---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe [at] perl
For additional commands, e-mail: dev-help [at] perl

tharper at livejournalinc

Dec 31, 2008, 2:39 AM

Post #3 of 4 (1498 views)
Permalink

Re: [mp2] frequent segfaults in APR::Table [In reply to]

Some comments inline, but the really useful stuff at the bottom.

Thank you very much for your help.

-Tupshin

Philippe M. Chiasson wrote:
> On 29/12/08 18:56, Tupshin Harper wrote:
>> 1. Problem Description:
>>
>> I'm attempting to upgrade one of the largest (measured both by users and
>> lines of code, I suspect) mod_perl sites from mod_perl 1 to mod_perl 2,
>> and also from 32 bit OS to 64 bit at the same time. I converted our
>> calls to use the new API, and basic functionality started working.
>> However, I am experiencing frequent segfaults in APR::Table (stack trace
>> below) when loading pages.
>
> Just out of curiosity, are you handling APR::Table objects directly ?
The only places where APR is ever mentioned are:
http://code.livejournal.org/trac/livejournal/browser/branches/modernize/cgi-bin/LJ/Request/Apache2.pm
(comment line 76)
and
http://code.livejournal.org/trac/bml/browser/branches/modernize/lib/Apache/BML.pm
(the two "use" statements, but those appear to actually be unused.

So no.
>
>> Somewhere betwen 1 out of every 2-4 page
>> loads will cause it. Identical problem occurs on:
>> 64 bit Debian Lenny with stock mod_perl 2.0.4
>> 64 bit Debian Lenny with hand-built mod_perl 2.0.5-dev from latest
>> source.
>> 64 bit Centos 5.2 with stock mod_perl 2.0.2.
>>
>> Let me know if there is any other information you need.
>
> See below. Of course, a shorter, reproducible test case would be the
> ideal.
Agreed, but given the complexity of the entire system and the fact that
we are using a home-brewed templating system (bml), makes it quite
difficult. I'll work on that if nothing else proves fruitful.
>
>> I have not yet
>> tried it with mod_perl 2 on a 32-bit OS.
>>
>> [...]
>>
>> Method it crashes in:
>>
>> /* Try to shortcut apr_table_get by fetching the key using the current
>> * iterator (unless it's inactive or points at different key).
>> */
>> static MP_INLINE const char *mpxs_APR__Table_FETCH(pTHX_ SV *tsv,
>> const char *key)
>> {
>> SV* rv = modperl_hash_tied_object_rv(aTHX_ "APR::Table", tsv);
>> const int i = mpxs_apr_table_iterix(rv);
>> apr_table_t *t = INT2PTR(apr_table_t *, SvIVX(SvRV(rv)));
>
> Possibly smells like a 64 bit issue to me.
My next step will be to confirm this theory by bringing it up on a 32
bit instance.
>
>> const apr_array_header_t *arr = apr_table_elts(t);
>> apr_table_entry_t *elts = (apr_table_entry_t
>> *)arr->elts;<---crashing line 186
>
> Can you get a little more information out of the current local variables.
>
> i.e. I'd be interested in seeing the value of:
>
> i
> *t
> *arr
>
> Which you can easily do from withing gdb with
>
> (gdb) display *t
> (gdb) display *arr
>
"i" is never anything but zero in the cases I'm looking at
a typical value for "t" is "(apr_table_t *) 0x956bfa0"
but printing *t always generates <incomplete type>
however, there is useful wrongness in "arr" and "elts".

A quick adendum to my previous report:

Sometimes it crashes directly on line 186, and in those cases, arr =
0x4f5349203a746573 (or something similar), and printing *arr reasonably
says "Cannot access memory at address 0x4f5349203a746573"

In other cases, it crashes within the apr_table_get(t, key) call on line
192. In those cases, "arr" is more reasonable, e.g.
(const apr_array_header_t *) 0x956bfa0
but *arr is:
{pool = 0x636f6c2f7273752f, elt_size = 1932487777, nelts = 980314466,
nalloc = 1920169263,
elts = 0x2f3a6e69622f6c61 <Address 0x2f3a6e69622f6c61 out of bounds>}
elts is:
(apr_table_entry_t *) 0x2f3a6e69622f6c61
and *elts is:
Cannot access memory at address 0x2f3a6e69622f6c61

So, to summarize, when it crashes on line 186, *arr is a bad pointer,
and when it crashes when calling apr_table_get from line 192, *elts is a
bad pointer.

Thanks.

-Tupshin

---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe [at] perl
For additional commands, e-mail: dev-help [at] perl

gozer at ectoplasm

Jan 7, 2009, 9:06 PM

Post #4 of 4 (1442 views)
Permalink

Re: [mp2] frequent segfaults in APR::Table [In reply to]

On 31/12/08 05:39, Tupshin Harper wrote:
> Some comments inline, but the really useful stuff at the bottom.

Same here, keep reading ;-)

> Thank you very much for your help.
>
> -Tupshin
>
> Philippe M. Chiasson wrote:
>> On 29/12/08 18:56, Tupshin Harper wrote:
>>> 1. Problem Description:
>>>
>>> I'm attempting to upgrade one of the largest (measured both by users and
>>> lines of code, I suspect) mod_perl sites from mod_perl 1 to mod_perl 2,
>>> and also from 32 bit OS to 64 bit at the same time. I converted our
>>> calls to use the new API, and basic functionality started working.
>>> However, I am experiencing frequent segfaults in APR::Table (stack trace
>>> below) when loading pages.
>> Just out of curiosity, are you handling APR::Table objects directly ?
> The only places where APR is ever mentioned are:
> http://code.livejournal.org/trac/livejournal/browser/branches/modernize/cgi-bin/LJ/Request/Apache2.pm
> (comment line 76)
> and
> http://code.livejournal.org/trac/bml/browser/branches/modernize/lib/Apache/BML.pm
> (the two "use" statements, but those appear to actually be unused.

Sometimes, when you call something in mod_perl land, you might get an APR::Table back, say:

my $o = $r->headers_out;

#$o is an APR::Table now, and you need to
use APR::Table;

#before you can call
$o->get([...])

> So no.

Okay, so this probably means you are hitting a mod_perl bug, not something
evil your code is doing with APR::Table's

>>> Somewhere betwen 1 out of every 2-4 page
>>> loads will cause it. Identical problem occurs on:
>>> 64 bit Debian Lenny with stock mod_perl 2.0.4
>>> 64 bit Debian Lenny with hand-built mod_perl 2.0.5-dev from latest
>>> source.
>>> 64 bit Centos 5.2 with stock mod_perl 2.0.2.
>>>
>>> Let me know if there is any other information you need.
>> See below. Of course, a shorter, reproducible test case would be the
>> ideal.
> Agreed, but given the complexity of the entire system and the fact that
> we are using a home-brewed templating system (bml), makes it quite
> difficult. I'll work on that if nothing else proves fruitful.

I know, it's sometimes tricky to boil down problems that only appear sometimes
in the wild and in a large system.

>>> I have not yet
>>> tried it with mod_perl 2 on a 32-bit OS.
>>>
>>> [...]
>>>
>>> Method it crashes in:
>>>
>>> /* Try to shortcut apr_table_get by fetching the key using the current
>>> * iterator (unless it's inactive or points at different key).
>>> */
>>> static MP_INLINE const char *mpxs_APR__Table_FETCH(pTHX_ SV *tsv,
>>> const char *key)
>>> {
>>> SV* rv = modperl_hash_tied_object_rv(aTHX_ "APR::Table", tsv);
>>> const int i = mpxs_apr_table_iterix(rv);
>>> apr_table_t *t = INT2PTR(apr_table_t *, SvIVX(SvRV(rv)));
>> Possibly smells like a 64 bit issue to me.
> My next step will be to confirm this theory by bringing it up on a 32
> bit instance.

Any changes/update with that ?

>>> const apr_array_header_t *arr = apr_table_elts(t);
>>> apr_table_entry_t *elts = (apr_table_entry_t
>>> *)arr->elts;<---crashing line 186
>> Can you get a little more information out of the current local variables.
>>
>> i.e. I'd be interested in seeing the value of:
>>
>> i
>> *t
>> *arr
>>
>> Which you can easily do from withing gdb with
>>
>> (gdb) display *t
>> (gdb) display *arr
>>
> "i" is never anything but zero in the cases I'm looking at
> a typical value for "t" is "(apr_table_t *) 0x956bfa0"
> but printing *t always generates<incomplete type>
> however, there is useful wrongness in "arr" and "elts".
>
> A quick adendum to my previous report:
>
> Sometimes it crashes directly on line 186, and in those cases, arr =
> 0x4f5349203a746573 (or something similar), and printing *arr reasonably
> says "Cannot access memory at address 0x4f5349203a746573"
>
> In other cases, it crashes within the apr_table_get(t, key) call on line
> 192. In those cases, "arr" is more reasonable, e.g.
> (const apr_array_header_t *) 0x956bfa0
> but *arr is:
> {pool = 0x636f6c2f7273752f, elt_size = 1932487777, nelts = 980314466,
> nalloc = 1920169263,
> elts = 0x2f3a6e69622f6c61<Address 0x2f3a6e69622f6c61 out of bounds>}
> elts is:
> (apr_table_entry_t *) 0x2f3a6e69622f6c61
> and *elts is:
> Cannot access memory at address 0x2f3a6e69622f6c61
>
> So, to summarize, when it crashes on line 186, *arr is a bad pointer,
> and when it crashes when calling apr_table_get from line 192, *elts is a
> bad pointer.

Starting to smell more and more like bad pointer mangling when in 64bit.

Forgot to ask, but can you dump the SV *rv and *tsv like so:

(gdb) call sv_dump(rv)
(gdb) call sv_dump(tsv)

Thanks, in the meantime, I am trying to visualize why this might be
hapenning. Everything so far looks like it's using the correct macros
to safely convery between IV and pointer. Hrm.

One way to dig into this further would be to add extra debugging to
modperl_hash_tied_object
modperl_hash_tie

when classname=="APR::Table"

and see how the void * is converted back and forth.

--
Philippe M. Chiasson GPG: F9BFE0C2480E7680 1AE53631CB32A107 88C3A5A5
http://gozer.ectoplasm.org/ m/gozer\@(apache|cpan|ectoplasm)\.org/

---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe [at] perl
For additional commands, e-mail: dev-help [at] perl

Index | Next | Previous | View Threaded

Interested in having your list archived? Contact Gossamer Threads