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

fork.t fails on Win32 since v5.15.4-465-g676a678 #11927

Closed
p5pRT opened this issue Feb 3, 2012 · 48 comments
Closed

fork.t fails on Win32 since v5.15.4-465-g676a678 #11927

p5pRT opened this issue Feb 3, 2012 · 48 comments

Comments

@p5pRT
Copy link

p5pRT commented Feb 3, 2012

Migrated from rt.perl.org#109718 (status was 'resolved')

Searchable as RT109718$

@p5pRT
Copy link
Author

p5pRT commented Feb 3, 2012

From @tonycoz

Created by @tonycoz

x64 MSVC build, but smokes have been failing too​:

C​:\Users\tony\dev\perl\git\perl\t>.\perl harness -v op/fork.t
op/fork.t ..
ok 1
ok 2
ok 3
ok 4
ok 5
ok 6
ok 7
ok 8
ok 9
ok 10
ok 11
ok 12
ok 13
ok 14
ok 15
PROG​:
if (eval q{$pid = fork}) {
  eval q{ die "parent died" };
  print $@​;
}
else {
  eval q{ die "child died" };
  print $@​;
}
EXPECTED​:
parent died at (eval 2) line 1.
child died at (eval 2) line 1.
GOT​:

# Failed at ./test.pl line 1076
not ok 16
ok 17
ok 18
ok 19
ok 20
ok 21
ok 22
ok 23
ok 24
ok 25
1..25
Failed 1/25 subtests

Test Summary Report
-------------------
op/fork.t (Wstat​: 0 Tests​: 25 Failed​: 1)
  Failed test​: 16
Files=1, Tests=25, 13 wallclock secs ( 0.08 usr + 0.00 sys = 0.08 CPU)
Result​: FAIL

Tested to be broken by 676a678​:

C​:\Users\tony\dev\perl\git\perl\t>git log -n1
WARNING​: terminal is not fully functional
commit 676a678
Author​: Zefram <zefram@​fysh.org>
Date​: Sat Nov 19 16​:00​:32 2011 +0000

  narrower localisation of PL_compcv around eval

  PL_compcv used to be localised around the entire string eval process,
  and hence at runtime of the evaled code would refer to the evaled code
  rather than code of a surrounding compilation. This interfered with the
  ability of string-evaled code in a BEGIN block to affect the surrounding
  compilation, in a similar way to the localisation of $^H and %^H that
  was fixed in f45b078.

  Similar to the fix there, this change moves the localisation of PL_compcv
  inside the new evalcomp scope. A couple of things were relying on
  PL_compcv to find the running code when in a string-eval scope; they now
  need to find it from cx->blk_eval.cv, which was already being populated.

C​:\Users\tony\dev\perl\git\perl\t>.\perl harness -v op/fork.t
op/fork.t ..
ok 1
ok 2
ok 3
ok 4
ok 5
ok 6
ok 7
ok 8
ok 9
ok 10
ok 11
ok 12
ok 13
ok 14
ok 15
(windows complains about a crashed program)
PROG​:
if (eval q{$pid = fork}) {
  eval q{ die "parent died" };
  print $@​;
}
else {
  eval q{ die "child died" };
  print $@​;
}
EXPECTED​:
parent died at (eval 2) line 1.
child died at (eval 2) line 1.
GOT​:

# Failed at ./test.pl line 1033
not ok 16
ok 17
ok 18
ok 19
ok 20
ok 21
ok 22
ok 23
ok 24
ok 25
1..25
Failed 1/25 subtests

Test Summary Report
-------------------
op/fork.t (Wstat​: 0 Tests​: 25 Failed​: 1)
  Failed test​: 16
Files=1, Tests=25, 18 wallclock secs ( 0.02 usr + 0.02 sys = 0.03 CPU)
Result​: FAIL

C​:\Users\tony\dev\perl\git\perl\t>cd ..

C​:\Users\tony\dev\perl\git\perl>git clean -dxf

C​:\Users\tony\dev\perl\git\perl>git checkout "676a678ac0683a727a07d56ed1a6e1fb59
085d5a^"
Previous HEAD position was 676a678... narrower localisation of PL_compcv around
eval
HEAD is now at fde6729... sv.c​: More consistent use of spaces after dots

C​:\Users\tony\dev\perl\git\perl>cd win32

C​:\Users\tony\dev\perl\git\perl\win32>dmake test-prep
(noise removed)
C​:\Users\tony\dev\perl\git\perl\win32>cd ..\t

C​:\Users\tony\dev\perl\git\perl\t>.\perl harness -v op/fork.t
op/fork.t ..
ok 1
ok 2
ok 3
ok 4
ok 5
ok 6
ok 7
ok 8
ok 9
ok 10
ok 11
ok 12
ok 13
ok 14
ok 15
ok 16
ok 17
ok 18
ok 19
ok 20
ok 21
ok 22
ok 23
ok 24
ok 25
1..25
ok
All tests successful.
Files=1, Tests=25, 14 wallclock secs ( 0.02 usr + 0.03 sys = 0.05 CPU)
Result​: PASS

Perl Info

Flags:
    category=core
    severity=medium

Site configuration information for perl 5.15.7:

Configured by tony at Fri Feb  3 19:01:40 2012.

Summary of my perl5 (revision 5 version 15 subversion 7) configuration:
  Derived from: 864fd8d30af274c82a36ddaf90ed55c91f64ebc7
  Platform:
    osname=MSWin32, osvers=6.1, archname=MSWin32-x64-multi-thread
    uname=''
    config_args='undef'
    hint=recommended, useposix=true, d_sigaction=undef
    useithreads=define, usemultiplicity=define
    useperlio=define, d_sfio=undef, uselargefiles=define, usesocks=undef
    use64bitint=define, use64bitall=undef, uselongdouble=undef
    usemymalloc=n, bincompat5005=undef
  Compiler:
    cc='cl', ccflags ='-nologo -GF -W3 -Od -MD -Zi -DDEBUGGING -fp:precise -DWIN32 -D_CONSOLE -DNO_STRICT -DWIN64 -DCONSERVATIVE -D_CRT_SECURE_NO_DEPRECATE -D_CRT_NONSTDC_NO_DEPRECATE  -DPERL_TEXTMODE_SCRIPTS -DPERL_IMPLICIT_CONTEXT -DPERL_IMPLICIT_SYS -DUSE_PERLIO',
    optimize='-Od -MD -Zi -DDEBUGGING -fp:precise',
    cppflags='-DWIN32'
    ccversion='15.00.30729.01', gccversion='', gccosandvers=''
    intsize=4, longsize=4, ptrsize=8, doublesize=8, byteorder=12345678
    d_longlong=undef, longlongsize=8, d_longdbl=define, longdblsize=8
    ivtype='__int64', ivsize=8, nvtype='double', nvsize=8, Off_t='__int64', lseeksize=8
    alignbytes=8, prototype=define
  Linker and Libraries:
    ld='link', ldflags ='-nologo -nodefaultlib -debug  -libpath:"c:\perl-none\lib\CORE"  -machine:AMD64 "/manifestdependency:type='Win32' name='Microsoft.Windows.Common-Controls' version='6.0.0.0' processorArchitecture='*' publicKeyToken='6595b64144ccf1df' language='*'"'
    libpth=\lib
    libs=oldnames.lib kernel32.lib user32.lib gdi32.lib winspool.lib  comdlg32.lib advapi32.lib shell32.lib ole32.lib oleaut32.lib  netapi32.lib uuid.lib ws2_32.lib mpr.lib winmm.lib  version.lib odbc32.lib odbccp32.lib comctl32.lib msvcrt.lib
    perllibs=oldnames.lib kernel32.lib user32.lib gdi32.lib winspool.lib  comdlg32.lib advapi32.lib shell32.lib ole32.lib oleaut32.lib  netapi32.lib uuid.lib ws2_32.lib mpr.lib winmm.lib  version.lib odbc32.lib odbccp32.lib comctl32.lib msvcrt.lib
    libc=msvcrt.lib, so=dll, useshrplib=true, libperl=perl515.lib
    gnulibc_version=''
  Dynamic Linking:
    dlsrc=dl_win32.xs, dlext=dll, d_dlsymun=undef, ccdlflags=' '
    cccdlflags=' ', lddlflags='-dll -nologo -nodefaultlib -debug  -libpath:"c:\perl-none\lib\CORE"  -machine:AMD64 "/manifestdependency:type='Win32' name='Microsoft.Windows.Common-Controls' version='6.0.0.0' processorArchitecture='*' publicKeyToken='6595b64144ccf1df' language='*'"'

Locally applied patches:
    


@INC for perl 5.15.7:
    lib
    C:/Users/tony/dev/perl/git/perl/lib
    .


Environment for perl 5.15.7:
    HOME (unset)
    LANG (unset)
    LANGUAGE (unset)
    LD_LIBRARY_PATH (unset)
    LOGDIR (unset)
    PATH=c:\Program Files (x86)\Microsoft Visual Studio 9.0\VC\Bin\amd64;c:\Program Files (x86)\Microsoft Visual Studio 9.0\VC\vcpackages;C:\Program Files (x86)\Microsoft Visual Studio 9.0\Common7\IDE;C:\Program Files\Microsoft SDKs\Windows\v7.0\Bin\x64;C:\Program Files\Microsoft SDKs\Windows\v7.0\Bin;C:\Windows\Microsoft.NET\Framework64\v3.5;C:\Windows\Microsoft.NET\Framework\v3.5;C:\Windows\Microsoft.NET\Framework64\v2.0.50727;C:\Windows\Microsoft.NET\Framework\v2.0.50727;C:\Program Files\Microsoft SDKs\Windows\v7.0\Setup;C:\Program Files (x86)\NVIDIA Corporation\PhysX\Common;C:\Program Files\Common Files\Microsoft Shared\Windows Live;C:\Program Files (x86)\Common Files\Microsoft Shared\Windows Live;C:\Windows\system32;C:\Windows;C:\Windows\System32\Wbem;C:\Windows\System32\WindowsPowerShell\v1.0\;C:\Program Files\WIDCOMM\Bluetooth Software\;C:\Program Files\WIDCOMM\Bluetooth Software\syswow64;C:\Program Files\Intel\WiFi\bin\;C:\Program Files\Common Files\Intel\WirelessCommon\;C:\Program Files (x86)\Common Files\Roxio Shared\10.0\DLLShared\;C:\Program Files (x86)\Common Files\Roxio Shared\DLLShared\;C:\Program Files (x86)\Microsoft SQL Server\90\Tools\binn\;C:\Program Files\TortoiseSVN\bin;C:\strawberry\c\bin;C:\strawberry\perl\site\bin;C:\strawberry\perl\bin;C:\Program Files (x86)\Windows Live\Shared;c:\apps\git\cmd;c:\Program Files (x86)\Microsoft SQL Server\100\Tools\Binn\;c:\Program Files\Microsoft SQL Server\100\Tools\Binn\;c:\Program Files\Microsoft SQL Server\100\DTS\Binn\
    PERL_BADLANG (unset)
    SHELL (unset)

@p5pRT
Copy link
Author

p5pRT commented Feb 3, 2012

From @tonycoz

A little more information​:

C​:\Users\tony\dev\perl\git\perl>.\perl -Ilib ..\forktest.pl
parent died at (eval 2) line 1.
panic​: top_env, v=3

C​:\Users\tony\dev\perl\git\perl>type ..\forktest.pl
if (eval q{$pid = fork}) {
  eval q{ die "parent died" };
  print $@​;
}
else {
  eval q{ die "child died" };
  print $@​;
}

@p5pRT
Copy link
Author

p5pRT commented Feb 3, 2012

@tonycoz - Status changed from 'new' to 'open'

@p5pRT
Copy link
Author

p5pRT commented Feb 18, 2012

From @cpansprout

Fixed in commit 44c19e2.

--

Father Chrysostomos

@p5pRT
Copy link
Author

p5pRT commented Feb 18, 2012

From [Unknown Contact. See original ticket]

Fixed in commit 44c19e2.

--

Father Chrysostomos

@p5pRT
Copy link
Author

p5pRT commented Feb 18, 2012

@cpansprout - Status changed from 'open' to 'resolved'

@p5pRT
Copy link
Author

p5pRT commented Feb 18, 2012

From zefram@fysh.org

Father Chrysostomos via RT wrote​:

Fixed in commit 44c19e2.

Is it really? I know I fixed *a* bug there, and I found it because I
was looking for a cause for the Win32 fork bug, but Corion reported that
the same test was still failing after 44c19e2.

-zefram

@p5pRT
Copy link
Author

p5pRT commented Feb 19, 2012

From @cpansprout

On Sat Feb 18 14​:52​:55 2012, zefram@​fysh.org wrote​:

Father Chrysostomos via RT wrote​:

Fixed in commit 44c19e2.

Is it really? I know I fixed *a* bug there, and I found it because I
was looking for a cause for the Win32 fork bug, but Corion reported that
the same test was still failing after 44c19e2.

I that case I misunderstood your commit message. I’ll re-open it.

--

Father Chrysostomos

@p5pRT
Copy link
Author

p5pRT commented Feb 19, 2012

@cpansprout - Status changed from 'resolved' to 'open'

@p5pRT
Copy link
Author

p5pRT commented Mar 16, 2012

From @tonycoz

On Fri Feb 03 00​:49​:17 2012, tonyc wrote​:

C​:\Users\tony\dev\perl\git\perl>type ..\forktest.pl
if (eval q{$pid = fork}) {
eval q{ die "parent died" };
print $@​;
}
else {
eval q{ die "child died" };
print $@​;
}

I should have tried this before​:

C​:\Users\tony\dev\perl\git\perl>.\perl -Dl -Ilib ..\forktest.pl
(..\forktest.pl​:0) ENTER scope 2 (savestack=0) at op.c​:6930
(..\forktest.pl​:-1) LEAVE scope 2 (savestack=11) at op.c​:6967
(..\forktest.pl​:-1) savestack​: releasing items 11 -> 0
(..\forktest.pl​:0) ENTER scope 2 (savestack=0) at ..\hv.c​:1569
(..\forktest.pl​:0) LEAVE scope 2 (savestack=2) at ..\hv.c​:1608
(..\forktest.pl​:0) savestack​: releasing items 2 -> 0
(..\forktest.pl​:0) ENTER scope 2 (savestack=0) at ..\hv.c​:1569
(..\forktest.pl​:0) LEAVE scope 2 (savestack=2) at ..\hv.c​:1608
(..\forktest.pl​:0) savestack​: releasing items 2 -> 0
(..\forktest.pl​:0) ENTER scope 2 (savestack=0) at ..\hv.c​:1569
(..\forktest.pl​:0) LEAVE scope 2 (savestack=2) at ..\hv.c​:1608
(..\forktest.pl​:0) savestack​: releasing items 2 -> 0
(..\forktest.pl​:0) ENTER scope 2 (savestack=0) at ..\hv.c​:1569
(..\forktest.pl​:0) LEAVE scope 2 (savestack=2) at ..\hv.c​:1608
(..\forktest.pl​:0) savestack​: releasing items 2 -> 0
(..\forktest.pl​:0) ENTER scope 2 (savestack=2) at ..\perly.c​:363
(..\forktest.pl​:4) savestack​: releasing items 70 -> 54
(..\forktest.pl​:8) savestack​: releasing items 70 -> 54
(..\forktest.pl​:8) savestack​: releasing items 54 -> 38
(..\forktest.pl​:8) savestack​: releasing items 38 -> 22
(..\forktest.pl​:8) ENTER scope 3 (savestack=22) at op.c​:9922
(..\forktest.pl​:7) ENTER scope 4 (savestack=27) at op.c​:9922
(..\forktest.pl​:3) LEAVE scope 4 (savestack=32) at op.c​:10373
(..\forktest.pl​:3) savestack​: releasing items 32 -> 27
(..\forktest.pl​:7) LEAVE scope 3 (savestack=27) at op.c​:10373
(..\forktest.pl​:7) savestack​: releasing items 27 -> 22
(..\forktest.pl​:8) ENTER scope 3 (savestack=22) at op.c​:1474
(..\forktest.pl​:7) LEAVE scope 3 (savestack=25) at op.c​:1479
(..\forktest.pl​:7) savestack​: releasing items 25 -> 22
(..\forktest.pl​:8) LEAVE scope 2 (savestack=22) at ..\perly.c​:724
(..\forktest.pl​:8) savestack​: releasing items 22 -> 2
(..\forktest.pl​:0) LEAVE scope 1 (savestack=2) at perl.c​:2269
(..\forktest.pl​:0) savestack​: releasing items 2 -> 0
(..\forktest.pl​:0) ENTER scope 1 (savestack=0) at perl.c​:2280
(..\forktest.pl​:0) JUMPENV_POP level=1 at perl.c​:1668
(..\forktest.pl​:0) JUMPENV_PUSH level=1 at perl.c​:2312

EXECUTING...

(..\forktest.pl​:0) Entering new RUNOPS level
(..\forktest.pl​:0) ENTER "block" scope 2 (savestack=0) at
..\pp_ctl.c​:2123
(..\forktest.pl​:0) CX 0 PUSH BLOCK (scope 2,2) at ..\pp_ctl.c​:2126
(..\forktest.pl​:1) ENTER "eval" scope 3 (savestack=3) at
..\pp_ctl.c​:4239
(..\forktest.pl​:1) CX 1 PUSH EVAL (scope 3,3) at ..\pp_ctl.c​:4270
(..\forktest.pl​:1) ENTER "evalcomp" scope 4 (savestack=45) at
..\pp_ctl.c​:3545
((eval 1)​:1) ENTER scope 5 (savestack=53) at ..\perly.c​:363
((eval 1)​:2) savestack​: releasing items 89 -> 73
((eval 1)​:2) ENTER scope 6 (savestack=73) at op.c​:9922
((eval 1)​:1) LEAVE scope 6 (savestack=78) at op.c​:10373
((eval 1)​:1) savestack​: releasing items 78 -> 73
((eval 1)​:2) ENTER scope 6 (savestack=73) at op.c​:1474
((eval 1)​:1) LEAVE scope 6 (savestack=76) at op.c​:1479
((eval 1)​:1) savestack​: releasing items 76 -> 73
((eval 1)​:2) LEAVE scope 5 (savestack=73) at ..\perly.c​:724
((eval 1)​:2) savestack​: releasing items 73 -> 53
((eval 1)​:2) LEAVE "evalcomp" scope 4 (savestack=53) at ..\pp_ctl.c​:3673
((eval 1)​:2) savestack​: releasing items 53 -> 45
((eval 1)​:1) CX 1 POP EVAL (scope 3,3) at ..\pp_ctl.c​:4329
(..\forktest.pl​:1) LEAVE "eval" scope 3 (savestack=47) at
..\pp_ctl.c​:4358
((eval 1)​:1) (dopoptoeval()​: found eval at cx=1)
((eval 1)​:1) CX 1 POP EVAL (scope 3,3) at ..\pp_ctl.c​:1735
(..\forktest.pl​:1) savestack​: releasing items 47 -> 3
(..\forktest.pl​:1) LEAVE scope 3 (savestack=47) at ..\pp_ctl.c​:1753
(..\forktest.pl​:1) ENTER "block" scope 3 (savestack=3) at
..\pp_ctl.c​:2123
(..\forktest.pl​:1) savestack​: releasing items 47 -> 3
(..\forktest.pl​:1) CX 1 PUSH BLOCK (scope 3,3) at ..\pp_ctl.c​:2126
(..\forktest.pl​:1) JUMPENV_JUMP(3) level=0 at ..\pp_ctl.c​:1783
(..\forktest.pl​:2) panic​: top_env, v=3
ENTER "eval" scope 4 (savestack=6) at ..\pp_ctl.c​:4239

@p5pRT
Copy link
Author

p5pRT commented Mar 19, 2012

From @jandubois

Sorry, I didn't get around to looking at it yet, but here are
some details​:

The crash happens in win32/perlhost.c on line 1727​:

1722​:
1723​: /* push a zero on the stack (we are the child) */
1724​: {
1725​: dSP;
1726​: dTARGET;
280B0289 mov eax,dword ptr [esi+4]
280B028C mov ecx,dword ptr [esi+8]
280B028F mov edi,dword ptr [esi]
1727​: PUSHi(0);
280B0291 push 0
280B0293 mov eax,dword ptr [eax+0Ch]
=======>
280B0296 mov ebx,dword ptr [ecx+eax*4]
280B0299 push ebx
280B029A push esi
280B029B call Perl_sv_setiv (280807bc)
280B02A0 add esp,0Ch
280B02A3 test byte ptr [ebx+0Ah],40h
280B02A7 je win32_start_child+78h (280b02b2)
280B02A9 push ebx
280B02AA push esi
280B02AB call Perl_mg_set (2801b30b)
280B02B0 pop ecx
280B02B1 pop ecx
280B02B2 add edi,4
280B02B5 mov dword ptr [edi],ebx
1728​: PUTBACK;
280B02B7 mov dword ptr [esi],edi
1729​: }

EAX = 00000002 EBX = 0014014C ECX = 00000000
EDX = FFFFFFFF ESI = 007A2744 EDI = 002FE6CC
EIP = 280B0296 ESP = 0098FF4C EBP = 0098FFB4
EFL = 00000202 CS = 001B DS = 0023 ES = 0023
SS = 0023 FS = 0038 GS = 0000 OV=0 UP=0 EI=1 PL=0
ZR=0 AC=0 PE=0 CY=0

00000008 = ????????

I have no idea how this might relate to the change triggering the
crash; I haven't looked at this code in ages.

Cheers,
-Jan

@p5pRT
Copy link
Author

p5pRT commented Apr 1, 2012

From alex@earth.li

I have distilled this down to​:

.\perl -Dl -e "eval q{fork}"

EXECUTING...

(-e​:0) Entering new RUNOPS level
(-e​:0) ENTER "block" scope 2 (savestack=0) at ..\pp_ctl.c​:2135
(-e​:0) CX 0 PUSH BLOCK (scope 2,2) at ..\pp_ctl.c​:2138
(-e​:1) ENTER "eval" scope 3 (savestack=3) at ..\pp_ctl.c​:4288
(-e​:1) CX 1 PUSH EVAL (scope 3,3) at ..\pp_ctl.c​:4319
(-e​:1) ENTER "evalcomp" scope 4 (savestack=45) at ..\pp_ctl.c​:3594
((eval 1)​:1) ENTER scope 5 (savestack=53) at ..\perly.c​:358
((eval 1)​:2) savestack​: releasing items 89 -> 73
((eval 1)​:2) ENTER scope 6 (savestack=75) at op.c​:2797
((eval 1)​:2) ENTER scope 7 (savestack=75) at op.c​:9969
((eval 1)​:2) LEAVE scope 7 (savestack=80) at op.c​:10420
((eval 1)​:2) savestack​: releasing items 80 -> 75
((eval 1)​:2) ENTER scope 7 (savestack=75) at op.c​:1501
((eval 1)​:2) LEAVE scope 7 (savestack=78) at op.c​:1506
((eval 1)​:2) savestack​: releasing items 78 -> 75
((eval 1)​:2) LEAVE scope 6 (savestack=75) at op.c​:2800
((eval 1)​:2) LEAVE scope 5 (savestack=73) at ..\perly.c​:719
((eval 1)​:2) savestack​: releasing items 73 -> 53
((eval 1)​:2) LEAVE "evalcomp" scope 4 (savestack=53) at ..\pp_ctl.c​:3722
((eval 1)​:2) savestack​: releasing items 53 -> 45
((eval 1)​:2) CX 1 POP EVAL (scope 3,3) at ..\pp_ctl.c​:4378
(-e​:1) LEAVE "eval" scope 3 (savestack=47) at ..\pp_ctl.c​:4407
(-e​:1) savestack​: releasing items 47 -> 3
(-e​:1) CX 0 POP BLOCK (scope 2,2) at ..\pp_ctl.c​:2156
(-e​:0) LEAVE "block" scope 2 (savestack=3) at ..\pp_ctl.c​:2164
(-e​:0) savestack​: releasing items 3 -> 0
(-e​:0) leaving RUNOPS level
(-e​:0) JUMPENV_JUMP(2) level=1 at perl.c​:4951
(-e​:0) JUMPENV_POP level=1 at perl.c​:2347
((eval 1)​:2) (dopoptoeval()​: found eval at cx=1)
((eval 1)​:2) CX 1 POP EVAL (scope 3,3) at ..\pp_ctl.c​:1747
(-e​:1) LEAVE scope 3 (savestack=47) at ..\pp_ctl.c​:1765
(-e​:1) savestack​: releasing items 47 -> 3
(-e​:1) JUMPENV_JUMP(3) level=0 at ..\pp_ctl.c​:1795
panic​: top_env, v=3

@p5pRT
Copy link
Author

p5pRT commented Apr 6, 2012

From @icerider70

On Sat, Mar 31, 2012 at 11​:27 PM, Alex Gough <alex@​earth.li> wrote​:

I have distilled this down to​:

.\perl -Dl -e "eval q{fork}"

EXECUTING...

<output showing panic snipped>

For comparison, here's the output of the same command when run against a
debugging win32 build of fde6729, i.e. just prior to the commit where
op/fork.t started exhibiting the failure​:

EXECUTING...

(-e​:0) Entering new RUNOPS level
(-e​:0) ENTER "block" scope 2 (savestack=0) at ..\pp_ctl.c​:2116
(-e​:0) CX 0 PUSH BLOCK (scope 2,2) at ..\pp_ctl.c​:2119
(-e​:1) ENTER "eval" scope 3 (savestack=3) at ..\pp_ctl.c​:4208
(-e​:1) CX 1 PUSH EVAL (scope 3,3) at ..\pp_ctl.c​:4239
((eval 1)​:1) ENTER "evalcomp" scope 4 (savestack=48) at ..\pp_ctl.c​:3528
((eval 1)​:1) ENTER scope 5 (savestack=53) at ..\perly.c​:362
((eval 1)​:2) savestack​: releasing items 89 -> 73
((eval 1)​:2) ENTER scope 6 (savestack=73) at op.c​:9869
((eval 1)​:2) LEAVE scope 6 (savestack=78) at op.c​:10284
((eval 1)​:2) savestack​: releasing items 78 -> 73
((eval 1)​:2) ENTER scope 6 (savestack=73) at op.c​:1462
((eval 1)​:2) LEAVE scope 6 (savestack=76) at op.c​:1467
((eval 1)​:2) savestack​: releasing items 76 -> 73
((eval 1)​:2) LEAVE scope 5 (savestack=73) at ..\perly.c​:723
((eval 1)​:2) savestack​: releasing items 73 -> 53
((eval 1)​:2) LEAVE "evalcomp" scope 4 (savestack=53) at ..\pp_ctl.c​:3577
((eval 1)​:2) savestack​: releasing items 53 -> 48
((eval 1)​:2) CX 1 POP EVAL (scope 3,3) at ..\pp_ctl.c​:4297
(-e​:1) LEAVE "eval" scope 3 (savestack=50) at ..\pp_ctl.c​:4325
(-e​:1) savestack​: releasing items 50 -> 3
((eval 1)​:2) JUMPENV_PUSH level=1 at perlhost.h​:1739
((eval 1)​:2) Entering new RUNOPS level
((eval 1)​:2) CX 1 POP EVAL (scope 3,3) at ..\pp_ctl.c​:4297
(-e​:1) LEAVE "eval" scope 3 (savestack=50) at ..\pp_ctl.c​:4325
(-e​:1) savestack​: releasing items 50 -> 3
(-e​:1) CX 0 POP BLOCK (scope 2,2) at ..\pp_ctl.c​:2137
((eval 1)​:0) LEAVE "block" scope 2 (savestack=3) at ..\pp_ctl.c​:2145
((eval 1)​:0) savestack​: releasing items 3 -> 0
((eval 1)​:0) leaving RUNOPS level
((eval 1)​:0) JUMPENV_POP level=1 at perlhost.h​:1780
(-e​:1) CX 0 POP BLOCK (scope 2,2) at ..\pp_ctl.c​:2137
(-e​:0) LEAVE "block" scope 2 (savestack=3) at ..\pp_ctl.c​:2145
(-e​:0) savestack​: releasing items 3 -> 0
(-e​:0) leaving RUNOPS level
(-e​:0) JUMPENV_JUMP(2) level=1 at perl.c​:4920
(-e​:0) JUMPENV_POP level=1 at perl.c​:2330
(-e​:0) LEAVE scope 1 (savestack=0) at perl.c​:570

@p5pRT
Copy link
Author

p5pRT commented Apr 6, 2012

From @khwilliamson

Attached is a diff file between the before/after with xterm color
escapes highlighting just the words that are different between the two.
cyan is the before version; yellow the panic

@p5pRT
Copy link
Author

p5pRT commented Apr 6, 2012

From @khwilliamson

win32.diff
  EXECUTING...
  
  (-e:0)  Entering new RUNOPS level
4,9c4,9
< (-e:0)  ENTER "block" scope 2 (savestack=0) at ..\pp_ctl.c:�[30;46m2116�[0m
< (-e:0)  CX 0 PUSH BLOCK (scope 2,2) at ..\pp_ctl.c:�[30;46m2119�[0m
< (-e:1)  ENTER "eval" scope 3 (savestack=3) at ..\pp_ctl.c:�[30;46m4208�[0m
< (-e:1)  CX 1 PUSH EVAL (scope 3,3) at ..\pp_ctl.c:�[30;46m4239�[0m
< (�[30;46m(eval 1)�[0m:1)  �[30;46m  �[0mENTER "evalcomp" scope 4 (savestack=�[30;46m48�[0m) at ..\pp_ctl.c:�[30;46m3528�[0m
< ((eval 1):1)    ENTER scope 5 (savestack=53) at ..\perly.c:�[30;46m362�[0m
---
> (-e:0)  ENTER "block" scope 2 (savestack=0) at ..\pp_ctl.c:�[30;43m2135�[0m
> (-e:0)  CX 0 PUSH BLOCK (scope 2,2) at ..\pp_ctl.c:�[30;43m2138�[0m
> (-e:1)  ENTER "eval" scope 3 (savestack=3) at ..\pp_ctl.c:�[30;43m4288�[0m
> (-e:1)  CX 1 PUSH EVAL (scope 3,3) at ..\pp_ctl.c:�[30;43m4319�[0m
> (�[30;43m-e�[0m:1)  ENTER "evalcomp" scope 4 (savestack=�[30;43m45�[0m) at ..\pp_ctl.c:�[30;43m3594�[0m
> ((eval 1):1)    ENTER scope 5 (savestack=53) at ..\perly.c:�[30;43m358�[0m
  ((eval 1):2)    savestack: releasing items 89 -> 73
11,17c11,19
< ((eval 1):2)    ENTER scope 6 (savestack=�[30;46m73�[0m) at op.c:�[30;46m9869�[0m
< ((eval 1):2)    LEAVE scope �[30;46m6�[0m (savestack=�[30;46m78�[0m) at op.c:�[30;46m10284�[0m
< ((eval 1):2)    savestack: releasing items �[30;46m78�[0m -> �[30;46m73�[0m
< ((eval 1):2)    ENTER scope �[30;46m6�[0m (savestack=�[30;46m73�[0m) at op.c:�[30;46m1462�[0m
< ((eval 1):2)    LEAVE scope �[30;46m6�[0m (savestack=�[30;46m76�[0m) at op.c:�[30;46m1467�[0m
< ((eval 1):2)    savestack: releasing items �[30;46m76�[0m -> �[30;46m73�[0m
< ((eval 1):2)    LEAVE scope 5 (savestack=73) at ..\perly.c:�[30;46m723�[0m
---
> ((eval 1):2)    ENTER scope 6 (savestack=�[30;43m75) at op.c:2797�[0m
> �[30;43m((eval 1):2)    ENTER scope 7 (savestack=75�[0m) at op.c:�[30;43m9969�[0m
> ((eval 1):2)    LEAVE scope �[30;43m7�[0m (savestack=�[30;43m80�[0m) at op.c:�[30;43m10420�[0m
> ((eval 1):2)    savestack: releasing items �[30;43m80�[0m -> �[30;43m75�[0m
> ((eval 1):2)    ENTER scope �[30;43m7�[0m (savestack=�[30;43m75�[0m) at op.c:�[30;43m1501�[0m
> ((eval 1):2)    LEAVE scope �[30;43m7�[0m (savestack=�[30;43m78�[0m) at op.c:�[30;43m1506�[0m
> ((eval 1):2)    savestack: releasing items �[30;43m78�[0m -> �[30;43m75�[0m
> �[30;43m((eval 1):2)    LEAVE scope 6 (savestack=75) at op.c:2800�[0m
> ((eval 1):2)    LEAVE scope 5 (savestack=73) at ..\perly.c:�[30;43m719�[0m
  ((eval 1):2)    savestack: releasing items 73 -> 53
19,35c21,27
< ((eval 1):2)    LEAVE "evalcomp" scope 4 (savestack=53) at ..\pp_ctl.c:�[30;46m3577�[0m
< ((eval 1):2)    savestack: releasing items 53 -> �[30;46m48�[0m
< ((eval 1):2)    CX 1 POP EVAL (scope 3,3) at ..\pp_ctl.c:�[30;46m4297�[0m
< (-e:1)  LEAVE "eval" scope 3 (savestack=�[30;46m50�[0m) at ..\pp_ctl.c:�[30;46m4325�[0m
< (-e:1)  savestack: releasing items �[30;46m50�[0m -> 3
< (�[30;46m(eval 1):2)    JUMPENV_PUSH level=1 at perlhost.h:1739�[0m
< �[30;46m((eval 1):2)    Entering new RUNOPS level�[0m
< �[30;46m((eval 1):2)    CX 1 POP EVAL (scope 3,3) at ..\pp_ctl.c:4297�[0m
< �[30;46m(-e:1)  LEAVE "eval" scope 3 (savestack=50) at ..\pp_ctl.c:4325�[0m
< �[30;46m(-e:1)  savestack: releasing items 50 -> 3�[0m
< �[30;46m(-e:1)  CX 0 POP BLOCK (scope 2,2) at ..\pp_ctl.c:2137�[0m
< �[30;46m((eval 1):0)    LEAVE "block" scope 2 (savestack=3) at ..\pp_ctl.c:2145�[0m
< �[30;46m((eval 1):0)    savestack: releasing items 3 -> 0�[0m
< �[30;46m((eval 1):0)    leaving RUNOPS level�[0m
< �[30;46m((eval 1):0)    JUMPENV_POP level=1 at perlhost.h:1780�[0m
< �[30;46m(�[0m-e:1)  CX 0 POP BLOCK (scope 2,2) at ..\pp_ctl.c:�[30;46m2137�[0m
< (-e:0)  LEAVE "block" scope 2 (savestack=3) at ..\pp_ctl.c:�[30;46m2145�[0m
---
> ((eval 1):2)    LEAVE "evalcomp" scope 4 (savestack=53) at ..\pp_ctl.c:�[30;43m3722�[0m
> ((eval 1):2)    savestack: releasing items 53 -> �[30;43m45�[0m
> ((eval 1):2)    CX 1 POP EVAL (scope 3,3) at ..\pp_ctl.c:�[30;43m4378�[0m
> (-e:1)  LEAVE "eval" scope 3 (savestack=�[30;43m47�[0m) at ..\pp_ctl.c:�[30;43m4407�[0m
> (-e:1)  savestack: releasing items �[30;43m47�[0m -> 3
> (-e:1)  CX 0 POP BLOCK (scope 2,2) at ..\pp_ctl.c:�[30;43m2156�[0m
> (-e:0)  LEAVE "block" scope 2 (savestack=3) at ..\pp_ctl.c:�[30;43m2164�[0m
  (-e:0)  savestack: releasing items 3 -> 0
  (-e:0)  leaving RUNOPS level
38,40c30,37
< (-e:0)  JUMPENV_JUMP(2) level=1 at perl.c:�[30;46m4920�[0m
< (-e:0)  JUMPENV_POP level=1 at perl.c:�[30;46m2330�[0m
< (-e:�[30;46m0�[0m)  LEAVE scope �[30;46m1�[0m (savestack=�[30;46m0�[0m) at �[30;46mperl�[0m.c:�[30;46m570�[0m
---
> (-e:0)  JUMPENV_JUMP(2) level=1 at perl.c:�[30;43m4951�[0m
> (-e:0)  JUMPENV_POP level=1 at perl.c:�[30;43m2347�[0m
> �[30;43m((eval 1):2)    (dopoptoeval(): found eval at cx=1)�[0m
> �[30;43m((eval 1):2)    CX 1 POP EVAL (scope 3,3) at ..\pp_ctl.c:1747�[0m
> (-e:�[30;43m1�[0m)  LEAVE scope �[30;43m3�[0m (savestack=�[30;43m47�[0m) at �[30;43m..\pp_ctl.c:1765�[0m
> �[30;43m(-e:1)  savestack: releasing items 47 -> 3�[0m
> �[30;43m(-e:1)  JUMPENV_JUMP(3) level=0 at ..\pp_ctl�[0m.c:�[30;43m1795�[0m
> �[30;43mpanic: top_env, v=3�[0m

@p5pRT
Copy link
Author

p5pRT commented Apr 8, 2012

From @bulk88

I did some thinking on this bug. I made a macro expanded Perl_die_unwind
using 5.15.9 release.

callstack of **CHILD** OS thread, the die_unwind is my version, so line
counts
are wrong compared to official perl release
____________________________________________________

perl515.dll!Perl_die_unwind(interpreter * my_perl=0x00907f24, sv *
msv=0x0090cf9c) Line 2058 C
  perl515.dll!Perl_vcroak(interpreter * my_perl=0x00907f24, const char *
pat=0x281b3f14, char * * args=0x00aefee4) Line 1716 + 0xd C
  perl515.dll!Perl_croak(interpreter * my_perl=0x00907f24, const char *
pat=0x281b3f14, ...) Line 1761 + 0x11 C
  perl515.dll!Perl_pad_sv(interpreter * my_perl=0x00907f24, unsigned
long po=1) Line 1329 + 0x44 C
  perl515.dll!win32_start_child(void * arg=0x00907f24) Line 1726 + 0x13 C++
  kernel32.dll!_BaseThreadStart@​8() + 0x37

______________________________________________________

It seems to me the bug is that this line (look in the die_unwind.c
attachment)
"
  if ((my_perl->Itop_env)->je_prev)
  longjmp ((((my_perl->Itop_env)->je_buf)),
(((3))));"
Never runs.

Debugger shows this.
je_buf array is 16 null characters.

- Itop_env 0x00908044 {je_prev=0x00000000 {je_prev=??? je_buf=0x00000004
je_ret=??? ...} je_buf=0x00908048 je_ret=-1 ...} jmpenv *
+ je_prev 0x00000000 {je_prev=??? je_buf=0x00000004 je_ret=??? ...} jmpenv *
+ je_buf 0x00908048 int [16]
  je_ret -1 int
  je_mustcatch 1 '␁' char

I'll guess the longjmp info is never collected.
____________________________________________________________________
Summary of my perl5 (revision 5 version 15 subversion 9) configuration​:

  Platform​:
  osname=MSWin32, osvers=5.1, archname=MSWin32-x86-multi-thread
  uname=''
  config_args='undef'
  hint=recommended, useposix=true, d_sigaction=undef
  useithreads=define, usemultiplicity=define
  useperlio=define, d_sfio=undef, uselargefiles=define, usesocks=undef
  use64bitint=undef, use64bitall=undef, uselongdouble=undef
  usemymalloc=n, bincompat5005=undef
  Compiler​:
  cc='cl', ccflags ='-nologo -GF -W3 -Od -MD -Zi -DDEBUGGING -Gy
-DWIN32 -D_CO
NSOLE -DNO_STRICT -DPERL_TEXTMODE_SCRIPTS -DPERL_IMPLICIT_CONTEXT
-DPERL_IMPLIC
IT_SYS -DUSE_PERLIO -D_USE_32BIT_TIME_T',
  optimize='-Od -MD -Zi -DDEBUGGING -Gy',
  cppflags='-DWIN32'
  ccversion='13.10.6030', gccversion='', gccosandvers=''
  intsize=4, longsize=4, ptrsize=4, doublesize=8, byteorder=1234
  d_longlong=undef, longlongsize=8, d_longdbl=define, longdblsize=8
  ivtype='long', ivsize=4, nvtype='double', nvsize=8, Off_t='__int64',
lseeksi
ze=8
  alignbytes=8, prototype=define
  Linker and Libraries​:
  ld='link', ldflags ='-nologo -nodefaultlib -debug -opt​:ref,icf
-libpath​:"c​:
\perl515\lib\CORE" -machine​:x86'
  libpth="C​:\Program Files\Microsoft Visual Studio .NET 2003\VC7\lib"
  libs=oldnames.lib kernel32.lib user32.lib gdi32.lib winspool.lib
comdlg32.l
ib advapi32.lib shell32.lib ole32.lib oleaut32.lib netapi32.lib
uuid.lib ws2_32
.lib mpr.lib winmm.lib version.lib odbc32.lib odbccp32.lib comctl32.lib
msvcrt.
lib
  perllibs=oldnames.lib kernel32.lib user32.lib gdi32.lib winspool.lib
comdlg
32.lib advapi32.lib shell32.lib ole32.lib oleaut32.lib netapi32.lib
uuid.lib ws
2_32.lib mpr.lib winmm.lib version.lib odbc32.lib odbccp32.lib
comctl32.lib msv
crt.lib
  libc=msvcrt.lib, so=dll, useshrplib=true, libperl=perl515.lib
  gnulibc_version=''
  Dynamic Linking​:
  dlsrc=dl_win32.xs, dlext=dll, d_dlsymun=undef, ccdlflags=' '
  cccdlflags=' ', lddlflags='-dll -nologo -nodefaultlib -debug
-opt​:ref,icf -
libpath​:"c​:\perl515\lib\CORE" -machine​:x86'

Characteristics of this binary (from libperl)​:
  Compile-time options​: DEBUGGING HAS_TIMES HAVE_INTERP_INTERN MULTIPLICITY
  PERLIO_LAYERS PERL_DONT_CREATE_GVSV
  PERL_IMPLICIT_CONTEXT PERL_IMPLICIT_SYS
  PERL_MALLOC_WRAP PERL_PRESERVE_IVUV
  PERL_TRACK_MEMPOOL PL_OP_SLAB_ALLOC USE_ITHREADS
  USE_LARGE_FILES USE_LOCALE USE_LOCALE_COLLATE
  USE_LOCALE_CTYPE USE_LOCALE_NUMERIC USE_PERLIO
  USE_PERL_ATOF
  Built under MSWin32
  Compiled at Apr 8 2012 14​:09​:10
  %ENV​:
  PERL_JSON_BACKEND="JSON​::XS"
  PERL_YAML_BACKEND="YAML"
  @​INC​:
  C​:/perl515/site/lib
  C​:/perl515/lib
  .

@p5pRT
Copy link
Author

p5pRT commented Apr 8, 2012

From @bulk88

void
Perl_die_unwind (PerlInterpreter * my_perl, SV * msv)
{
    extern int Perl___notused (void);
    SV *exceptsv = Perl_sv_mortalcopy (my_perl, msv);
    U8 in_eval = (my_perl->Iin_eval);
    (void) ((msv) || (_assert ("msv", "..\\pp_ctl.c", 1676), 0));

    if (in_eval)
      {
          I32 cxix;
          I32 gimme;

          /*
           * Historically, perl used to set ERRSV ($@) early in the die
           * process and rely on it not getting clobbered during unwinding.
           * That sucked, because it was liable to get clobbered, so the
           * setting of ERRSV used to emit the exception from eval{} has
           * been moved to much later, after unwinding (see just before
           * JMPENV_JUMP below).  However, some modules were relying on the
           * early setting, by examining $@ during unwinding to use it as
           * a flag indicating whether the current unwinding was caused by
           * an exception.  It was never a reliable flag for that purpose,
           * being totally open to false positives even without actual
           * clobberage, but was useful enough for production code to
           * semantically rely on it.
           *
           * We'd like to have a proper introspective interface that
           * explicitly describes the reason for whatever unwinding
           * operations are currently in progress, so that those modules
           * work reliably and $@ isn't further overloaded.  But we don't
           * have one yet.  In its absence, as a stopgap measure, ERRSV is
           * now *additionally* set here, before unwinding, to serve as the
           * (unreliable) flag that it used to.
           *
           * This behaviour is temporary, and should be removed when a
           * proper way to detect exceptional unwinding has been developed.
           * As of 2010-12, the authors of modules relying on the hack
           * are aware of the issue, because the modules failed on
           * perls 5.13.{1..7} which had late setting of $@ without this
           * early-setting hack.
           */
          if (!(in_eval & 4))
            {
                ((exceptsv)->sv_flags &= ~0x00080000);
                Perl_sv_setsv_flags (my_perl,
                                     (*
                                      ((0 +
                                        ((my_perl->Ierrgv))->sv_u.svu_gp)->gp_sv ? &((0 +
                                                                                      ((my_perl->Ierrgv))->
                                                                                      sv_u.svu_gp)->
                                                                                     gp_sv) : &((0 +
                                                                                                 (Perl_gv_add_by_type
                                                                                                  (my_perl,
                                                                                                   ((my_perl->Ierrgv)), SVt_NULL))->sv_u.svu_gp)->gp_sv))), exceptsv, 2 | 512 | 1024);
            }

          while ((cxix = S_dopoptoeval (my_perl, ((my_perl->Icurstackinfo)->si_cxix))) < 0
                 && (my_perl->Icurstackinfo)->si_prev)
            {
                Perl_dounwind (my_perl, -1);
                do
                  {
                      SV **sp = (my_perl->Istack_sp);
                      PERL_SI *const prev = (my_perl->Icurstackinfo)->si_prev;
                      if (((my_perl->Idebug) & 0x00000004))
                        {
                            int i = -1;
                            PERL_SI *p = (my_perl->Icurstackinfo);
                            while (p)
                              {
                                  i++;
                                  p = p->si_prev;
                              }
                            Perl_deb (my_perl, "pop  STACKINFO %d at %s:%d\n", i, "..\\pp_ctl.c", 1720);
                        }
                      if (!prev)
                        {
                            PerlIO_printf (((my_perl->Istderrgv)
                                            && (((svtype) (((my_perl->Istderrgv))->sv_flags & 0xff)) ==
                                                SVt_PVGV)
                                            && ((0 + ((my_perl->Istderrgv))->sv_u.svu_gp)->gp_io)
                                            &&
                                            ((XPVIO
                                              *) (((0 +
                                                    ((my_perl->Istderrgv))->sv_u.svu_gp)->gp_io))->sv_any)->
                                            xio_ofp
                                            ? ((XPVIO
                                                *) (((0 +
                                                      ((my_perl->Istderrgv))->sv_u.svu_gp)->gp_io))->
                                               sv_any)->xio_ofp : Perl_PerlIO_stderr (my_perl)),
                                           "panic: POPSTACK\n");
                            Perl_my_exit (my_perl, 1);
                        }
                      do
                        {
                            ((XPVAV *) ((my_perl->Icurstack))->sv_any)->xav_fill =
                                sp - (my_perl->Istack_base);
                            (my_perl->Istack_base) = ((prev->si_stack)->sv_u.svu_array);
                            (my_perl->Istack_max) =
                                (my_perl->Istack_base) + ((XPVAV *) (prev->si_stack)->sv_any)->xav_max;
                            sp = (my_perl->Istack_sp) =
                                (my_perl->Istack_base) + ((XPVAV *) (prev->si_stack)->sv_any)->xav_fill;
                            (my_perl->Icurstack) = prev->si_stack;
                        }
                      while (0);
                      (my_perl->Icurstackinfo) = prev;
                  }
                while (0);
            }

          if (cxix >= 0)
            {
                I32 optype;
                SV *namesv;
                PERL_CONTEXT *cx;
                SV **newsp;
                COP *oldcop;
                JMPENV *restartjmpenv;
                OP *restartop;

                if (cxix < ((my_perl->Icurstackinfo)->si_cxix))
                    Perl_dounwind (my_perl, cxix);

                if (((my_perl->Idebug) & 0x00000004))
                    Perl_deb (my_perl, "CX %ld %s %s (scope %ld,%ld) at %s:%d\n",
                              (long) ((my_perl->Icurstackinfo)->si_cxix), "POP",
                              PL_block_type[((&((my_perl->Icurstackinfo)->si_cxstack)
                                              [((my_perl->Icurstackinfo)->si_cxix)])->cx_u.cx_subst.
                                             sbu_type & 0xf)], (long) (my_perl->Iscopestack_ix),
                              (long) (((my_perl->Icurstackinfo)->
                                       si_cxstack)[((my_perl->Icurstackinfo)->si_cxix)].cx_u.cx_blk.
                                      blku_oldscopesp), "..\\pp_ctl.c", 1735);;
                cx = &((my_perl->Icurstackinfo)->si_cxstack)[((my_perl->Icurstackinfo)->si_cxix)--], newsp =
                    (my_perl->Istack_base) + cx->cx_u.cx_blk.blku_oldsp, (my_perl->Icurcop) =
                    cx->cx_u.cx_blk.blku_oldcop, (my_perl->Imarkstack_ptr) =
                    (my_perl->Imarkstack) + cx->cx_u.cx_blk.blku_oldmarksp, (my_perl->Iscopestack_ix) =
                    cx->cx_u.cx_blk.blku_oldscopesp, (my_perl->Icurpm) = cx->cx_u.cx_blk.blku_oldpm, gimme =
                    cx->cx_u.cx_blk.blku_gimme;;
                if (((cx)->cx_u.cx_subst.sbu_type & 0xf) != 10)
                  {
                      STRLEN msglen;
                      const char *message =
                          (((my_perl->ISv) =
                            (exceptsv)),
                           ((((my_perl->ISv))->sv_flags & (0x00000400)) ==
                            0x00000400 ? ((msglen = ((XPV *) ((my_perl->ISv))->sv_any)->xpv_cur),
                                          ((const char *) (0 +
                                                           ((my_perl->ISv))->sv_u.
                                                           svu_pv))) : (const char *)
                            Perl_sv_2pv_flags (my_perl, (my_perl->ISv), &msglen, 2 | 32)));
                      Perl_PerlIO_write (my_perl,
                                         ((my_perl->Istderrgv)
                                          && (((svtype) (((my_perl->Istderrgv))->sv_flags & 0xff)) ==
                                              SVt_PVGV)
                                          && ((0 + ((my_perl->Istderrgv))->sv_u.svu_gp)->gp_io)
                                          &&
                                          ((XPVIO *) (((0 + ((my_perl->Istderrgv))->sv_u.svu_gp)->gp_io))->
                                           sv_any)->
                                          xio_ofp
                                          ? ((XPVIO
                                              *) (((0 +
                                                    ((my_perl->Istderrgv))->sv_u.svu_gp)->gp_io))->sv_any)->
                                          xio_ofp : Perl_PerlIO_stderr (my_perl)),
                                         (const char *) "panic: die ", 11);
                      Perl_PerlIO_write (my_perl,
                                         ((my_perl->Istderrgv)
                                          && (((svtype) (((my_perl->Istderrgv))->sv_flags & 0xff)) ==
                                              SVt_PVGV)
                                          && ((0 + ((my_perl->Istderrgv))->sv_u.svu_gp)->gp_io)
                                          &&
                                          ((XPVIO *) (((0 + ((my_perl->Istderrgv))->sv_u.svu_gp)->gp_io))->
                                           sv_any)->
                                          xio_ofp
                                          ? ((XPVIO
                                              *) (((0 +
                                                    ((my_perl->Istderrgv))->sv_u.svu_gp)->gp_io))->sv_any)->
                                          xio_ofp : Perl_PerlIO_stderr (my_perl)), message, msglen);
                      Perl_my_exit (my_perl, 1);
                  }
                do
                  {
                      (my_perl->Iin_eval) = (((cx)->cx_u.cx_blk.blku_u16) & 0x7F);
                      optype = (((cx)->cx_u.cx_blk.blku_u16) >> 7);
                      (my_perl->Ieval_root) = cx->cx_u.cx_blk.blk_u.blku_eval.old_eval_root;
                      if (cx->cx_u.cx_blk.blk_u.blku_eval.old_namesv)
                          Perl_sv_2mortal (my_perl, cx->cx_u.cx_blk.blk_u.blku_eval.old_namesv);
                  }
                while (0);
                namesv = cx->cx_u.cx_blk.blk_u.blku_eval.old_namesv;
                oldcop = cx->cx_u.cx_blk.blku_oldcop;
                restartjmpenv = cx->cx_u.cx_blk.blk_u.blku_eval.cur_top_env;
                restartop = cx->cx_u.cx_blk.blk_u.blku_eval.retop;

                if (gimme == 2)
                    *++newsp = &(my_perl->Isv_undef);
                (my_perl->Istack_sp) = newsp;

                do
                  {
                      if (((my_perl->Idebug) & 0x00000004))
                          Perl_deb (my_perl, "%s scope %ld (savestack=%ld) at %s:%d\n", "LEAVE",
                                    (long) (my_perl->Iscopestack_ix), (long) (my_perl->Isavestack_ix),
                                    "..\\pp_ctl.c", 1753);
                      Perl_pop_scope (my_perl);
                  }
                while (0);

                /* LEAVE could clobber PL_curcop (see save_re_context())
                 * XXX it might be better to find a way to avoid messing with
                 * PL_curcop in save_re_context() instead, but this is a more
                 * minimal fix --GSAR */
                (my_perl->Icurcop) = oldcop;

                if (optype == OP_REQUIRE)
                  {
                      (void) ((SV **)
                              Perl_hv_common_key_len (my_perl,
                                                      (((0 + ((my_perl->Iincgv))->sv_u.svu_gp)->gp_hv ? (0 +
                                                                                                         ((my_perl->Iincgv))->sv_u.svu_gp)->gp_hv : (0 + (Perl_gv_add_by_type (my_perl, ((my_perl->Iincgv)), SVt_PVHV))->sv_u.svu_gp)->gp_hv)), (((const char *) (0 + (namesv)->sv_u.svu_pv))), (((namesv)->sv_flags & 0x20000000) ? -(I32) ((XPV *) (namesv)->sv_any)->xpv_cur : (I32) ((XPV *) (namesv)->sv_any)->xpv_cur), (0x04 | 0x20), (&(my_perl->Isv_undef)), (0)));
                      /* note that unlike pp_entereval, pp_require isn't
                       * supposed to trap errors. So now that we've popped the
                       * EVAL that pp_require pushed, and processed the error
                       * message, rethrow the error */
                      Perl_croak (my_perl, "%" "-p" "Compilation failed in require",
                                  ((void *) (exceptsv ? exceptsv :
                                             Perl_newSVpvn_flags (my_perl, ("" "Unknown error\n" ""),
                                                                  (sizeof ("Unknown error\n") - 1),
                                                                  0x00080000))));
                  }
                if (in_eval & 4)
                  {
                      Perl_ck_warner (my_perl, (12), "\t(in cleanup) %" "-p", ((void *) (exceptsv)));
                  }
                else
                  {
                      Perl_sv_setsv_flags (my_perl,
                                           (*
                                            ((0 +
                                              ((my_perl->Ierrgv))->sv_u.svu_gp)->gp_sv ? &((0 +
                                                                                            ((my_perl->
                                                                                              Ierrgv))->
                                                                                            sv_u.svu_gp)->
                                                                                           gp_sv) : &((0 +
                                                                                                       (Perl_gv_add_by_type
                                                                                                        (my_perl,
                                                                                                         ((my_perl->Ierrgv)), SVt_NULL))->sv_u.svu_gp)->gp_sv))), exceptsv, 2 | 512 | 1024);
                  }
                (my_perl->Irestartjmpenv) = restartjmpenv;
                (my_perl->Irestartop) = restartop;
                do
                  {
                      if (((my_perl->Idebug) & 0x00000004))
                        {
                            int i = -1;
                            JMPENV *p = (my_perl->Itop_env);
                            while (p)
                              {
                                  i++;
                                  p = p->je_prev;
                              }
                            Perl_deb (my_perl, "JUMPENV_JUMP(%d) level=%d at %s:%d\n", (int) 3, i,
                                      "..\\pp_ctl.c", 1783);
                        }
                      (void) 0;
                      if ((my_perl->Itop_env)->je_prev)
                          longjmp ((((my_perl->Itop_env)->je_buf)), (((3))));
                      if ((3) == 2)
                            PerlProc_exit((my_perl->Istatusvalue));
                      PerlIO_printf (Perl_PerlIO_stderr (my_perl), "panic: top_env, v=%d\n", (int) 3);
                      PerlProc_exit((1));
                  }
                while (0);
                /* NOTREACHED */
            }
      }

    Perl_write_to_stderr (my_perl, exceptsv);
    Perl_my_failure_exit (my_perl);
    /* NOTREACHED */
}

@p5pRT
Copy link
Author

p5pRT commented Apr 8, 2012

From @bulk88

forkbugdb.PNG

@p5pRT
Copy link
Author

p5pRT commented Apr 8, 2012

From @bulk88

forgot to add, the test program the above post was done with is "-e
"eval q{fork}""

@p5pRT
Copy link
Author

p5pRT commented Apr 8, 2012

From @bulk88

On Sun Apr 08 11​:45​:45 2012, bulk88 wrote​:

forgot to add, the test program the above post was done with is "-e
"eval q{fork}""
The bug is actually that there is no pad in the interpreter (null
pointer). Its an assert thats failing, "ASSERT_CURPAD_ACTIVE("pad_sv");"
in Perl_pad_sv. The assert is conditional on DEBUGGING flag in pad.h
___________________________________________________
#ifdef DEBUGGING
# define ASSERT_CURPAD_LEGAL(label) \
  pad_peg(label); \
  if (PL_comppad ? (AvARRAY(PL_comppad) != PL_curpad) : (PL_curpad !=
0)) \
  Perl_croak(aTHX_ "panic​: illegal pad in %s​: 0x%"UVxf"[0x%"UVxf"]",\
  label, PTR2UV(PL_comppad), PTR2UV(PL_curpad));

# define ASSERT_CURPAD_ACTIVE(label) \
  pad_peg(label); \
  if (!PL_comppad || (AvARRAY(PL_comppad) != PL_curpad)) \
  Perl_croak(aTHX_ "panic​: invalid pad in %s​: 0x%"UVxf"[0x%"UVxf"]",\
  label, PTR2UV(PL_comppad), PTR2UV(PL_curpad));
#else
# define ASSERT_CURPAD_LEGAL(label)
# define ASSERT_CURPAD_ACTIVE(label)
#endif
_____________________________________________________
So some people get the top_env panic, others get access vio.

@p5pRT
Copy link
Author

p5pRT commented Apr 8, 2012

From @bulk88

forkbugdb2.PNG

@p5pRT
Copy link
Author

p5pRT commented Apr 8, 2012

From @bulk88

On Sun Apr 08 12​:30​:34 2012, bulk88 wrote​:

The bug is actually that there is no pad in the interpreter (null
pointer).

On my perl 5.12, curpad and comppad are non-null at the beginning (
http​://perl5.git.perl.org/perl.git/blob/03d9f026ae253e9e69212a3cf6f1944437e9f070​:/win32/perlhost.h#l1696
) of the child thread. On perl 5.15 curpad and comppad are null at the
beginning of the child thread. Problem is in parent thread.

At
http​://perl5.git.perl.org/perl.git/blob/03d9f026ae253e9e69212a3cf6f1944437e9f070​:/win32/perlhost.h#l1823
in child interpreter in 5.15, curpad is null after perl_clone_using, it
is non-null in 5.12.

At
http​://perl5.git.perl.org/perl.git/blob/03d9f026ae253e9e69212a3cf6f1944437e9f070​:/sv.c#l13284
in 5.12, curpad and compad get set to non-poison/garbage pointers. In
5.15 PAD_CLONE_VARS (
http​://perl5.git.perl.org/perl.git/blob/03d9f026ae253e9e69212a3cf6f1944437e9f070​:/pad.h#l339
) sets from poison/garbage to null pointers.

I might research it more today, or not, IDK. If someone is else is
faster than me, good.

@p5pRT
Copy link
Author

p5pRT commented Apr 8, 2012

From @bulk88

On Sun Apr 08 13​:17​:36 2012, bulk88 wrote​:
comppad isn't found in the pointer table, this returns null in 5.15
http​://perl5.git.perl.org/perl.git/blob/03d9f026ae253e9e69212a3cf6f1944437e9f070​:/sv.c#l11551

In 5.12, curpad is added with the following callstack.
___________________________________________________________
  perl512.dll!Perl_ptr_table_store(interpreter * my_perl=0x008368b4,
ptr_tbl * const tbl=0x00838ec4, const void * const oldsv=0x0082b35c,
void * const newsv=0x0084e564) Line 10799 C
  perl512.dll!Perl_sv_dup(interpreter * my_perl=0x008368b4, const sv *
const sstr=0x0082b35c, clone_params * const param=0x0006fa48) Line
10999 + 0x1b C
  perl512.dll!S_sv_dup_inc_multiple(interpreter * my_perl=0x008368b4, sv
* const * source=0x0082d3f0, sv * * dest=0x0085a9b8, int items=0,
clone_params * const param=0x0006fa48) Line 10948 + 0x19 C
  perl512.dll!Perl_sv_dup(interpreter * my_perl=0x008368b4, const sv *
const sstr=0x00397e9c, clone_params * const param=0x0006fa48) Line
11191 + 0x19 C
  perl512.dll!Perl_sv_dup(interpreter * my_perl=0x008368b4, const sv *
const sstr=0x00397e6c, clone_params * const param=0x0006fa48) Line
11284 + 0x57 C

perl512.dll!perl_clone_using(interpreter * proto_perl=0x00394194,
unsigned long flags=1, IPerlMem * ipM=0x00286074, IPerlMem *
ipMS=0x00286090, IPerlMem * ipMP=0x002860ac, IPerlEnv * ipE=0x002860c8,
IPerlStdIO * ipStd=0x00286100, IPerlLIO * ipLIO=0x0028619c, IPerlDir *
ipD=0x00286204, IPerlSock * ipS=0x00286230, IPerlProc * ipP=0x002862e0)
Line 12230 + 0x17 C
  perl512.dll!PerlProcFork(IPerlProc * piPerl=0x00285eb0) Line 1859 +
0x65 C++
  perl512.dll!Perl_pp_fork(interpreter * my_perl=0x00394194) Line
4082 + 0x16 C
  perl512.dll!Perl_runops_debug(interpreter * my_perl=0x00394194) Line
2049 + 0xd C
  perl512.dll!S_run_body(interpreter * my_perl=0x00394194, long
oldscope=1) Line 2308 + 0xd C
  perl512.dll!perl_run(interpreter * my_perl=0x00394194) Line 2233 + 0xd C
  perl512.dll!RunPerl(int argc=3, char * * argv=0x00282478, char * *
env=0x00285148) Line 270 + 0x9 C++
  perl.exe!main(int argc=3, char * * argv=0x00282478, char * *
env=0x00282d68) Line 23 + 0x12 C
  perl.exe!mainCRTStartup() Line 398 + 0xe C
  kernel32.dll!_BaseProcessStart@​4() + 0x23
_______________________________________________________________
In 5.12, the line that triggered the cloning is
http​://perl5.git.perl.org/perl.git/blob/03d9f026ae253e9e69212a3cf6f1944437e9f070​:/sv.c#l13282
" PL_compcv = cv_dup(proto_perl->Icompcv, param);".
Somewhere between 5.12 and 5.15, sv_dup was gutted and turned into
sv_dup_common.

At this point,
http​://perl5.git.perl.org/perl.git/blob/03d9f026ae253e9e69212a3cf6f1944437e9f070​:/sv.c#l13282
, in 5.12 compcv of parent interp is non-null, in 5.15 compcv of parent
interp is null. Therefore it wont get cloned into the "pointer table".

On entry to perl_clone_using
at
http​://perl5.git.perl.org/perl.git/blob/03d9f026ae253e9e69212a3cf6f1944437e9f070​:/sv.c#l12779
, in 5.12, parent interp has non-null compcv. In 5.15, in parent interp
has null compcv.

On entry to pp_fork at
http​://perl5.git.perl.org/perl.git/blob/03d9f026ae253e9e69212a3cf6f1944437e9f070​:/pp_sys.c#l3980
in 5.12 compcv in my_perl/parent interp is non null, in 5.15 it is null.

This is now an opcode problem.

_____________________________________________
  perl512.dll!Perl_pp_fork(interpreter * my_perl=0x00394194) Line 4049 C
  perl512.dll!Perl_runops_debug(interpreter * my_perl=0x00394194) Line
2049 + 0xd C
  perl512.dll!S_run_body(interpreter * my_perl=0x00394194, long
oldscope=1) Line 2308 + 0xd C
  perl512.dll!perl_run(interpreter * my_perl=0x00394194) Line 2233 + 0xd C
  perl512.dll!RunPerl(int argc=3, char * * argv=0x00282478, char * *
env=0x00285148) Line 270 + 0x9 C++
  perl.exe!main(int argc=3, char * * argv=0x00282478, char * *
env=0x00282d68) Line 23 + 0x12 C
  perl.exe!mainCRTStartup() Line 398 + 0xe C

kernel32.dll!_BaseProcessStart@​4() + 0x23
_________________________________________________
perl515.dll!Perl_pp_fork(interpreter * my_perl=0x00384194) Line 4035 C
  perl515.dll!Perl_runops_debug(interpreter * my_perl=0x00384194) Line
2119 + 0xd C
  perl515.dll!S_run_body(interpreter * my_perl=0x00384194, long
oldscope=1) Line 2400 + 0xd C
  perl515.dll!perl_run(interpreter * my_perl=0x00384194) Line 2318 + 0xd C
  perl515.dll!RunPerl(int argc=3, char * * argv=0x00342478, char * *
env=0x00345148) Line 270 + 0x9 C++
  perl.exe!main(int argc=3, char * * argv=0x00342478, char * *
env=0x00342d68) Line 23 + 0x12 C
  perl.exe!mainCRTStartup() Line 398 + 0xe C
  kernel32.dll!_BaseProcessStart@​4() + 0x23
___________________________________________________

@p5pRT
Copy link
Author

p5pRT commented Apr 8, 2012

From @cpansprout

On Sun Apr 08 13​:17​:36 2012, bulk88 wrote​:

I might research it more today, or not, IDK. If someone is else is
faster than me, good.

Thank you very much for researching this. I’m afraid I don’t have
access to a (functional) Windows with a compiler, so I won’t be any
faster. :-)

--

Father Chrysostomos

@p5pRT
Copy link
Author

p5pRT commented Apr 8, 2012

From @bulk88

On perl 5.12 PP(pp_entereval) opcode sets compcv. On perl 5.15 it doesn't.

entereval calls, S_doeval. On 5.15, at, hmm, head git 5.15 doesn't match
my 5.15.9, in S_doeval, the line " else if (!startop)
LEAVE_with_name("evalcomp");" sets perl 5.15 compcv to null.
_______________________________________________________
  if (gimme != G_ARRAY) PUSHs(&PL_sv_undef);
  PUTBACK;
  return FALSE;
  }
  else if (!startop) LEAVE_with_name("evalcomp");
  CopLINE_set(&PL_compiling, 0);
  if (startop) {
  *startop = PL_eval_root;
  } else
  SAVEFREEOP(PL_eval_root);

  DEBUG_x(dump_eval());
_____________________________________________________

In both 5.12 and 5.15, startop is null pointer on entry and remains
false throughout the body of S_doeval. In the calling function
"pp_entereval", startop parameter is const NULL pointer in both 5.12 and
5.15. Since 5.12 doesn't have " else if (!startop)
LEAVE_with_name("evalcomp");", compcv can not be set to null and 5.12
works without any problems. I think im probably done analyzing this.

@p5pRT
Copy link
Author

p5pRT commented Apr 8, 2012

From @bulk88

Here is where in LEAVE_with_name compcv is set to null. I guess a NULL
compcv cv is being saved onto the save stack.

@p5pRT
Copy link
Author

p5pRT commented Apr 8, 2012

From @bulk88

forkbugdb3.PNG

@p5pRT
Copy link
Author

p5pRT commented Apr 8, 2012

From @bulk88

On Sun Apr 08 15​:12​:29 2012, bulk88 wrote​:

Here is where in LEAVE_with_name compcv is set to null. I guess a NULL
compcv cv is being saved onto the save stack.

compcv is null on entry to S_doeval in 5.15 and 5.12.

I will guess the bug is either a lack of a extra mortal/scope/save, or
the "else if (!startop) LEAVE_with_name("evalcomp");". I can't write a
fix since I dont know enough about perl interp internals, or why the
LEAVE_with_name is there in the first place. I'm done here. Not going to
put any more replys here unless someone else responds.

@p5pRT
Copy link
Author

p5pRT commented Apr 8, 2012

From @khwilliamson

On 04/08/2012 04​:28 PM, bulk 88 via RT wrote​:

On Sun Apr 08 15​:12​:29 2012, bulk88 wrote​:

Here is where in LEAVE_with_name compcv is set to null. I guess a NULL
compcv cv is being saved onto the save stack.

compcv is null on entry to S_doeval in 5.15 and 5.12.

I will guess the bug is either a lack of a extra mortal/scope/save, or
the "else if (!startop) LEAVE_with_name("evalcomp");". I can't write a
fix since I dont know enough about perl interp internals, or why the
LEAVE_with_name is there in the first place. I'm done here. Not going to
put any more replys here unless someone else responds.

---
via perlbug​: queue​: perl5 status​: open
https://rt-archive.perl.org/perl5/Ticket/Display.html?id=109718

Thanks very much for your tracking this down. I'm hopeful that someone
who knows something about this area of the code will see this and figure
it out shortly, but I think you've given us a huge step forward on this
seemingly intractable bug.

karl williamson

@p5pRT
Copy link
Author

p5pRT commented Apr 9, 2012

From @rjbs

Thanks /very much/ for this detective work! It's really appreciated over here.

--
rjbs

@p5pRT
Copy link
Author

p5pRT commented Apr 10, 2012

From @cpansprout

On Sun Apr 08 15​:28​:23 2012, bulk88 wrote​:

On Sun Apr 08 15​:12​:29 2012, bulk88 wrote​:

Here is where in LEAVE_with_name compcv is set to null. I guess a NULL
compcv cv is being saved onto the save stack.

compcv is null on entry to S_doeval in 5.15 and 5.12.

The change that caused this crash (see subject) intentionally restored
compcv to its previous value before exiting S_doeval, so that XS code
run from sub foo { BEGIN { eval "xs_code()" } } would be able to see foo
in PL_compcv (since it is the currently compiling sub).

I will guess the bug is either a lack of a extra mortal/scope/save, or
the "else if (!startop) LEAVE_with_name("evalcomp");".

The purpose of the evalcomp scope (which I added earlier) is to undo
localisations that happen only for the sake of compiling the eval, so
that the eval can affect the calling compilation scope, making eval
'$^H{foo} = "bar"' equivalent to eval { $^H{foo} = "bar" }.

Earlier, you wrote​:

At

http​://perl5.git.perl.org/perl.git/blob/03d9f026ae253e9e69212a3cf6f1944437e9f070​:/sv.c#l13284

in 5.12, curpad and compad get set to non-poison/garbage pointers. In
5.15 PAD_CLONE_VARS (

http​://perl5.git.perl.org/perl.git/blob/03d9f026ae253e9e69212a3cf6f1944437e9f070​:/pad.h#l339

) sets from poison/garbage to null pointers.

That may be the problem.

What happens if you apply the attached patch? This is a bit of a stab
in the dark, as I don’t understand in detail how PL_comppad is used.

--

Father Chrysostomos

@p5pRT
Copy link
Author

p5pRT commented Apr 10, 2012

From @cpansprout

Inline Patch
diff --git a/pad.h b/pad.h
index ddde4d7..aa6521f 100644
--- a/pad.h
+++ b/pad.h
@@ -338,7 +338,7 @@ Clone the state variables associated with running and compiling pads.
  * sub's CV or padlist. */
 
 #define PAD_CLONE_VARS(proto_perl, param)				\
-    PL_comppad = MUTABLE_AV(ptr_table_fetch(PL_ptr_table, proto_perl->Icomppad)); \
+    PL_comppad			= av_dup(proto_perl->Icomppad, param);	\
     PL_curpad = PL_comppad ?  AvARRAY(PL_comppad) : NULL;		\
     PL_comppad_name		= av_dup(proto_perl->Icomppad_name, param); \
     PL_comppad_name_fill	= proto_perl->Icomppad_name_fill;	\

@p5pRT
Copy link
Author

p5pRT commented Apr 10, 2012

From @jandubois

On Mon, 09 Apr 2012, Father Chrysostomos via RT wrote​:

What happens if you apply the attached patch? This is a bit of a stab
in the dark, as I don’t understand in detail how PL_comppad is used.

Excellent, this does indeed fix the crashes!

Cheers,
-Jan

@p5pRT
Copy link
Author

p5pRT commented Apr 10, 2012

From @cpansprout

On Mon Apr 09 19​:59​:06 2012, jdb wrote​:

On Mon, 09 Apr 2012, Father Chrysostomos via RT wrote​:

What happens if you apply the attached patch? This is a bit of a stab
in the dark, as I don’t understand in detail how PL_comppad is used.

Excellent, this does indeed fix the crashes!

I’ve pushed it to the smoke-me/109718 branch. Let’s see what the
smokers make of it.

Believe or not, I’ve not even tried compiling it yet. :-)

--

Father Chrysostomos

@p5pRT
Copy link
Author

p5pRT commented Apr 10, 2012

From @cpansprout

On Mon Apr 09 20​:38​:49 2012, sprout wrote​:

On Mon Apr 09 19​:59​:06 2012, jdb wrote​:

On Mon, 09 Apr 2012, Father Chrysostomos via RT wrote​:

What happens if you apply the attached patch? This is a bit of a stab
in the dark, as I don’t understand in detail how PL_comppad is used.

Excellent, this does indeed fix the crashes!

I’ve pushed it to the smoke-me/109718 branch. Let’s see what the
smokers make of it.

Could this getppid.t failure have anything to do with it, or is it
unrelated?

On Apr 9, 2012, at 9​:53 PM, George Greer wrote​:

Smoke logs available at http​://m-l.org/~perl/smoke/perl/

Automated smoke report for 5.15.9 patch
66dd4310c0fc5d85e51003ee57996343616e1253 v5.15.9-124-g66dd431
zwei​: Intel(R) Core(TM) i7 CPU 920 @​ 2.67GHz (GenuineIntel 2668MHz)
(x86_64/8 cpu)
on linux - 3.0.0-17-generic [debian]
using clang version 4.2.1 Compatible Clang Compiler
smoketime 57 minutes 42 seconds (average 14 minutes 26 seconds)

Summary​: FAIL(F)

O = OK F = Failure(s), extended report at the bottom
X = Failure(s) under TEST but not under harness
? = still running or test results not (yet) available
Build failures during​: - = unknown or N/A
c = Configure, m = make, M = make (after miniperl), t = make test-prep

v5.15.9-124-g66dd431 Configuration (common) -A -Dcc=clang
append​:ccflags=" -fcatch-undefined-behavior -DPERL_POISON "
----------- ---------------------------------------------------------
O O O O
O O F O -Duseithreads
| +--------- -DDEBUGGING
+----------- no debugging

Locally applied patches​:
uncommitted-changes
SMOKE66dd4310c0fc5d85e51003ee57996343616e1253

Testsuite was run only with 'harness'

Failures​: (common-args) -A -Dcc=clang append​:ccflags="
-fcatch-undefined-behavior -DPERL_POISON "
[default] -DDEBUGGING -Duseithreads
../t/op/getppid.t...........................................FAILED
6-7

--

Father Chrysostomos

@p5pRT
Copy link
Author

p5pRT commented Apr 10, 2012

From @bulk88

On Mon Apr 09 18​:18​:56 2012, sprout wrote​:

On Sun Apr 08 15​:28​:23 2012, bulk88 wrote​:

At

http​://perl5.git.perl.org/perl.git/blob/03d9f026ae253e9e69212a3cf6f1944437e9f070​:/sv.c#l13284

in 5.12, curpad and compad get set to non-poison/garbage pointers.
In
5.15 PAD_CLONE_VARS (

http​://perl5.git.perl.org/perl.git/blob/03d9f026ae253e9e69212a3cf6f1944437e9f070​:/pad.h#l339

) sets from poison/garbage to null pointers.

That may be the problem.

What happens if you apply the attached patch? This is a bit of a stab
in the dark, as I don’t understand in detail how PL_comppad is used.

I haven't tested your fix. compad becomes the pad in win32_start_child.
It can't be null, it will fail the asset/crash in pad_sv. pad_sv is used
here
http​://perl5.git.perl.org/perl.git/blob/HEAD​:/win32/perlhost.h#l1726 on
entry to child thread, inside the "dTARGET;". pad_sv asserts/crashes on
null pad. Contents of comppad are set by PAD_CLONE_VARS " PL_comppad
= MUTABLE_AV(ptr_table_fetch(PL_ptr_table, proto_perl->Icomppad));" Here
is a piece of macro expanded 5.15.9 pad_sv func, DEBUGGING is on.
___________________________________________
SV *
Perl_pad_sv (PerlInterpreter * my_perl, PADOFFSET po)
{
  extern int Perl___notused (void);
  ;
  if (!(my_perl->Icomppad)
  ||
  ((((my_perl->Icomppad))->sv_u.svu_array) != (my_perl->Icurpad)))
  Perl_croak (my_perl, "panic​: invalid pad in %s​: 0x%" "lx" "[0x%"
"lx" "]", "pad_sv",
  (UV) ((my_perl->Icomppad)), (UV) ((my_perl->Icurpad)));;
____________________________________________
beginning of win32_start_child, DEBUGGING on (not sure if it means
anything here)
_____________________________________________
static DWORD __stdcall
win32_start_child(LPVOID arg)
{
  PerlInterpreter *my_perl = (PerlInterpreter*)arg;
  int status;
  HWND parent_message_hwnd;

  Perl_set_context(my_perl);
  win32_checkTLS(my_perl);

  ((my_perl->Isys_intern).pseudo_id) = GetCurrentThreadId();
#line 1713 "c​:\\perl-5.15.9\\win32\\perlhost.h"
  /* create message window and tell parent about it */
  parent_message_hwnd = ((my_perl->Isys_intern).message_hwnd);
  ((my_perl->Isys_intern).message_hwnd) = win32_create_message_window();
  if (parent_message_hwnd != 0)
  PostMessageA(parent_message_hwnd, ((0x0400+30)),
((my_perl->Isys_intern).pseudo_id),
(LPARAM)((my_perl->Isys_intern).message_hwnd));

  /* push a zero on the stack (we are the child) */
  {
  SV **sp = (my_perl->Istack_sp);
  SV * targ = Perl_pad_sv(my_perl, (my_perl->Iop)->op_targ);
  do { Perl_sv_setiv(my_perl, targ,(IV)(0)); do { do { if
(((targ)->sv_flags & 0x00400000)) Perl_mg_set(my_perl, targ); } while
(0); (*++sp = (targ)); } while (0); } while (0);
  (my_perl->Istack_sp) = sp;
  }

  /* continue from next op */
  (my_perl->Iop) = (my_perl->Iop)->op_next;
_________________________________________________
croak can't report the actual error ("invalid pad") that since there is
no scope to jump back to in this child interp, and croak instead dies
with "top_env".

The reason why compad is null/not found in pointer table is because
compcv was null when cv_dup aka sv_dup was called on it, read above
again, ill try to rephrase it here again,

In 5.12, the line that triggered the cloning is
http​://perl5.git.perl.org/perl.git/blob/03d9f026ae253e9e69212a3cf6f1944437e9f070​:/sv.c#l13282
" PL_compcv = cv_dup(proto_perl->Icompcv, param);".
___________________________________________________
SV *
Perl_sv_dup(pTHX_ const SV *sstr, CLONE_PARAMS* param)
{
  dVAR;
  SV *dstr;

  PERL_ARGS_ASSERT_SV_DUP;

  if (!sstr)
  return NULL;
____________________________________________________
Now me comparing 5.12 to 5.15, and me assuming 5.12's design is "right"
and 5.15's design is "wrong", might be a red herring here, but its the
only way I can discuss anything here since I an not an interp person.

If compcv is null, sv_dup does nothing, so comppad wont be added to the
pointer table, I believe this is true for 5.15 and 5.12. In perl 5.12,
the pad is duped and will be added to the pointer table by PAD_DUP macro
in sv_dup when sv_dup is done on a CV, here
http​://perl5.git.perl.org/perl.git/blob/e42956688f2e0df936f1a42811962946e4e185bf​:/sv.c#l11329
(this link isn't 5.12), in 5.15 this line doesn't exit anymore (PAD_DUP
replaced with a func), functionality is still there I think. I didn't
test this with a debugger for my guess about 5.15 that sv_dup dupes the
pad when sv_dup gets a CV.

I will try to run the patch sometime in the next day or 2 and i'll give
an update.

@p5pRT
Copy link
Author

p5pRT commented Apr 10, 2012

From @iabyn

On Mon, Apr 09, 2012 at 06​:18​:57PM -0700, Father Chrysostomos via RT wrote​:

What happens if you apply the attached patch? This is a bit of a stab
in the dark, as I don’t understand in detail how PL_comppad is used.
- PL_comppad = MUTABLE_AV(ptr_table_fetch(PL_ptr_table, proto_perl->Icomppad)); \
+ PL_comppad = av_dup(proto_perl->Icomppad, param); \

I don't think that's the most correct fix. The intention is that whatever
is the currently executing CV should be cloned, and as a side-effect, its
pad gets cloned. The PL_comppad code is then just updating the pointer on
the assumption that someone else should already have cloned the CV.
In the past, this worked because PL_compcv (which only has compile-time
meaning) just happened to get left-over pointing at the currently
executing eval CV.

I suspect the correct fix is to ensure the current CV is always cloned;
possibly by making sure blk_eval.cv is cloned within the CXt_EVAL branch
of Perl_cx_dup, then after this line​:
  PL_curstackinfo = si_dup(proto_perl->Icurstackinfo, param);
repeating the PAD_CLONE_VARS to ensure that PL_comppad gets updated?

Do you want to run with this, or should I?

--
But Pity stayed his hand. "It's a pity I've run out of bullets",
he thought. -- "Bored of the Rings"

@p5pRT
Copy link
Author

p5pRT commented Apr 10, 2012

From @cpansprout

On Tue Apr 10 04​:30​:45 2012, davem wrote​:

On Mon, Apr 09, 2012 at 06​:18​:57PM -0700, Father Chrysostomos via RT
wrote​:

What happens if you apply the attached patch? This is a bit of a
stab
in the dark, as I don’t understand in detail how PL_comppad is used.
- PL_comppad = MUTABLE_AV(ptr_table_fetch(PL_ptr_table,
proto_perl->Icomppad)); \
+ PL_comppad = av_dup(proto_perl->Icomppad, param); \

I don't think that's the most correct fix. The intention is that
whatever
is the currently executing CV should be cloned, and as a side-effect,
its
pad gets cloned. The PL_comppad code is then just updating the pointer
on
the assumption that someone else should already have cloned the CV.
In the past, this worked because PL_compcv (which only has compile-
time
meaning) just happened to get left-over pointing at the currently
executing eval CV.

I suspect the correct fix is to ensure the current CV is always
cloned;
possibly by making sure blk_eval.cv is cloned within the CXt_EVAL
branch
of Perl_cx_dup, then after this line​:
PL_curstackinfo = si_dup(proto_perl->Icurstackinfo, param);
repeating the PAD_CLONE_VARS to ensure that PL_comppad gets updated?

Do you want to run with this, or should I?

If you are offering to take over, please go ahead. :-)

I need to ask the Windows users​: Does perl -efork crash?

If it doesn’t, can you (Dave Mitchell) explain why not?

--

Father Chrysostomos

@p5pRT
Copy link
Author

p5pRT commented Apr 10, 2012

From @cpansprout

On Tue Apr 10 03​:55​:30 2012, bulk88 wrote​:

The reason why compad is null/not found in pointer table is because
compcv was null when cv_dup aka sv_dup was called on it, read above
again, ill try to rephrase it here again,

I understood that. I realise I may have been a bit terse.

In 5.12, the line that triggered the cloning is

http​://perl5.git.perl.org/perl.git/blob/03d9f026ae253e9e69212a3cf6f1944437e9f070​:/sv.c#l13282

" PL_compcv = cv_dup(proto_perl->Icompcv, param);".
___________________________________________________
SV *
Perl_sv_dup(pTHX_ const SV *sstr, CLONE_PARAMS* param)
{
dVAR;
SV *dstr;

PERL\_ARGS\_ASSERT\_SV\_DUP;

if \(\!sstr\)
return NULL;

____________________________________________________
Now me comparing 5.12 to 5.15, and me assuming 5.12's design is
"right"
and 5.15's design is "wrong", might be a red herring here, but its the
only way I can discuss anything here since I an not an interp person.

If compcv is null, sv_dup does nothing, so comppad wont be added to
the
pointer table, I believe this is true for 5.15 and 5.12. In perl 5.12,
the pad is duped and will be added to the pointer table by PAD_DUP
macro
in sv_dup when sv_dup is done on a CV, here

http​://perl5.git.perl.org/perl.git/blob/e42956688f2e0df936f1a42811962946e4e185bf​:/sv.c#l11329

(this link isn't 5.12), in 5.15 this line doesn't exit anymore
(PAD_DUP
replaced with a func), functionality is still there I think. I didn't
test this with a debugger for my guess about 5.15 that sv_dup dupes
the
pad when sv_dup gets a CV.

What I was trying to say is that PL_compcv is *supposed* to be null in
that case.

The code for setting PL_comppad in the child thread was making untenable
assumptions and hence needs to be rewritten.

--

Father Chrysostomos

@p5pRT
Copy link
Author

p5pRT commented Apr 10, 2012

From @greerga

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

On Mon Apr 09 20​:38​:49 2012, sprout wrote​:

On Mon Apr 09 19​:59​:06 2012, jdb wrote​:

On Mon, 09 Apr 2012, Father Chrysostomos via RT wrote​:

What happens if you apply the attached patch? This is a bit of a stab
in the dark, as I don?t understand in detail how PL_comppad is used.

Excellent, this does indeed fix the crashes!

I?ve pushed it to the smoke-me/109718 branch. Let?s see what the
smokers make of it.

Could this getppid.t failure have anything to do with it, or is it
unrelated?

Probably unrelated as I've seen it before. It's like the tie deepcopy
test failure​: rare and probably related to either "make -j" or TEST_JOBS=8
or the load caused by either or both prior. The test assumes a "sleep 2"
is sufficient to get reparented from a parent that does "sleep 1; exit".

--
George Greer

@p5pRT
Copy link
Author

p5pRT commented Apr 10, 2012

From @iabyn

On Tue, Apr 10, 2012 at 06​:04​:36AM -0700, Father Chrysostomos via RT wrote​:

On Tue Apr 10 04​:30​:45 2012, davem wrote​:

I suspect the correct fix is to ensure the current CV is always
cloned;
possibly by making sure blk_eval.cv is cloned within the CXt_EVAL
branch
of Perl_cx_dup, then after this line​:
PL_curstackinfo = si_dup(proto_perl->Icurstackinfo, param);
repeating the PAD_CLONE_VARS to ensure that PL_comppad gets updated?

Do you want to run with this, or should I?

If you are offering to take over, please go ahead. :-)

Whoops, that was silly of me :-)

I need to ask the Windows users​: Does perl -efork crash?

If it doesn’t, can you (Dave Mitchell) explain why not?

Because then the currently executing sub is PL_main_cv which is
explicitly cloned beforehand, so the pad gets cloned. Similarly for any sub
which is reachable from PL_defstash.

--
"Emacs isn't a bad OS once you get used to it.
It just lacks a decent editor."

@p5pRT
Copy link
Author

p5pRT commented Apr 10, 2012

From @iabyn

On Tue, Apr 10, 2012 at 12​:21​:30PM +0100, Dave Mitchell wrote​:

On Mon, Apr 09, 2012 at 06​:18​:57PM -0700, Father Chrysostomos via RT wrote​:

What happens if you apply the attached patch? This is a bit of a stab
in the dark, as I don’t understand in detail how PL_comppad is used.
- PL_comppad = MUTABLE_AV(ptr_table_fetch(PL_ptr_table, proto_perl->Icomppad)); \
+ PL_comppad = av_dup(proto_perl->Icomppad, param); \

I don't think that's the most correct fix. The intention is that whatever
is the currently executing CV should be cloned, and as a side-effect, its
pad gets cloned. The PL_comppad code is then just updating the pointer on
the assumption that someone else should already have cloned the CV.
In the past, this worked because PL_compcv (which only has compile-time
meaning) just happened to get left-over pointing at the currently
executing eval CV.

I suspect the correct fix is to ensure the current CV is always cloned;
possibly by making sure blk_eval.cv is cloned within the CXt_EVAL branch
of Perl_cx_dup, then after this line​:
PL_curstackinfo = si_dup(proto_perl->Icurstackinfo, param);

Actually, I misread a bit of code in cx_dup(); the CV *is* duplicated in
the CXt_EVAL branch; which means I think your fix *is* safe and complete;
it dups the pad, then later on the parent CV is also duped, and pick up
the already-duped pad. So do please continue with it.

--
More than any other time in history, mankind faces a crossroads. One path
leads to despair and utter hopelessness. The other, to total extinction.
Let us pray we have the wisdom to choose correctly.
  -- Woody Allen

@p5pRT
Copy link
Author

p5pRT commented Apr 10, 2012

From @bulk88

The av_dup patch worked for me. The getppid test isn't done on windows.
I have no other comments.

@p5pRT
Copy link
Author

p5pRT commented Apr 10, 2012

From @cpansprout

On Tue Apr 10 07​:08​:11 2012, davem wrote​:

On Tue, Apr 10, 2012 at 12​:21​:30PM +0100, Dave Mitchell wrote​:
Actually, I misread a bit of code in cx_dup(); the CV *is* duplicated
in
the CXt_EVAL branch; which means I think your fix *is* safe and
complete;
it dups the pad, then later on the parent CV is also duped, and pick
up
the already-duped pad. So do please continue with it.

I’ve applied it as 253649d.

--

Father Chrysostomos

@p5pRT
Copy link
Author

p5pRT commented Apr 10, 2012

@cpansprout - Status changed from 'open' to 'resolved'

@p5pRT p5pRT closed this as completed Apr 10, 2012
@p5pRT
Copy link
Author

p5pRT commented Apr 11, 2012

From @cpansprout

This ticket might not be completely resolved yet.

In <612945.556640625-sendEmail@​hpwin7>, Steve Hay’s smoke report says​:

Failures​: (common-args) -DCCTYPE=MSVC100
[default] -Duseithreads -Duselargefiles
[default] -DDEBUGGING -Duseithreads -Duselargefiles
./t/op/fork.t..............................................FAILED
  24

Steve, are you able to find out when this particular failure started? I
don’t see this from any other Windows smokers.

--

Father Chrysostomos

@p5pRT
Copy link
Author

p5pRT commented Apr 11, 2012

From @steve-m-hay

On 11 April 2012 22​:11, Father Chrysostomos via RT
<perlbug-followup@​perl.org> wrote​:

This ticket might not be completely resolved yet.

In <612945.556640625-sendEmail@​hpwin7>, Steve Hay’s smoke report says​:

Failures​: (common-args) -DCCTYPE=MSVC100
[default] -Duseithreads -Duselargefiles
[default] -DDEBUGGING -Duseithreads -Duselargefiles
./t/op/fork.t..............................................FAILED
   24

Steve, are you able to find out when this particular failure started?  I
don’t see this from any other Windows smokers.

Not easily. I've only recently restarted smoking again after a long
hiatus, and fork.t has been failing for the whole month or so that
I've been doing it now.

I do notice that smokes from me before the one above were failing
tests 16 and 24, but now only 24 has failed. Time will tell if that
was just a one-off, but I think you've fixed one problem because I
found the test 16 failure to be a consistent crash, whereas the
remaining test 24 failure is intermittent and sometimes hangs too...

In the absence of much recent smoke history on this machine, I have
already been trying to bisect to find where this started (and likewise
with another issue that I posted about recently with various tests
hanging whenever I run the test suite manually without STDERR
redirected to a log file(!)) but haven't yet had any joy with either.

@p5pRT
Copy link
Author

p5pRT commented Apr 12, 2012

From @kmx

FYI​: here is how goes ./t/op/fork.t on Windows 7 + gcc-4.4.7/32bit - tested
on 2653c1e

op/fork.t ......................................................... 23/? PROG​:
# Windows 7​: https://rt.cpan.org/Ticket/Display.html?id=66016#txn-908976
system $^X, "-e", "if (\$pid=fork){kill(9, \$pid)} else {sleep 5}";
print $?>>8, "\n";
EXPECTED​:
0
GOT​:
9
# Failed test 24 - at ./test.pl line 1079
op/fork.t ......................................................... Failed
1/25 subtests

No crash, just the one failure (which AFAIK exists some time and is related
to other RT)

--
kmx

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

1 participant