Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

segmentation fault in mg.c on Fedora 16-x64 #11845

Open
p5pRT opened this issue Jan 3, 2012 · 22 comments
Open

segmentation fault in mg.c on Fedora 16-x64 #11845

p5pRT opened this issue Jan 3, 2012 · 22 comments

Comments

@p5pRT
Copy link

p5pRT commented Jan 3, 2012

Migrated from rt.perl.org#107480 (status was 'open')

Searchable as RT107480$

@p5pRT
Copy link
Author

p5pRT commented Jan 3, 2012

From erik@thekrib.com

Created by erik@thekrib.com

Running the sympa mailing list software via its fastcgi module wwsympa.fcgi,

when I perform various functions like subscribe/unsubscribe that cause an e-mail to be generated,
I get a segfault in libperl.so

Another person has reported this under openSUSE, same version of perl. It formerly worked in perl 5.12.

E-mail thread​: https://listes.cru.fr/sympa/arc/sympa-users/2012-01/msg00005.html

I am using Fedora 16, stock distribution perl, modules installed via CPAN.

Enabled crash dumps, shows that in all of the different cases, it's crashing on the same line, mg.c#232

I can send full crash dumps if needed, as well as result of -d​:Trace. Here is snippet of relevant bt​:

[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib64/libthread_db.so.1".
Core was generated by `/usr/bin/perl -U -d​:Trace
/home/sympa/bin/wwsympa.fcgi'.
Program terminated with signal 11, Segmentation fault.
#0 0x00007fe01a823821 in Perl_mg_get (my_perl=0xbd3010, sv=0x61ac888) at mg.c​:232
232 if (!(mg->mg_flags & MGf_GSKIP) && vtbl && vtbl->svt_get) {
(gdb) bt
#0 0x00007fe01a823821 in Perl_mg_get (my_perl=0xbd3010, sv=0x61ac888) at mg.c​:232
#1 0x00007fe01a8467e1 in Perl_sv_setsv_flags (my_perl=0xbd3010, dstr=0x68ebe08, sstr=0x61ac888, flags=18) at sv.c​:4097
#2 0x00007fe01a84754b in Perl_newSVsv (my_perl=0xbd3010, old=<optimized out>) at sv.c​:8733
#3 0x00007fe01a7fd3d6 in S_pad_findlex (my_perl=0xbd3010, name=<optimized out>, cv=<optimized out>, seq=<optimized out>, warn=1, out_capture=0x0,
[...]

(gdb) print mg
$1 = (MAGIC *) 0xbd6d28
(gdb) print mg->mg_flags
$2 = 0 '\000'
(gdb) print vtbl
$3 = (const MGVTBL * const) 0x2200000c00000003
(gdb) print vtbl->svt_get
Cannot access memory at address 0x2200000c00000003
(gdb) print mg->mg_virtual
$4 = (MGVTBL *) 0x2200000c00000003

Alignment bug? Stepping on freed memory? Thanks for any help! I can provide any support. This is 100% reproducible for me.

- Erik

Perl Info

Flags:
    category=core
    severity=critical

This perlbug was built using Perl 5.14.2 in the Fedora build system.
It is being executed now by Perl 5.14.2 - Fri Nov 18 10:40:04 UTC 2011.

Site configuration information for perl 5.14.2:

Configured by Red Hat, Inc. at Fri Nov 18 10:40:04 UTC 2011.

Summary of my perl5 (revision 5 version 14 subversion 2) configuration:
   
  Platform:
    osname=linux, osvers=2.6.32-131.17.1.el6.x86_64, archname=x86_64-linux-thread-multi
    uname='linux x86-09.phx2.fedoraproject.org 2.6.32-131.17.1.el6.x86_64 #1 smp thu sep 29 10:24:25 edt 2011 x86_64 x86_64 x86_64 gnulinux '
    config_args='-des -Doptimize=-O2 -g -pipe -Wall -Wp,-D_FORTIFY_SOURCE=2 -fexceptions -fstack-protector --param=ssp-buffer-size=4  -m64 -mtune=generic -Dccdlflags=-Wl,--enable-new-dtags -DDEBUGGING=-g -Dversion=5.14.2 -Dmyhostname=localhost -Dperladmin=root@localhost -Dcc=gcc -Dcf_by=Red Hat, Inc. -Dprefix=/usr -Dvendorprefix=/usr -Dsiteprefix=/usr/local -Dsitelib=/usr/local/share/perl5 -Dsitearch=/usr/local/lib64/perl5 -Dprivlib=/usr/share/perl5 -Dvendorlib=/usr/share/perl5/vendor_perl -Darchlib=/usr/lib64/perl5 -Dvendorarch=/usr/lib64/perl5/vendor_perl -Darchname=x86_64-linux-thread-multi -Dlibpth=/usr/local/lib64 /lib64 /usr/lib64 -Duseshrplib -Dusethreads -Duseithreads -Dusedtrace=/usr/bin/dtrace -Duselargefiles -Dd_semctl_semun -Di_db -Ui_ndbm -Di_gdbm -Di_shadow -Di_syslog -Dman3ext=3pm -Duseperlio -Dinstallusrbinperl=n -Ubincompat5005 -Uversiononly -Dpager=/usr/bin/less -isr -Dd_gethostent_r_proto -Ud_endhostent_r_proto -Ud_sethostent_r_proto -Ud_endprotoent_r_prot!
 o -Ud_setprotoent_r_proto -Ud_endservent_r_proto -Ud_setservent_r_proto -Dscriptdir=/usr/bin'
    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='gcc', ccflags ='-D_REENTRANT -D_GNU_SOURCE -fno-strict-aliasing -pipe -fstack-protector -I/usr/local/include -D_LARGEFILE_SOURCE -D_FILE_OFFSET_BITS=64',
    optimize='-O2 -g -pipe -Wall -Wp,-D_FORTIFY_SOURCE=2 -fexceptions -fstack-protector --param=ssp-buffer-size=4 -m64 -mtune=generic',
    cppflags='-D_REENTRANT -D_GNU_SOURCE -fno-strict-aliasing -pipe -fstack-protector -I/usr/local/include'
    ccversion='', gccversion='4.6.2 20111027 (Red Hat 4.6.2-1)', 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='gcc', ldflags =' -fstack-protector'
    libpth=/usr/local/lib64 /lib64 /usr/lib64
    libs=-lresolv -lnsl -lgdbm -ldb -ldl -lm -lcrypt -lutil -lpthread -lc -lgdbm_compat
    perllibs=-lresolv -lnsl -ldl -lm -lcrypt -lutil -lpthread -lc
    libc=, so=so, useshrplib=true, libperl=libperl.so
    gnulibc_version='2.14.90'
  Dynamic Linking:
    dlsrc=dl_dlopen.xs, dlext=so, d_dlsymun=undef, ccdlflags='-Wl,--enable-new-dtags -Wl,-rpath,/usr/lib64/perl5/CORE'
    cccdlflags='-fPIC', lddlflags='-shared -O2 -g -pipe -Wall -Wp,-D_FORTIFY_SOURCE=2 -fexceptions -fstack-protector --param=ssp-buffer-size=4 -m64 -mtune=generic'

Locally applied patches:
    


@INC for perl 5.14.2:
    /usr/local/lib64/perl5
    /usr/local/share/perl5
    /usr/lib64/perl5/vendor_perl
    /usr/share/perl5/vendor_perl
    /usr/lib64/perl5
    /usr/share/perl5
    .


Environment for perl 5.14.2:
    HOME=/root
    LANG=en_US.UTF-8
    LANGUAGE (unset)
    LD_LIBRARY_PATH (unset)
    LOGDIR (unset)
    PATH=/usr/lib64/ccache:/usr/local/bin:/bin:/usr/bin:/usr/local/sbin:/usr/sbin:/sbin:/home/erik/bin
    PERL_BADLANG (unset)
    SHELL=/bin/bash

@p5pRT
Copy link
Author

p5pRT commented Jan 3, 2012

From @cpansprout

On Tue Jan 03 11​:43​:51 2012, erik@​thekrib.com wrote​:

Running the sympa mailing list software via its fastcgi module
wwsympa.fcgi,

when I perform various functions like subscribe/unsubscribe that cause
an e-mail to be generated,
I get a segfault in libperl.so

Another person has reported this under openSUSE, same version of perl.
It formerly worked in perl 5.12.

E-mail thread​: https://listes.cru.fr/sympa/arc/sympa-users/2012-
01/msg00005.html

I am using Fedora 16, stock distribution perl, modules installed via
CPAN.

Enabled crash dumps, shows that in all of the different cases, it's
crashing on the same line, mg.c#232

I can send full crash dumps if needed, as well as result of -d​:Trace.
Here is snippet of relevant bt​:

[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib64/libthread_db.so.1".
Core was generated by `/usr/bin/perl -U -d​:Trace
/home/sympa/bin/wwsympa.fcgi'.
Program terminated with signal 11, Segmentation fault.
#0 0x00007fe01a823821 in Perl_mg_get (my_perl=0xbd3010, sv=0x61ac888)
at mg.c​:232
232 if (!(mg->mg_flags & MGf_GSKIP) && vtbl && vtbl->svt_get) {
(gdb) bt
#0 0x00007fe01a823821 in Perl_mg_get (my_perl=0xbd3010, sv=0x61ac888)
at mg.c​:232
#1 0x00007fe01a8467e1 in Perl_sv_setsv_flags (my_perl=0xbd3010,
dstr=0x68ebe08, sstr=0x61ac888, flags=18) at sv.c​:4097
#2 0x00007fe01a84754b in Perl_newSVsv (my_perl=0xbd3010,
old=<optimized out>) at sv.c​:8733
#3 0x00007fe01a7fd3d6 in S_pad_findlex (my_perl=0xbd3010,
name=<optimized out>, cv=<optimized out>, seq=<optimized out>,
warn=1, out_capture=0x0,
[...]

(gdb) print mg
$1 = (MAGIC *) 0xbd6d28
(gdb) print mg->mg_flags
$2 = 0 '\000'
(gdb) print vtbl
$3 = (const MGVTBL * const) 0x2200000c00000003
(gdb) print vtbl->svt_get
Cannot access memory at address 0x2200000c00000003
(gdb) print mg->mg_virtual
$4 = (MGVTBL *) 0x2200000c00000003

Alignment bug? Stepping on freed memory? Thanks for any help! I can
provide any support. This is 100% reproducible for me.

I don’t really know where to begin. But you could try

  call Perl_warn(my_perl, "here")

in gdb to see which piece of Perl code it’s crashing on.

Is there any chance you could do a binary search to find out which
change was responsible?

--

Father Chrysostomos

@p5pRT
Copy link
Author

p5pRT commented Jan 3, 2012

The RT System itself - Status changed from 'new' to 'open'

@p5pRT
Copy link
Author

p5pRT commented Jan 4, 2012

From erik@thekrib.com

On Tue, 3 Jan 2012, Father Chrysostomos via RT wrote​:

On Tue Jan 03 11​:43​:51 2012, erik@​thekrib.com wrote​:

Running the sympa mailing list software via its fastcgi module
wwsympa.fcgi,

when I perform various functions like subscribe/unsubscribe that cause
an e-mail to be generated,
I get a segfault in libperl.so

Another person has reported this under openSUSE, same version of perl.
It formerly worked in perl 5.12.

E-mail thread​: https://listes.cru.fr/sympa/arc/sympa-users/2012-
01/msg00005.html

I am using Fedora 16, stock distribution perl, modules installed via
CPAN.

Enabled crash dumps, shows that in all of the different cases, it's
crashing on the same line, mg.c#232

I can send full crash dumps if needed, as well as result of -d​:Trace.
Here is snippet of relevant bt​:

[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib64/libthread_db.so.1".
Core was generated by `/usr/bin/perl -U -d​:Trace
/home/sympa/bin/wwsympa.fcgi'.
Program terminated with signal 11, Segmentation fault.
#0 0x00007fe01a823821 in Perl_mg_get (my_perl=0xbd3010, sv=0x61ac888)
at mg.c​:232
232 if (!(mg->mg_flags & MGf_GSKIP) && vtbl && vtbl->svt_get) {
(gdb) bt
#0 0x00007fe01a823821 in Perl_mg_get (my_perl=0xbd3010, sv=0x61ac888)
at mg.c​:232
#1 0x00007fe01a8467e1 in Perl_sv_setsv_flags (my_perl=0xbd3010,
dstr=0x68ebe08, sstr=0x61ac888, flags=18) at sv.c​:4097
#2 0x00007fe01a84754b in Perl_newSVsv (my_perl=0xbd3010,
old=<optimized out>) at sv.c​:8733
#3 0x00007fe01a7fd3d6 in S_pad_findlex (my_perl=0xbd3010,
name=<optimized out>, cv=<optimized out>, seq=<optimized out>,
warn=1, out_capture=0x0,
[...]

(gdb) print mg
$1 = (MAGIC *) 0xbd6d28
(gdb) print mg->mg_flags
$2 = 0 '\000'
(gdb) print vtbl
$3 = (const MGVTBL * const) 0x2200000c00000003
(gdb) print vtbl->svt_get
Cannot access memory at address 0x2200000c00000003
(gdb) print mg->mg_virtual
$4 = (MGVTBL *) 0x2200000c00000003

Alignment bug? Stepping on freed memory? Thanks for any help! I can
provide any support. This is 100% reproducible for me.

I don’t really know where to begin. But you could try

call Perl_warn(my_perl, "here")

in gdb to see which piece of Perl code it’s crashing on.

Is there any chance you could do a binary search to find out which
change was responsible?

Thank you for responding so quickly!

Because this is run out out of a cgi script, I'm relying on core dumps as
the process segfaults. So the process is gone. I tried attaching, and
didn't get anything from call Perl_warn(my_perl, "here").

But I did some more digging in one of the core dumps. This caught my eye...

(gdb) frame 0
#0 0x00007fbff7a7f821 in Perl_mg_get (my_perl=0x1d4f010, sv=0x5e8d328) at mg.c​:232
232 if (!(mg->mg_flags & MGf_GSKIP) && vtbl && vtbl->svt_get) {
(gdb) print mg
$3 = (MAGIC *) 0x1d52bd8
(gdb) print *mg
$4 = {mg_moremagic = 0x1d57620, mg_virtual = 0x2200000c00000003, mg_private = 39744, mg_type = -42 '\326', mg_flags = 1 '\001', mg_len = 0,
  mg_obj = 0x1d651a0, mg_ptr = 0x800900000001 <Address 0x800900000001 out of bounds>}

  **** These look to be bogus values for mg structure -- in particular, mg_virtual, which is unlike all other pointers I've seen.
  **** mg is obtained as sv->sv_any->xmg_magic

(gdb) print sv
$5 = (SV *) 0x5e8d328
(gdb) print *sv
$6 = {sv_any = 0x58ef6a0, sv_refcnt = 2, sv_flags = 1074021383, sv_u = {svu_pv = 0x5fd8450 "%alias", svu_iv = 100500560, svu_uv = 100500560,
  svu_rv = 0x5fd8450, svu_array = 0x5fd8450, svu_hash = 0x5fd8450, svu_gp = 0x5fd8450, svu_fp = 0x5fd8450}}

sv_flags in hex is = 40044407 -- includes svpad_name and svpad_our flags.

(gdb) print sv->sv_any
$7 = (void *) 0x58ef6a0
(gdb) print (XPVMG *)0x58ef6a0
$8 = (XPVMG *) 0x58ef6a0
(gdb) print *((XPVMG *)0x58ef6a0)
$9 = {xmg_stash = 0x0, xmg_u = {xmg_magic = 0x1d52bd8, xmg_ourstash = 0x1d52bd8}, xpv_cur = 6, xpv_len = 16, xiv_u = {xivu_iv = 0, xivu_uv = 0,
  xivu_i32 = 0, xivu_namehek = 0x0}, xnv_u = {xnv_nv = -nan(0xfffff00009f5a), xgv_stash = 0xffffffff00009f5a, xpad_cop_seq = {xlow = 40794,
  xhigh = 4294967295}, xbm_s = {xbm_previous = 40794, xbm_flags = 255 '\377', xbm_rare = 255 '\377'}}}

sv->sv_any looks good.

So based on xmg_u being a union, I tried to look at xmg_u as xmg_ourstash

(gdb) print *((HV *)0x1d52bd8)
$11 = {sv_any = 0x1d57620, sv_refcnt = 3, sv_flags = 570425356, sv_u = {svu_pv = 0x1d69b40 "", svu_iv = 30841664, svu_uv = 30841664, svu_rv = 0x1d69b40,
  svu_array = 0x1d69b40, svu_hash = 0x1d69b40, svu_gp = 0x1d69b40, svu_fp = 0x1d69b40}}

The code in Perl_mg_get() is walking that link to xmg_magic without checking the flags first?

  - Erik

--
Erik Olson
Sent from my spiffy new Linux box

@p5pRT
Copy link
Author

p5pRT commented Jan 5, 2012

From @cpansprout

On Wed Jan 04 08​:10​:13 2012, erik@​thekrib.com wrote​:

But I did some more digging in one of the core dumps. This caught my
eye...

(gdb) frame 0
#0 0x00007fbff7a7f821 in Perl_mg_get (my_perl=0x1d4f010,
sv=0x5e8d328) at mg.c​:232
232 if (!(mg->mg_flags & MGf_GSKIP) && vtbl && vtbl-

svt_get) {
(gdb) print mg
$3 = (MAGIC *) 0x1d52bd8
(gdb) print *mg
$4 = {mg_moremagic = 0x1d57620, mg_virtual = 0x2200000c00000003,
mg_private = 39744, mg_type = -42 '\326', mg_flags = 1 '\001', mg_len
= 0,
mg_obj = 0x1d651a0, mg_ptr = 0x800900000001 <Address 0x800900000001
out of bounds>}

**** These look to be bogus values for mg structure -- in
particular, mg_virtual, which is unlike all other pointers I've seen.
**** mg is obtained as sv->sv_any->xmg_magic

That entire magic structure is garbage. There is no magic type '\326'.
All magic types apart from '\0' are ASCII characters.

(gdb) print sv
$5 = (SV *) 0x5e8d328
(gdb) print *sv
$6 = {sv_any = 0x58ef6a0, sv_refcnt = 2, sv_flags = 1074021383, sv_u =
{svu_pv = 0x5fd8450 "%alias", svu_iv = 100500560, svu_uv = 100500560,
svu_rv = 0x5fd8450, svu_array = 0x5fd8450, svu_hash = 0x5fd8450,
svu_gp = 0x5fd8450, svu_fp = 0x5fd8450}}

sv_flags in hex is = 40044407 -- includes svpad_name and svpad_our
flags.

SVt_PVMG, SVf_POK, SVp_POK, SVpad_OUR, SVpad_NAME

And the call is coming from S_pad_findlex. Was pad.c​:1035 the line
number that got cut off? (That’s the only instance of newSVsv in pad.c.)

But S_pad_find_lex is trying to create a new SV from an existing one
(newSVsv). The existing sv seems to have a corrupt magic pointer, since
the call is coming from here in sv_setsv_flags​:

  case SVt_PVMG​:
  if (SvGMAGICAL(sstr) && (flags & SV_GMAGIC)) {
--> mg_get(sstr);
  if (SvTYPE(sstr) != stype)
  stype = SvTYPE(sstr);
  }

(gdb) print sv->sv_any
$7 = (void *) 0x58ef6a0
(gdb) print (XPVMG *)0x58ef6a0
$8 = (XPVMG *) 0x58ef6a0
(gdb) print *((XPVMG *)0x58ef6a0)
$9 = {xmg_stash = 0x0, xmg_u = {xmg_magic = 0x1d52bd8, xmg_ourstash =
0x1d52bd8}, xpv_cur = 6, xpv_len = 16, xiv_u = {xivu_iv = 0, xivu_uv =
0,
xivu_i32 = 0, xivu_namehek = 0x0}, xnv_u = {xnv_nv =
-nan(0xfffff00009f5a), xgv_stash = 0xffffffff00009f5a, xpad_cop_seq =
{xlow = 40794,
xhigh = 4294967295}, xbm_s = {xbm_previous = 40794, xbm_flags =
255 '\377', xbm_rare = 255 '\377'}}}

sv->sv_any looks good.

So based on xmg_u being a union, I tried to look at xmg_u as
xmg_ourstash

I’ve just learn something new. sv.h has this​:

union _xmgu {
  MAGIC* xmg_magic; /* linked list of magicalness */
  HV* xmg_ourstash; /* Stash for our (when SvPAD_OUR is true) */
};

(gdb) print *((HV *)0x1d52bd8)
$11 = {sv_any = 0x1d57620, sv_refcnt = 3, sv_flags = 570425356, sv_u =
{svu_pv = 0x1d69b40 "", svu_iv = 30841664, svu_uv = 30841664, svu_rv =
0x1d69b40,
svu_array = 0x1d69b40, svu_hash = 0x1d69b40, svu_gp = 0x1d69b40,
svu_fp = 0x1d69b40}}

The code in Perl_mg_get() is walking that link to xmg_magic without
checking the flags first?

mg_get seems to be designed that way. But the calling code checks
SvGMAGICAL first; i.e., SvFLAGS(sv) & 0x00200000.

0x00200000 # SVs_GMG
0x40044407 # SvFLAGS(sv)

Maybe this is a compiler bug. I really can’t tell.

Are you in a position to recompile perl? You could try SvGMAGICAL(sstr)
? 1 : 0 or SvGMAGICAL(sstr) != 0 or !!SvGMAGICAL(sstr).

Or what happens if you reinstall perl unmodified?

(When it comes to this compilation stuff, I’m just waving my hands
around. I really don’t understand it that much.)

Also​: Is it possible for you to run the CGI script yourself from the
command line? Getting it down to something reproducible is usually
extremely helpful, as you can imagine.

--

Father Chrysostomos

@p5pRT
Copy link
Author

p5pRT commented Jan 7, 2012

From erik@thekrib.com

Update of information on this bug.

I have spent the last two evenings trying to make progress. It is very
frustrating.

I was able to repro the problems on a virtual machine with an all-new
installation (clean) of the OS {fedora 16, 64-bit}. I also confirmed the
problem does NOT happen with the previous release of the OS {fedora 15,
64-bit, with updates} -- which is using perl 5.12 -- installed on another
VM.

On Wed, 4 Jan 2012, Father Chrysostomos via RT wrote​:

And the call is coming from S_pad_findlex. Was pad.c​:1035 the line
number that got cut off? (That’s the only instance of newSVsv in pad.c.)

Yes, line 1035 definitely.

Are you in a position to recompile perl?

Yes, I have broken through the barrier of DBD​::mysql not building (patched
it here https://rt.cpan.org/Public/Bug/Display.html?id=68112 and now
everything builds).

I built it with -DDEBUGGING turned on, and very interestingly, it asserts
on first invocation of the fastcgi script via httpd. (i.e., this is even
BEFORE I attempt to send it the command that page-faults the script.)

perl​: mg.c​:227​: Perl_mg_get​: Assertion `!(((_svmagic)->sv_flags & (0x40000000|0x00040000)) == (0x40000000|0x00040000))' failed.

I beleive this corresponds to the second assert in this macro​:

# define SvMAGIC(sv) \
  (*({ const SV *const _svmagic = (const SV *)(sv); \
  assert(SvTYPE(_svmagic) >= SVt_PVMG); \
  if(SvTYPE(_svmagic) == SVt_PVMG) \
  assert(!SvPAD_OUR(_svmagic)); \ <----- This one
  &(((XPVMG*) MUTABLE_PTR(SvANY(_svmagic)))->xmg_u.xmg_magic); \
  }))

Is this opposite case of the one that page-faults the machine?

Unfortunately, because of that assert, I cannot attempt to run the command
that segfaults the machine.

I ran this with perl tracing on, and here are the last few lines before
the assert​:

[Thu Jan 05 20​:31​:05 2012] [warn] [client :​:1] mod_fcgid​: stderr​: >> /opt/perl/lib/5.14.2/Exporter.pm​:45​: my $args = @​_ or @​_ = @​$exports;
[Thu Jan 05 20​:31​:05 2012] [warn] [client :​:1] mod_fcgid​: stderr​: >> /opt/perl/lib/5.14.2/Exporter.pm​:47​: local $_;
[Thu Jan 05 20​:31​:05 2012] [warn] [client :​:1] mod_fcgid​: stderr​: >> /opt/perl/lib/5.14.2/Exporter.pm​:48​: if ($args and not %$export_cache) {
[Thu Jan 05 20​:31​:05 2012] [warn] [client :​:1] mod_fcgid​: stderr​: >> /opt/perl/lib/5.14.2/Exporter.pm​:52​: my $heavy;
[Thu Jan 05 20​:31​:05 2012] [warn] [client :​:1] mod_fcgid​: stderr​: >> /opt/perl/lib/5.14.2/Exporter.pm​:55​: if ($args or $fail) {
[Thu Jan 05 20​:31​:05 2012] [warn] [client :​:1] mod_fcgid​: stderr​: >> /opt/perl/lib/5.14.2/Exporter.pm​:58​: foreach (@​_);
[Thu Jan 05 20​:31​:05 2012] [warn] [client :​:1] mod_fcgid​: stderr​: >> /opt/perl/lib/5.14.2/Exporter.pm​:63​: return export $pkg, $callpkg, ($args ? @​_ : ()) if $heavy;

Full Devel​::trace at http​://test.thekrib.com/trace-107480-debug.txt.gz

You could try SvGMAGICAL(sstr)
? 1 : 0 or SvGMAGICAL(sstr) != 0 or !!SvGMAGICAL(sstr).

Tried these, to no avail. It still gets through. I don't think this is a
compiler bug. I think the SvGMAGICAL flag *is* set when it enters that
function, and somewhere in the function called on line 221​:

  save_magic(mgs_ix, sv);

the flag value is reset along with who-knows-what.

Also​: Is it possible for you to run the CGI script yourself from the
command line? Getting it down to something reproducible is usually
extremely helpful, as you can imagine.

Not possible, due to its interaction, but I can use gdb to attach to the
process while it's still behaving, and then crash it into the debugger
rather than dumping a core. I will see if I can add some breakpoints
higher up and catch it in the act of processing the bogus sv.

I am at a disadvantage here because I'm not that familiar with even the
perl language. I can use my C skills to tell what's happening, but can't
understand WHY. :)

Thanks for any insight.

  - Erik

--
Erik Olson
Sent from my spiffy new Linux box

@p5pRT
Copy link
Author

p5pRT commented Jan 8, 2012

From @cpansprout

On Sat Jan 07 04​:20​:22 2012, erik@​thekrib.com wrote​:

Update of information on this bug.

I built it with -DDEBUGGING turned on, and very interestingly, it
asserts
on first invocation of the fastcgi script via httpd. (i.e., this is
even
BEFORE I attempt to send it the command that page-faults the script.)

perl​: mg.c​:227​: Perl_mg_get​: Assertion `!(((_svmagic)->sv_flags &
(0x40000000|0x00040000)) == (0x40000000|0x00040000))' failed.

I beleive this corresponds to the second assert in this macro​:

# define SvMAGIC(sv)
\
(*({ const SV *const _svmagic = (const SV *)(sv);
\
assert(SvTYPE(_svmagic) >= SVt_PVMG);
\
if(SvTYPE(_svmagic) == SVt_PVMG)
\
assert(!SvPAD_OUR(_svmagic));
\ <----- This one
&(((XPVMG*) MUTABLE_PTR(SvANY(_svmagic)))-

xmg_u.xmg_magic); \
}))

Is this opposite case of the one that page-faults the machine?

It sounds like exactly the same problem to me.

Unfortunately, because of that assert, I cannot attempt to run the
command
that segfaults the machine.

I ran this with perl tracing on, and here are the last few lines
before
the assert​:

[Thu Jan 05 20​:31​:05 2012] [warn] [client :​:1] mod_fcgid​: stderr​: >>
/opt/perl/lib/5.14.2/Exporter.pm​:45​: my $args = @​_ or @​_ =
@​$exports;
[Thu Jan 05 20​:31​:05 2012] [warn] [client :​:1] mod_fcgid​: stderr​: >>
/opt/perl/lib/5.14.2/Exporter.pm​:47​: local $_;
[Thu Jan 05 20​:31​:05 2012] [warn] [client :​:1] mod_fcgid​: stderr​: >>
/opt/perl/lib/5.14.2/Exporter.pm​:48​: if ($args and not
%$export_cache) {
[Thu Jan 05 20​:31​:05 2012] [warn] [client :​:1] mod_fcgid​: stderr​: >>
/opt/perl/lib/5.14.2/Exporter.pm​:52​: my $heavy;
[Thu Jan 05 20​:31​:05 2012] [warn] [client :​:1] mod_fcgid​: stderr​: >>
/opt/perl/lib/5.14.2/Exporter.pm​:55​: if ($args or $fail) {
[Thu Jan 05 20​:31​:05 2012] [warn] [client :​:1] mod_fcgid​: stderr​: >>
/opt/perl/lib/5.14.2/Exporter.pm​:58​: foreach (@​_);
[Thu Jan 05 20​:31​:05 2012] [warn] [client :​:1] mod_fcgid​: stderr​: >>
/opt/perl/lib/5.14.2/Exporter.pm​:63​: return export $pkg, $callpkg,
($args ? @​_ : ()) if $heavy;

Full Devel​::trace at http​://test.thekrib.com/trace-107480-debug.txt.gz

Due to local firewall settings, I cannot access that URL. Could you
e-mail it to sprout at cpan dot org? (Don’t worry about size limits.)

I am at a disadvantage here because I'm not that familiar with even
the
perl language. I can use my C skills to tell what's happening, but
can't
understand WHY. :)

I’m in the opposite position. I’m a Perl and JavaScript programmer who
learnt C by hacking on the perl internals. I’m still learning it.

--

Father Chrysostomos

@p5pRT
Copy link
Author

p5pRT commented Jan 9, 2012

From @iabyn

On Fri, Jan 06, 2012 at 10​:33​:48PM -0800, Erik Olson wrote​:

Tried these, to no avail. It still gets through. I don't think
this is a compiler bug. I think the SvGMAGICAL flag *is* set when
it enters that function, and somewhere in the function called on
line 221​:

save\_magic\(mgs\_ix\, sv\);

the flag value is reset along with who-knows-what.

Yes, this is normal behaviour. I think the problem is that an SV in the
pad that holds the name of a lexical variable is expected never to have
magic attached to it, which is why the xmg_magic and xmg_ourstash fields
are in fact a union. So something naughty somewhere is adding magic
to a name SV.

The diff below to 5.14.2 adds an assertion that should catch that
happening. Can you apply it and retest? Thanks.

Inline Patch
--- sv.h.orig	2012-01-08 23:43:14.352614694 +0000
+++ sv.h	2012-01-08 23:52:00.791663213 +0000
@@ -1214,6 +1214,8 @@
                 ((sv)->sv_u.svu_rv = (val)); } STMT_END
 #define SvMAGIC_set(sv, val) \
         STMT_START { assert(SvTYPE(sv) >= SVt_PVMG); \
+	    	     assert(!(SvFLAGS(sv) & SVpad_NAME) || \
+			(SvTYPE(sv) != SVt_PVNV && SvTYPE(sv) != SVt_PVMG)); \
                 (((XPVMG*)SvANY(sv))->xmg_u.xmg_magic = (val)); } STMT_END
 #define SvSTASH_set(sv, val) \
         STMT_START { assert(SvTYPE(sv) >= SVt_PVMG); \


-- 

"I do not resent criticism, even when, for the sake of emphasis,
it parts for the time with reality".
  -- Winston Churchill, House of Commons, 22nd Jan 1941.

@p5pRT
Copy link
Author

p5pRT commented Jan 10, 2012

From @cpansprout

On Sun Jan 08 14​:14​:19 2012, sprout wrote​:

On Sat Jan 07 04​:20​:22 2012, erik@​thekrib.com wrote​:

Update of information on this bug.

I built it with -DDEBUGGING turned on, and very interestingly, it
asserts
on first invocation of the fastcgi script via httpd. (i.e., this is
even
BEFORE I attempt to send it the command that page-faults the script.)

perl​: mg.c​:227​: Perl_mg_get​: Assertion `!(((_svmagic)->sv_flags &
(0x40000000|0x00040000)) == (0x40000000|0x00040000))' failed.

Unfortunately, because of that assert, I cannot attempt to run the
command
that segfaults the machine.

Can you also provide a full gdb backtrace from that assertion?

And also, back to my earlier question​: Since the problem begins (i.e.,
something goes screwy) even before you sent the script the fatal
command, is it possible to run it on the command line (with the
DEBUGGING build), and trace what’s happening to the SV in question, and
where?

I ran this with perl tracing on, and here are the last few lines
before
the assert​:

[Thu Jan 05 20​:31​:05 2012] [warn] [client :​:1] mod_fcgid​: stderr​: >>
/opt/perl/lib/5.14.2/Exporter.pm​:45​: my $args = @​_ or @​_ =
@​$exports;
[Thu Jan 05 20​:31​:05 2012] [warn] [client :​:1] mod_fcgid​: stderr​: >>
/opt/perl/lib/5.14.2/Exporter.pm​:47​: local $_;
[Thu Jan 05 20​:31​:05 2012] [warn] [client :​:1] mod_fcgid​: stderr​: >>
/opt/perl/lib/5.14.2/Exporter.pm​:48​: if ($args and not
%$export_cache) {
[Thu Jan 05 20​:31​:05 2012] [warn] [client :​:1] mod_fcgid​: stderr​: >>
/opt/perl/lib/5.14.2/Exporter.pm​:52​: my $heavy;
[Thu Jan 05 20​:31​:05 2012] [warn] [client :​:1] mod_fcgid​: stderr​: >>
/opt/perl/lib/5.14.2/Exporter.pm​:55​: if ($args or $fail) {
[Thu Jan 05 20​:31​:05 2012] [warn] [client :​:1] mod_fcgid​: stderr​: >>
/opt/perl/lib/5.14.2/Exporter.pm​:58​: foreach (@​_);
[Thu Jan 05 20​:31​:05 2012] [warn] [client :​:1] mod_fcgid​: stderr​: >>
/opt/perl/lib/5.14.2/Exporter.pm​:63​: return export $pkg, $callpkg,
($args ? @​_ : ()) if $heavy;

Full Devel​::trace at http​://test.thekrib.com/trace-107480-debug.txt.gz

Due to local firewall settings, I cannot access that URL. Could you
e-mail it to sprout at cpan dot org? (Don’t worry about size limits.)

I’ve had a look at it, but I really don’t know what to look for. I wish
I could be of more help.

I am at a disadvantage here because I'm not that familiar with even
the
perl language. I can use my C skills to tell what's happening, but
can't
understand WHY. :)

I’m in the opposite position. I’m a Perl and JavaScript programmer who
learnt C by hacking on the perl internals. I’m still learning it.

--

Father Chrysostomos

@p5pRT
Copy link
Author

p5pRT commented Jan 10, 2012

From erik@thekrib.com

gzipped perl trace rejected by mailing list, will send separately if you
want. Core dump backtrace hopefully small enough.

---------- Forwarded message ----------
From​: Erik Olson <erik@​thekrib.com>
To​: Dave Mitchell <davem@​iabyn.com>
Cc​: Father Chrysostomos via RT <perlbug-followup@​perl.org>
Date​: Mon, 9 Jan 2012 22​:09​:04
Subject​: Re​: [perl #107480] segmentation fault in mg.c on Fedora 16-x64

On Mon, 9 Jan 2012, Dave Mitchell wrote​:

The diff below to 5.14.2 adds an assertion that should catch that
happening. Can you apply it and retest? Thanks.

--- sv.h.orig 2012-01-08 23​:43​:14.352614694 +0000
+++ sv.h 2012-01-08 23​:52​:00.791663213 +0000
@​@​ -1214,6 +1214,8 @​@​
((sv)->sv_u.svu_rv = (val)); } STMT_END
#define SvMAGIC_set(sv, val) \
STMT_START { assert(SvTYPE(sv) >= SVt_PVMG); \
+ assert(!(SvFLAGS(sv) & SVpad_NAME) || \
+ (SvTYPE(sv) != SVt_PVNV && SvTYPE(sv) != SVt_PVMG)); \
(((XPVMG*)SvANY(sv))->xmg_u.xmg_magic = (val)); } STMT_END
#define SvSTASH_set(sv, val) \
STMT_START { assert(SvTYPE(sv) >= SVt_PVMG); \

Yes, I was able to get it to assert on this as I fired up the cgi script for
the first time, mg.c​:589

  SvMAGIC_set(sv, moremagic);

Like the previous assert alluded to on mg.c​:227, this happens before I even run
the offending command that crashes the system.

Full bt of core dump enclosed.
Also full Devel​::Trace of the perl statements enclosed (though I wonder if the
last statements actually get logged when it chokes...).

I can keep running tests like this, as much as it takes.

I have worked around the problem locally by recompiling perl 5.12.x, so time
constraint for me is lifted. But I don't think anyone on the sympa team is
investigating this.

  - Erik

--
Erik Olson
Sent from my spiffy new Linux box

@p5pRT
Copy link
Author

p5pRT commented Jan 10, 2012

From erik@thekrib.com

#0 0x00000032ec036285 in __GI_raise (sig=6) at ../nptl/sysdeps/unix/sysv/linux/raise.c​:64
  resultvar = 0
  pid = <optimized out>
  selftid = 6699
#1 0x00000032ec037b9b in __GI_abort () at abort.c​:91
  save_stage = 2
  act = {__sigaction_handler = {sa_handler = 0x60c3a0, sa_sigaction = 0x60c3a0}, sa_mask = {__val = {218709306491, 1,
  9123232, 140736100807040, 218708229538, 6341536, 206158430232, 140736100807056, 140736100806832, 7302446,
  206158430256, 85296848, 218711652096, 218709311584, 4404837271705380472, 140736100814708}},
  sa_flags = -334033822, sa_restorer = 0x61ba18}
  sigs = {__val = {32, 0 <repeats 15 times>}}
#2 0x00000032ec02ee9e in __assert_fail_base (fmt=<optimized out>,
  assertion=0x60c3a0 "!((sv)->sv_flags & 0x40000000) || (((svtype)((sv)->sv_flags & 0xff)) != SVt_PVNV && ((svtype)((sv)->sv_flags & 0xff)) != SVt_PVMG)", file=0x61ba18 "mg.c", line=<optimized out>, function=<optimized out>) at assert.c​:94
  str = 0x51586d0 "X\367​:\354\062"
  total = 4096
#3 0x00000032ec02ef42 in __GI___assert_fail (
  assertion=0x60c3a0 "!((sv)->sv_flags & 0x40000000) || (((svtype)((sv)->sv_flags & 0xff)) != SVt_PVNV && ((svtype)((sv)->sv_flags & 0xff)) != SVt_PVMG)", file=0x61ba18 "mg.c", line=589, function=0x623241 "Perl_mg_free") at assert.c​:103
No locals.
#4 0x00000000004b638a in Perl_mg_free (sv=0x50a9730) at mg.c​:589
  mg = <optimized out>
  moremagic = 0x0
  __PRETTY_FUNCTION__ = "Perl_mg_free"
#5 0x00000000004f335d in Perl_sv_clear (orig_sv=0x50a9730) at sv.c​:6085
  stash = <optimized out>
  type = 7
  sv_type_details = 0x6
  iter_sv = <optimized out>
  next_sv = 0x0
  sv = <optimized out>
  __PRETTY_FUNCTION__ = "Perl_sv_clear"
#6 0x00000000004f43c1 in Perl_sv_free2 (sv=0x50a9730) at sv.c​:6474
No locals.
#7 0x0000000000548b46 in Perl_leave_scope (base=327) at scope.c​:948
  _sv = <optimized out>
  uv = <optimized out>
  type = <optimized out>
  sv = <optimized out>
  value = <optimized out>
  gv = <optimized out>
  av = <optimized out>
  hv = <optimized out>
  ptr = <optimized out>
  str = <optimized out>
  i = <optimized out>
  was = 1 '\001'
  __PRETTY_FUNCTION__ = "Perl_leave_scope"
#8 0x000000000047035b in S_sublex_done () at toke.c​:2537
No locals.
#9 S_sublex_done () at toke.c​:2475
No locals.
#10 0x0000000000460264 in Perl_yylex () at toke.c​:4583
  s = <optimized out>
  d = <optimized out>
  len = <optimized out>
  bof = 0 '\000'
  fake_eof = 0
  orig_keyword = 0
  gv = 0x0
  gvp = 0x0
  __PRETTY_FUNCTION__ = "Perl_yylex"
#11 0x0000000000471c43 in Perl_yyparse (gramtype=<optimized out>) at perly.c​:434
  yystate = 245
  yyn = 2509
  yyresult = <optimized out>
  yytoken = 10
  parser = 0x510f6f0
  ps = 0x50519f0
  yyval = <optimized out>
#12 0x0000000000551f9b in S_doeval (gimme=2, startop=0x0, outside=<optimized out>, seq=<optimized out>) at pp_ctl.c​:3334
  sp = 0x44df050
  saveop = 0x2532860
  in_require = <optimized out>
  yystatus = <optimized out>
  __PRETTY_FUNCTION__ = "S_doeval"
#13 0x000000000056591d in Perl_pp_require () at pp_ctl.c​:3906
  sp = 0x44df050
  cx = <optimized out>
  sv = <optimized out>
  name = <optimized out>
  len = 19
  unixname = <optimized out>
  unixlen = 19
  tryname = 0x50214e0 "/opt/perl-debug/lib/site_perl/5.14.2/x86_64-linux/Template/Context.pm"
  namesv = 0x509a050
  gimme = 2
  filter_has_file = <optimized out>
  tryrsfp = 0x1531b40
  filter_cache = <optimized out>
  filter_state = <optimized out>
  filter_sub = <optimized out>
  hook_sv = <optimized out>
  encoding = 0x0
  op = <optimized out>
  __PRETTY_FUNCTION__ = "Perl_pp_require"
#14 0x00000000004aa3cb in Perl_runops_debug () at dump.c​:2266
No locals.
#15 0x0000000000441c10 in S_run_body (oldscope=1) at perl.c​:2350
No locals.
#16 perl_run (my_perl=<optimized out>) at perl.c​:2268
  oldscope = 1
  ret = <optimized out>
  cur_env = {je_prev = 0x8b34c0, je_buf = {{__jmpbuf = {0, -8744298758903777483, 4315052, 140736100809968, 0, 0,
  8744116963770808117, -8744299343590934731}, __mask_was_saved = 0, __saved_mask = {__val = {6, 6,
  140736100809968, 5187071, 6637696, 22194832, 0, 0, 6, 22174752, 0, 4315052, 140736100809968, 0, 0,
  5189425}}}}, je_ret = 0, je_mustcatch = 0 '\000'}
  __PRETTY_FUNCTION__ = "perl_run"
#17 0x000000000041d79d in main (argc=3, argv=0x7fffad4bbcf8, env=0x7fffad4bbd18) at perlmain.c​:120
  exitstatus = <optimized out>
  i = <optimized out>

@p5pRT
Copy link
Author

p5pRT commented Jan 10, 2012

From erik@thekrib.com

On Mon, 9 Jan 2012, Father Chrysostomos via RT wrote​:

Can you also provide a full gdb backtrace from that assertion?

Sent a backtrace from the new assertion. Let's see if that helps.

And also, back to my earlier question​: Since the problem begins (i.e.,
something goes screwy) even before you sent the script the fatal
command, is it possible to run it on the command line (with the
DEBUGGING build), and trace what’s happening to the SV in question, and
where?

Nope, when I run it straight from the commandline, it exits out "normally"
without hitting the assert, most likely because it knows it's not being
launched by apache's fastcgi module.

--
Erik Olson
Sent from my spiffy new Linux box

@p5pRT
Copy link
Author

p5pRT commented Jan 11, 2012

From @iabyn

On Mon, Jan 09, 2012 at 10​:09​:04PM -0800, Erik Olson wrote​:

On Mon, 9 Jan 2012, Dave Mitchell wrote​:

The diff below to 5.14.2 adds an assertion that should catch that
happening. Can you apply it and retest? Thanks.

--- sv.h.orig 2012-01-08 23​:43​:14.352614694 +0000
+++ sv.h 2012-01-08 23​:52​:00.791663213 +0000
@​@​ -1214,6 +1214,8 @​@​
((sv)->sv_u.svu_rv = (val)); } STMT_END
#define SvMAGIC_set(sv, val) \
STMT_START { assert(SvTYPE(sv) >= SVt_PVMG); \
+ assert(!(SvFLAGS(sv) & SVpad_NAME) || \
+ (SvTYPE(sv) != SVt_PVNV && SvTYPE(sv) != SVt_PVMG)); \
(((XPVMG*)SvANY(sv))->xmg_u.xmg_magic = (val)); } STMT_END
#define SvSTASH_set(sv, val) \
STMT_START { assert(SvTYPE(sv) >= SVt_PVMG); \

Yes, I was able to get it to assert on this as I fired up the cgi
script for the first time, mg.c​:589

    SvMAGIC\_set\(sv\, moremagic\);

Like the previous assert alluded to on mg.c​:227, this happens before
I even run the offending command that crashes the system.

Full bt of core dump enclosed.
Also full Devel​::Trace of the perl statements enclosed (though I
wonder if the last statements actually get logged when it
chokes...).

The assertion failing there indicates that the assertion code I gave you
was wrong :-( Could you try the revised one below instead, thanks.
Also, the output of the trace indicated that the fastcgi environment was
running under -t, so it might be that you'll be able to reproduce the
failure from the command line by running with perl -t ...

Inline Patch
--- sv.h.orig	2012-01-08 23:43:14.352614694 +0000
+++ sv.h	2012-01-11 17:41:01.957571210 +0000
@@ -1214,6 +1214,8 @@
                 ((sv)->sv_u.svu_rv = (val)); } STMT_END
 #define SvMAGIC_set(sv, val) \
         STMT_START { assert(SvTYPE(sv) >= SVt_PVMG); \
+	    	     assert(!SvPAD_OUR(sv) || \
+			(SvTYPE(sv) != SVt_PVNV && SvTYPE(sv) != SVt_PVMG)); \
                 (((XPVMG*)SvANY(sv))->xmg_u.xmg_magic = (val)); } STMT_END
 #define SvSTASH_set(sv, val) \
         STMT_START { assert(SvTYPE(sv) >= SVt_PVMG); \

-- 

No matter how many dust sheets you use, you will get paint on the carpet.

@p5pRT
Copy link
Author

p5pRT commented Jan 11, 2012

From @cpansprout

On Wed Jan 11 10​:02​:29 2012, davem wrote​:

On Mon, Jan 09, 2012 at 10​:09​:04PM -0800, Erik Olson wrote​:

On Mon, 9 Jan 2012, Dave Mitchell wrote​:

The diff below to 5.14.2 adds an assertion that should catch that
happening. Can you apply it and retest? Thanks.

--- sv.h.orig 2012-01-08 23​:43​:14.352614694 +0000
+++ sv.h 2012-01-08 23​:52​:00.791663213 +0000
@​@​ -1214,6 +1214,8 @​@​
((sv)->sv_u.svu_rv = (val)); } STMT_END
#define SvMAGIC_set(sv, val) \
STMT_START { assert(SvTYPE(sv) >= SVt_PVMG); \
+ assert(!(SvFLAGS(sv) & SVpad_NAME) || \
+ (SvTYPE(sv) != SVt_PVNV && SvTYPE(sv) != SVt_PVMG)); \
(((XPVMG*)SvANY(sv))->xmg_u.xmg_magic = (val)); }
STMT_END
#define SvSTASH_set(sv, val) \
STMT_START { assert(SvTYPE(sv) >= SVt_PVMG); \

Yes, I was able to get it to assert on this as I fired up the cgi
script for the first time, mg.c​:589

    SvMAGIC\_set\(sv\, moremagic\);

Like the previous assert alluded to on mg.c​:227, this happens before
I even run the offending command that crashes the system.

Full bt of core dump enclosed.
Also full Devel​::Trace of the perl statements enclosed (though I
wonder if the last statements actually get logged when it
chokes...).

The assertion failing there indicates that the assertion code I gave
you
was wrong :-( Could you try the revised one below instead, thanks.
Also, the output of the trace indicated that the fastcgi environment
was
running under -t, so it might be that you'll be able to reproduce the
failure from the command line by running with perl -t ...

If the script won’t run without a CGI environment, it might be
sufficient to set REQUEST_METHOD​:

$ REQUEST_METHOD=GET perl5.14.2 -t wwsympa.fcgi

--- sv.h.orig 2012-01-08 23​:43​:14.352614694 +0000
+++ sv.h 2012-01-11 17​:41​:01.957571210 +0000
@​@​ -1214,6 +1214,8 @​@​
((sv)->sv_u.svu_rv = (val)); } STMT_END
#define SvMAGIC_set(sv, val) \
STMT_START { assert(SvTYPE(sv) >= SVt_PVMG); \
+ assert(!SvPAD_OUR(sv) || \
+ (SvTYPE(sv) != SVt_PVNV && SvTYPE(sv) != SVt_PVMG)); \
(((XPVMG*)SvANY(sv))->xmg_u.xmg_magic = (val)); }
STMT_END
#define SvSTASH_set(sv, val) \
STMT_START { assert(SvTYPE(sv) >= SVt_PVMG); \

--

Father Chrysostomos

@p5pRT
Copy link
Author

p5pRT commented Jan 12, 2012

From erik@thekrib.com

On Wed, 11 Jan 2012, Dave Mitchell wrote​:

The assertion failing there indicates that the assertion code I gave you
was wrong :-( Could you try the revised one below instead, thanks.
Also, the output of the trace indicated that the fastcgi environment was
running under -t, so it might be that you'll be able to reproduce the
failure from the command line by running with perl -t ...

Indeed, this DOES now allow me to run it on the commandline -- thanks!

--- sv.h.orig 2012-01-08 23​:43​:14.352614694 +0000
+++ sv.h 2012-01-11 17​:41​:01.957571210 +0000
@​@​ -1214,6 +1214,8 @​@​
((sv)->sv_u.svu_rv = (val)); } STMT_END
#define SvMAGIC_set(sv, val) \
STMT_START { assert(SvTYPE(sv) >= SVt_PVMG); \
+ assert(!SvPAD_OUR(sv) || \
+ (SvTYPE(sv) != SVt_PVNV && SvTYPE(sv) != SVt_PVMG)); \
(((XPVMG*)SvANY(sv))->xmg_u.xmg_magic = (val)); } STMT_END
#define SvSTASH_set(sv, val) \
STMT_START { assert(SvTYPE(sv) >= SVt_PVMG); \

Unfortunately, with this new assert added, I'm back to the "original"
assert I was getting on first invocation of debug perl​: Perl_mg_get, mg.c​:227

Anything I can dig up here?

Oh, full backtrace​:

(gdb) bt
#0 0x00000032ec036285 in __GI_raise (sig=6) at ../nptl/sysdeps/unix/sysv/linux/raise.c​:64
#1 0x00000032ec037b9b in __GI_abort () at abort.c​:91
#2 0x00000032ec02ee9e in __assert_fail_base (fmt=<optimized out>, assertion=0x5ee8f0 "!(((_svmagic)->sv_flags & (0x40000000|0x00040000)) == (0x40000000|0x00040000))", file=0x61ba78 "mg.c", line=<optimized out>, function=<optimized out>) at assert.c​:94
#3 0x00000032ec02ef42 in __GI___assert_fail ( assertion=0x5ee8f0 "!(((_svmagic)->sv_flags & (0x40000000|0x00040000)) == (0x40000000|0x00040000))", file=0x61ba78 "mg.c", line=227, function=0x623190 "Perl_mg_get") at assert.c​:103
#4 0x00000000004b5748 in Perl_mg_get (sv=0x4483890) at mg.c​:227
#5 0x00000000004ec98a in Perl_sv_setsv_flags (dstr=0x4483d40, sstr=0x4483890, flags=18) at sv.c​:4097
#6 0x00000000004f0e12 in Perl_newSVsv (old=<optimized out>) at sv.c​:8733
#7 0x0000000000475103 in S_pad_findlex (name=<optimized out>, cv=<optimized out>, seq=<optimized out>, Perl_warn=1, out_capture=0x0, out_name_sv=0x7fffffffdb40, out_flags=0x7fffffffdb4c) at pad.c​:1035
#8 0x00000000004764cb in Perl_pad_findmy (name=0x44e8530 "$PLUGIN_FILTER", len=14, flags=<optimized out>) at pad.c​:744
#9 0x0000000000460538 in S_pending_ident () at toke.c​:8352
#10 Perl_yylex () at toke.c​:4316
#11 0x0000000000471c43 in Perl_yyparse (gramtype=<optimized out>) at perly.c​:434
#12 0x0000000000551fab in S_doeval (gimme=2, startop=0x0, outside=<optimized out>, seq=<optimized out>) at pp_ctl.c​:3334
#13 0x000000000056592d in Perl_pp_require () at pp_ctl.c​:3906
#14 0x00000000004aa39b in Perl_runops_debug () at dump.c​:2266
#15 0x0000000000441c10 in S_run_body (oldscope=1) at perl.c​:2350
#16 perl_run (my_perl=<optimized out>) at perl.c​:2268
#17 0x000000000041d79d in main (argc=4, argv=0x7fffffffe558, env=0x7fffffffe580) at perlmain.c​:120

(gdb) bt full
#0 0x00000032ec036285 in __GI_raise (sig=6) at
../nptl/sysdeps/unix/sysv/linux/raise.c​:64
  resultvar = 0
  pid = <optimized out>
  selftid = 2097
#1 0x00000032ec037b9b in __GI_abort () at abort.c​:91
  save_stage = 2
  act = {__sigaction_handler = {sa_handler = 0x5ee8f0, sa_sigaction
= 0x5ee8f0}, sa_mask = {__val = {218709306491, 7,
  0, 140737488345328, 218708229538, 6220016, 206158430232,
140737488345344, 140737488345120, 7302446,
  206158430256, 72482048, 0, 3760558673587371056, 1,
140737488349081}}, sa_flags = -331680000,
  sa_restorer = 0x10450}
  sigs = {__val = {32, 0 <repeats 15 times>}}
#2 0x00000032ec02ee9e in __assert_fail_base (fmt=<optimized out>,
  assertion=0x5ee8f0 "!(((_svmagic)->sv_flags & (0x40000000|0x00040000))
== (0x40000000|0x00040000))",
  file=0x61ba78 "mg.c", line=<optimized out>, function=<optimized out>)
at assert.c​:94
  str = 0x451fd00 "perl​: mg.c​:227​: Perl_mg_get​: Assertion
`!(((_svmagic)->sv_flags & (0x40000000|0x00040000)) ==
(0x40000000|0x00040000))' failed.\n"
  total = 4096
#3 0x00000032ec02ef42 in __GI___assert_fail (
  assertion=0x5ee8f0 "!(((_svmagic)->sv_flags & (0x40000000|0x00040000))
== (0x40000000|0x00040000))",
  file=0x61ba78 "mg.c", line=227, function=0x623190 "Perl_mg_get") at
assert.c​:103
No locals.
#4 0x00000000004b5748 in Perl_mg_get (sv=0x4483890) at mg.c​:227
  _svmagic = 0x4483890
  mgs_ix = 2768
  have_new = 0 '\000'
  newmg = <optimized out>
  head = <optimized out>
  cur = <optimized out>
  mg = <optimized out>
  __PRETTY_FUNCTION__ = "Perl_mg_get"
#5 0x00000000004ec98a in Perl_sv_setsv_flags (dstr=0x4483d40,
sstr=0x4483890, flags=18) at sv.c​:4097
  sflags = <optimized out>
  dtype = <optimized out>
  stype = <optimized out>
  __PRETTY_FUNCTION__ = "Perl_sv_setsv_flags"
#6 0x00000000004f0e12 in Perl_newSVsv (old=<optimized out>) at sv.c​:8733
  sv = 0x4483d40
#7 0x0000000000475103 in S_pad_findlex (name=<optimized out>,
cv=<optimized out>, seq=<optimized out>, Perl_warn=1,
  out_capture=0x0, out_name_sv=0x7fffffffdb40, out_flags=0x7fffffffdb4c)
at pad.c​:1035
  new_namesv = <optimized out>
  ocomppad_name = <optimized out>
  ocomppad = <optimized out>
  offset = 36
  new_offset = <optimized out>
  new_capture = 0x0
  new_capturep = 0x7fffffffdae8
  padlist = <optimized out>
  __PRETTY_FUNCTION__ = "S_pad_findlex"
#8 0x00000000004764cb in Perl_pad_findmy (name=0x44e8530
"$PLUGIN_FILTER", len=14, flags=<optimized out>) at pad.c​:744
  out_sv = 0x4483890
  out_flags = 0
  offset = <optimized out>
  name_svp = <optimized out>
  __PRETTY_FUNCTION__ = "Perl_pad_findmy"
#9 0x0000000000460538 in S_pending_ident () at toke.c​:8352
  tmp = 0
  pit = 36 '$'
  tokenbuf_len = 14
  d = <optimized out>
  has_colon = 0x0
#10 Perl_yylex () at toke.c​:4316
  s = <optimized out>
  d = <optimized out>
  len = <optimized out>
  bof = 0 '\000'
  fake_eof = 0
  orig_keyword = 0
  gv = 0x0
  gvp = 0x0
  __PRETTY_FUNCTION__ = "Perl_yylex"
#11 0x0000000000471c43 in Perl_yyparse (gramtype=<optimized out>) at
perly.c​:434
  yystate = 19
  yyn = 667
  yyresult = <optimized out>
  yytoken = 15
  parser = 0x44e83e0
  ps = 0x44fd8e0
  yyval = <optimized out>
#12 0x0000000000551fab in S_doeval (gimme=2, startop=0x0,
outside=<optimized out>, seq=<optimized out>) at pp_ctl.c​:3334
  sp = 0x38756e0
  saveop = 0x18c6920
  in_require = <optimized out>
  yystatus = <optimized out>
  __PRETTY_FUNCTION__ = "S_doeval"
#13 0x000000000056592d in Perl_pp_require () at pp_ctl.c​:3906
  sp = 0x38756e0
  cx = <optimized out>
  sv = <optimized out>
  name = <optimized out>
  len = 19
  unixname = <optimized out>
  unixlen = 19
  tryname = 0x41089c0
"/opt/perl-debug/lib/site_perl/5.14.2/x86_64-linux/Template/Filters.pm"
  namesv = 0x4443ea0
  gimme = 2
  filter_has_file = <optimized out>
  tryrsfp = 0x8c45d0
  filter_cache = <optimized out>
  filter_state = <optimized out>
  filter_sub = <optimized out>
  hook_sv = <optimized out>
  encoding = 0x0
  op = <optimized out>
  __PRETTY_FUNCTION__ = "Perl_pp_require"
#14 0x00000000004aa39b in Perl_runops_debug () at dump.c​:2266
No locals.
#15 0x0000000000441c10 in S_run_body (oldscope=1) at perl.c​:2350
No locals.
#16 perl_run (my_perl=<optimized out>) at perl.c​:2268
  oldscope = 1
  ret = <optimized out>
  cur_env = {je_prev = 0x8b3560, je_buf = {{__jmpbuf = {0,
571751511318026192, 4315052, 140737488348496, 0, 0,
  -571751511159777328, 571750926832195536}, __mask_was_saved
= 0, __saved_mask = {__val = {6, 6,
  140737488348496, 5187039, 6637856, 9161600, 0, 0, 6,
9137184, 0, 4315052, 140737488348496, 0, 0,
  5189393}}}}, je_ret = 0, je_mustcatch = 0 '\000'}
  __PRETTY_FUNCTION__ = "perl_run"
#17 0x000000000041d79d in main (argc=4, argv=0x7fffffffe558,
env=0x7fffffffe580) at perlmain.c​:120
  exitstatus = <optimized out>
  i = <optimized out>

--
Erik Olson
Sent from my spiffy new Linux box

@p5pRT
Copy link
Author

p5pRT commented Jan 13, 2012

From @iabyn

On Wed, Jan 11, 2012 at 04​:18​:57PM -0800, Erik Olson wrote​:

Unfortunately, with this new assert added, I'm back to the
"original" assert I was getting on first invocation of debug perl​:
Perl_mg_get, mg.c​:227

Oh :-(

Indeed, this DOES now allow me to run it on the commandline -- thanks!

In that case, would it be possible to provide a stripped down test script
(with as few external dependencies as possible) that reproduces the issue?

--
"You may not work around any technical limitations in the software"
  -- Windows Vista license

@p5pRT
Copy link
Author

p5pRT commented Jan 13, 2012

From @cpansprout

On Fri Jan 13 04​:05​:38 2012, davem wrote​:

On Wed, Jan 11, 2012 at 04​:18​:57PM -0800, Erik Olson wrote​:

Unfortunately, with this new assert added, I'm back to the
"original" assert I was getting on first invocation of debug perl​:
Perl_mg_get, mg.c​:227

Oh :-(

Indeed, this DOES now allow me to run it on the commandline -- thanks!

In that case, would it be possible to provide a stripped down test script
(with as few external dependencies as possible) that reproduces the issue?

But he doesn’t know Perl. :-(

I have not been able to reproduce this problem myself.

--

Father Chrysostomos

@p5pRT
Copy link
Author

p5pRT commented Jan 13, 2012

From erik@thekrib.com

On Fri, 13 Jan 2012, Father Chrysostomos via RT wrote​:

On Fri Jan 13 04​:05​:38 2012, davem wrote​:

On Wed, Jan 11, 2012 at 04​:18​:57PM -0800, Erik Olson wrote​:

Unfortunately, with this new assert added, I'm back to the
"original" assert I was getting on first invocation of debug perl​:
Perl_mg_get, mg.c​:227

Oh :-(

Indeed, this DOES now allow me to run it on the commandline -- thanks!

In that case, would it be possible to provide a stripped down test script
(with as few external dependencies as possible) that reproduces the issue?

But he doesn’t know Perl. :-(

I have not been able to reproduce this problem myself.

But I do know how to hack. So I will see if using the 10,000-line source
wwwsympa script + the Devel​::trace output leading to the problem, if I can
pare things down a bit. It may take a while...

  - Erik

--
Erik Olson
Sent from my spiffy new Linux box

@p5pRT
Copy link
Author

p5pRT commented Feb 10, 2012

From bouyer@NetBSD.org

Hello,
FYI, I'm seeing the same problem, also with the sympa software, on a
NetBSD 5.1/i386 host running perl 5.14.2. So it looks really like a perl
bug, not something related to the OS or compiler.

Here is what gdb tells me from the core dump​:
Core was generated by `perl'.
Program terminated with signal 11, Segmentation fault.
#0 0xbb734960 in Perl_mg_get ()
  from /usr/pkg/lib/perl5/5.14.0/i386-netbsd-thread-multi/CORE/libperl.so
(gdb) where
#0 0xbb734960 in Perl_mg_get ()
  from /usr/pkg/lib/perl5/5.14.0/i386-netbsd-thread-multi/CORE/libperl.so
#1 0xbb752b84 in Perl_sv_setsv_flags ()
  from /usr/pkg/lib/perl5/5.14.0/i386-netbsd-thread-multi/CORE/libperl.so
#2 0xbb75d388 in Perl_newSVsv ()
  from /usr/pkg/lib/perl5/5.14.0/i386-netbsd-thread-multi/CORE/libperl.so
#3 0xbb708e9c in S_pad_findlex ()
  from /usr/pkg/lib/perl5/5.14.0/i386-netbsd-thread-multi/CORE/libperl.so
#4 0xbb70950a in Perl_pad_findmy ()
  from /usr/pkg/lib/perl5/5.14.0/i386-netbsd-thread-multi/CORE/libperl.so
#5 0xbb6fbe42 in Perl_yylex ()
  from /usr/pkg/lib/perl5/5.14.0/i386-netbsd-thread-multi/CORE/libperl.so
#6 0xbb705517 in Perl_yyparse ()
  from /usr/pkg/lib/perl5/5.14.0/i386-netbsd-thread-multi/CORE/libperl.so
#7 0xbb777c0a in S_doeval ()
  from /usr/pkg/lib/perl5/5.14.0/i386-netbsd-thread-multi/CORE/libperl.so
#8 0xbb779bc8 in Perl_pp_require ()
  from /usr/pkg/lib/perl5/5.14.0/i386-netbsd-thread-multi/CORE/libperl.so
#9 0xbb742a63 in Perl_runops_standard ()
  from /usr/pkg/lib/perl5/5.14.0/i386-netbsd-thread-multi/CORE/libperl.so
#10 0xbb6df7ff in perl_run ()
  from /usr/pkg/lib/perl5/5.14.0/i386-netbsd-thread-multi/CORE/libperl.so
#11 0x08048db8 in main ()

@p5pRT
Copy link
Author

p5pRT commented Feb 10, 2012

From [Unknown Contact. See original ticket]

Hello,
FYI, I'm seeing the same problem, also with the sympa software, on a
NetBSD 5.1/i386 host running perl 5.14.2. So it looks really like a perl
bug, not something related to the OS or compiler.

Here is what gdb tells me from the core dump​:
Core was generated by `perl'.
Program terminated with signal 11, Segmentation fault.
#0 0xbb734960 in Perl_mg_get ()
  from /usr/pkg/lib/perl5/5.14.0/i386-netbsd-thread-multi/CORE/libperl.so
(gdb) where
#0 0xbb734960 in Perl_mg_get ()
  from /usr/pkg/lib/perl5/5.14.0/i386-netbsd-thread-multi/CORE/libperl.so
#1 0xbb752b84 in Perl_sv_setsv_flags ()
  from /usr/pkg/lib/perl5/5.14.0/i386-netbsd-thread-multi/CORE/libperl.so
#2 0xbb75d388 in Perl_newSVsv ()
  from /usr/pkg/lib/perl5/5.14.0/i386-netbsd-thread-multi/CORE/libperl.so
#3 0xbb708e9c in S_pad_findlex ()
  from /usr/pkg/lib/perl5/5.14.0/i386-netbsd-thread-multi/CORE/libperl.so
#4 0xbb70950a in Perl_pad_findmy ()
  from /usr/pkg/lib/perl5/5.14.0/i386-netbsd-thread-multi/CORE/libperl.so
#5 0xbb6fbe42 in Perl_yylex ()
  from /usr/pkg/lib/perl5/5.14.0/i386-netbsd-thread-multi/CORE/libperl.so
#6 0xbb705517 in Perl_yyparse ()
  from /usr/pkg/lib/perl5/5.14.0/i386-netbsd-thread-multi/CORE/libperl.so
#7 0xbb777c0a in S_doeval ()
  from /usr/pkg/lib/perl5/5.14.0/i386-netbsd-thread-multi/CORE/libperl.so
#8 0xbb779bc8 in Perl_pp_require ()
  from /usr/pkg/lib/perl5/5.14.0/i386-netbsd-thread-multi/CORE/libperl.so
#9 0xbb742a63 in Perl_runops_standard ()
  from /usr/pkg/lib/perl5/5.14.0/i386-netbsd-thread-multi/CORE/libperl.so
#10 0xbb6df7ff in perl_run ()
  from /usr/pkg/lib/perl5/5.14.0/i386-netbsd-thread-multi/CORE/libperl.so
#11 0x08048db8 in main ()

@p5pRT
Copy link
Author

p5pRT commented Feb 14, 2012

From @cpansprout

On Fri Feb 10 07​:04​:57 2012, bouyer wrote​:

Hello,
FYI, I'm seeing the same problem, also with the sympa software, on a
NetBSD 5.1/i386 host running perl 5.14.2. So it looks really like a perl
bug, not something related to the OS or compiler.

Are you able to reproduce it from the command line? If so, would you be
able to try reducing the problem (by deleting big chunks of sympa
without eliminating the crash)?

--

Father Chrysostomos

@p5pRT
Copy link
Author

p5pRT commented Feb 14, 2012

From erik@thekrib.com

Different person -- bouyer is not me.

"Real" work has swamped me, so I can't yet devote a chunk of time to
chasing this one yet. I will get back to it eventually...

On Mon, 13 Feb 2012, Father Chrysostomos via RT wrote​:

On Fri Feb 10 07​:04​:57 2012, bouyer wrote​:

Hello,
FYI, I'm seeing the same problem, also with the sympa software, on a
NetBSD 5.1/i386 host running perl 5.14.2. So it looks really like a perl
bug, not something related to the OS or compiler.

Are you able to reproduce it from the command line? If so, would you be
able to try reducing the problem (by deleting big chunks of sympa
without eliminating the crash)?

--
Erik Olson
Sent from my spiffy new Linux box

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

2 participants