Smoke [blead] v5.17.5-531-g388a574 FAIL(F) MSWin32 Win2000 SP4 (x86/1 cpu)

[George Greer]

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

Note: Due to a quirk of the virtual machine, build failures are generally
because of timing issues on the VM rather than Perl problems, unless all
of the grid says "M".

Automated smoke report for 5.17.6 patch 388a574e2ce769493876ee1389dd11718da585c7 v5.17.5-531-g388a574
perl-win2k: Intel(R) Core(TM) i7 CPU 920 @ 2.67GHz(~2661 MHz) (x86/1 cpu)
on MSWin32 - Win2000 SP4
using cl version 14.00.50727.762
smoketime 3 hours 21 minutes (average 50 minutes 29 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.17.5-531-g388a574 Configuration (common) none
----------- ---------------------------------------------------------
O O
F F -Duseithreads
| +--------- -DDEBUGGING
+----------- no debugging


Locally applied patches:
uncommitted-changes
SMOKE388a574e2ce769493876ee1389dd11718da585c7

Failures: (common-args) none
[default] -Duseithreads
../dist/IO/t/io_multihomed.t................................FAILED
../dist/IO/t/io_sock.t......................................FAILED
Non-zero exit status: 5

[default] -DDEBUGGING -Duseithreads
../dist/IO/t/io_multihomed.t................................FAILED
../dist/IO/t/io_sock.t......................................FAILED
Non-zero exit status: 9

Compiler messages(MSWin32):
..\mg.c(681) : warning C4646: function declared with __declspec(noreturn) has non-void return type
..\mg.c(686) : warning C4645: function declared with __declspec(noreturn) has a return statement
op.c(7325) : warning C4244: 'initializing' : conversion from 'U32' to 'const char', possible loss of data
op.c(11726) : warning C4028: formal parameter 1 different from declaration
..\pp.c(5874) : warning C4244: 'function' : conversion from 'U32' to 'const char', possible loss of data
..\pp_hot.c(2745) : warning C4244: 'initializing' : conversion from 'I32' to 'U8', possible loss of data
..\pp_sort.c(1668) : warning C4244: 'initializing' : conversion from 'I32' to 'U8', possible loss of data
..\regcomp.c(6253) : warning C4244: 'function' : conversion from 'I32' to 'char', possible loss of data
..\regcomp.c(6254) : warning C4244: 'function' : conversion from 'I32' to 'char', possible loss of data
..\regcomp.c(6278) : warning C4244: 'function' : conversion from 'I32' to 'char', possible loss of data
..\regcomp.c(6279) : warning C4244: 'function' : conversion from 'I32' to 'char', possible loss of data
..\regcomp.c(10904) : warning C4244: '=' : conversion from 'UV' to 'char', possible loss of data
..\regcomp.c(12533) : warning C4244: '=' : conversion from 'IV' to 'U8', possible loss of data
..\regexec.c(4800) : warning C4244: 'initializing' : conversion from 'I32' to 'U8', possible loss of data
..\regexec.c(4803) : warning C4244: 'initializing' : conversion from 'I32' to 'U8', possible loss of data
..\toke.c(765) : warning C4244: '=' : conversion from 'U32' to 'U8', possible loss of data
..\util.c(2192) : warning C4244: '=' : conversion from 'long' to 'char', possible loss of data
..\util.c(2193) : warning C4244: '=' : conversion from 'long' to 'char', possible loss of data
..\util.c(2194) : warning C4244: '=' : conversion from 'long' to 'char', possible loss of data
..\util.c(2195) : warning C4244: '=' : conversion from 'long' to 'char', possible loss of data
..\util.c(2221) : warning C4244: '=' : conversion from 'long' to 'char', possible loss of data
..\util.c(2222) : warning C4244: '=' : conversion from 'long' to 'char', possible loss of data
..\util.c(2223) : warning C4244: '=' : conversion from 'long' to 'char', possible loss of data
..\util.c(2224) : warning C4244: '=' : conversion from 'long' to 'char', possible loss of data
B.xs(998) : warning C4101: 'len' : unreferenced local variable
B.xs(1936) : warning C4018: '<=' : signed/unsigned mismatch
B.xs(1946) : warning C4018: '<=' : signed/unsigned mismatch
IO.xs(493) : warning C4101: 'ret' : unreferenced local variable
ListUtil.xs(249) : warning C4244: 'initializing' : conversion from 'I32' to 'U8', possible loss of data
ListUtil.xs(297) : warning C4244: 'initializing' : conversion from 'I32' to 'U8', possible loss of data
Base64.xs(394) : warning C4146: unary minus operator applied to unsigned type, result still unsigned
Base64.xs(396) : warning C4146: unary minus operator applied to unsigned type, result still unsigned
POSIX.xs(707) : warning C4101: 'charstring' : unreferenced local variable
scalar.xs(175) : warning C4018: '>' : signed/unsigned mismatch
Storable.xs(4902) : warning C4101: 'mg' : unreferenced local variable
Storable.xs(4934) : warning C4101: 'mg' : unreferenced local variable
Piece.xs(950) : warning C4101: 'ret' : unreferenced local variable
APItest.xs(3070) : warning C4244: 'initializing' : conversion from 'I32' to 'U8', possible loss of data
APItest.xs(3469) : warning C4101: 'tmp' : unreferenced local variable
re_exec.c(4800) : warning C4244: 'initializing' : conversion from 'I32' to 'U8', possible loss of data
re_exec.c(4803) : warning C4244: 'initializing' : conversion from 'I32' to 'U8', possible loss of data
re_comp.c(6253) : warning C4244: 'function' : conversion from 'I32' to 'char', possible loss of data
re_comp.c(6254) : warning C4244: 'function' : conversion from 'I32' to 'char', possible loss of data
re_comp.c(6278) : warning C4244: 'function' : conversion from 'I32' to 'char', possible loss of data
re_comp.c(6279) : warning C4244: 'function' : conversion from 'I32' to 'char', possible loss of data
re_comp.c(10904) : warning C4244: '=' : conversion from 'UV' to 'char', possible loss of data
re_comp.c(12533) : warning C4244: '=' : conversion from 'IV' to 'U8', possible loss of data
op.c(11726) : warning C4028: formal parameter 2 different from declaration

--
Report by Test::Smoke v1.42 build 1267 running on perl 5.10.0
(Reporter v0.035 / Smoker v0.045)

[bulk 88]

> CC: perl5-...@perl.org
> Subject: Smoke [blead] v5.17.5-531-g388a574 FAIL(F) MSWin32 Win2000 SP4 (x86/1 cpu)
> Date: Sun, 18 Nov 2012 20:36:00 -0500
> To: smokers...@perl.org
> From: pe...@greerga.m-l.org

Reproduced. Investigating.

[bulk88]

Got a crash in t/io_sock.t. 2 OS threads in the process. First one, non crashed.
_______________________________________________________________
     ntdll.dll!_KiFastSystemCallRet@0()    
     ntdll.dll!_ZwWaitForMultipleObjects@20()  + 0xc   
     kernel32.dll!_WaitForMultipleObjectsEx@20()  - 0x48   
     kernel32.dll!_WaitForMultipleObjects@16()  + 0x18   
     perl517.dll!win32_wait_for_children(interpreter * my_perl=0x7ffde000)  Line 1225    C
     perl517.dll!perl_destruct(interpreter * my_perl=0x0034464c)  Line 537    C
     perl517.dll!RunPerl(int argc=0x00000004, char * * argv=0x01342cf0, char * * env=0x003432a0)  Line 275    C
     perl.exe!mainCRTStartup()  Line 398 + 0xe    C
     kernel32.dll!_BaseProcessStart@4()  + 0x23   

_________________________________________________________________
Looks ok. Its curcop pointer is null.

Next OS thread.
_________________________________________________________________
>    perl517.dll!VMem::Free()  Line 202    C
     perl517.dll!Perl_safesysfree(void * where=0x00bcaf24)  Line 276 + 0xe    C
     perl517.dll!PerlIO_pop(interpreter * my_perl=0x00bab524, _PerlIO * * f=0x008f4f8c)  Line 759 + 0x8    C
     perl517.dll!Perl_PerlIO_close(interpreter * my_perl=0x00bab524, _PerlIO * * f=0x008f4f8c)  Line 1481    C
     perl517.dll!Perl_io_close(interpreter * my_perl=0x008f4f8c, io * io=0x00070023, char not_implicit=0x00)  Line 976 + 0xb    C
     perl517.dll!Perl_sv_clear(interpreter * my_perl=0x00bab524, sv * const orig_sv=0x00aafdac)  Line 6054 + 0xa    C
     perl517.dll!Perl_sv_free2(interpreter * my_perl=0x00bab524, sv * const sv=0x00aafdac)  Line 6506    C
     perl517.dll!S_SvREFCNT_dec(interpreter * my_perl=0x00bab524, sv * sv=0x00aafdac)  Line 61    C
     perl517.dll!do_clean_named_io_objs(interpreter * my_perl=0x00bab524, sv * const sv=0x00aafd7c)  Line 551 + 0x7    C
     perl517.dll!Perl_sv_clean_objs(interpreter * my_perl=0x008f4f8c)  Line 591 + 0x7    C
     perl517.dll!perl_destruct(interpreter * my_perl=0x00bab524)  Line 772    C
     perl517.dll!win32_start_child(void * arg=0x00bab524)  Line 1796    C
     kernel32.dll!_BaseThreadStart@8()  + 0x37   
_________________________________________________________________
crashed at
____________________________________________________________________
void VMem::Free(void* pMem)
{
#ifdef _USE_LINKED_LIST
    if (pMem) {
    PMEMORY_BLOCK_HEADER ptr = (PMEMORY_BLOCK_HEADER)(((char*)pMem)-sizeof(MEMORY_BLOCK_HEADER));
        if (ptr->owner != this) {
        if (ptr->owner) {
#if 1
            int *nowhere = NULL;
            Perl_warn_nocontext("Free to wrong pool %p not %p",this,ptr->owner);
                *nowhere = 0; /* this segfault is deliberate, <<<<<<<<<<<<<<<<<<<<<<<<<<
                                 so you can see the stack trace */
#else
                ptr->owner->Free(pMem);   
#endif
        }
        return;
        }
    GetLock();
    UnlinkBlock(ptr);
    ptr->owner = NULL;
    free(ptr);
    FreeLock();
    }
#else /*_USE_LINKED_LIST*/
    free(pMem);
#endif
}
____________________________________________________________________
Curcop for 2nd thread says  "t/io_sock.t", line 0. Probably invalid. The console for the test says
____________________________________________________________________
C:\p517\perl\t>..\perl.exe -I..\lib harness ../dist/IO/t/io_sock.t
../dist/IO/t/io_sock.t .. 1/26 Use of uninitialized value $self in scalar derefe
rence at ../../lib/SelectSaver.pm line 51.
Use of uninitialized value in ref-to-glob cast at ../../lib/SelectSaver.pm line
51.
        (in cleanup) Bad symbol for filehandle at ../../lib/SelectSaver.pm line
51.
Use of uninitialized value $self in scalar dereference at ../../lib/SelectSaver.
pm line 51.
Use of uninitialized value in ref-to-glob cast at ../../lib/SelectSaver.pm line
51.
        (in cleanup) Bad symbol for filehandle at ../../lib/SelectSaver.pm line
51.
Use of uninitialized value $self in scalar dereference at ../../lib/SelectSaver.
pm line 51.
Use of uninitialized value in ref-to-glob cast at ../../lib/SelectSaver.pm line
51.
        (in cleanup) Bad symbol for filehandle at ../../lib/SelectSaver.pm line
51.
../dist/IO/t/io_sock.t .. 8/26 Use of uninitialized value $self in scalar derefe
rence at ../../lib/SelectSaver.pm line 51.
Use of uninitialized value in ref-to-glob cast at ../../lib/SelectSaver.pm line
51.
        (in cleanup) Bad symbol for filehandle at ../../lib/SelectSaver.pm line
51.
../dist/IO/t/io_sock.t .. 10/26 Use of uninitialized value $self in scalar deref
erence at ../../lib/SelectSaver.pm line 51.
Use of uninitialized value in ref-to-glob cast at ../../lib/SelectSaver.pm line
51.
        (in cleanup) Bad symbol for filehandle at ../../lib/SelectSaver.pm line
51.
../dist/IO/t/io_sock.t .. 11/26 Use of uninitialized value $self in scalar deref
erence at ../../lib/SelectSaver.pm line 51.
Use of uninitialized value in ref-to-glob cast at ../../lib/SelectSaver.pm line
51.
        (in cleanup) Bad symbol for filehandle at ../../lib/SelectSaver.pm line
51.
Use of uninitialized value $self in scalar dereference at ../../lib/SelectSaver.
pm line 51, <GEN9> line 4.
Use of uninitialized value in ref-to-glob cast at ../../lib/SelectSaver.pm line
51, <GEN9> line 4.
        (in cleanup) Bad symbol for filehandle at ../../lib/SelectSaver.pm line
51, <GEN9> line 4.
______________________________________________________________

multihomed.t
______________________________________________________________
C:\p517\perl\t>..\perl.exe -I..\lib harness -v ../dist/IO/t/io_multihomed.t
../dist/IO/t/io_multihomed.t ..
1..8
ok 1
ok 5
ok 6
ok 8
# Test process timed out - terminating
Failed 4/8 subtests

Test Summary Report
-------------------
../dist/IO/t/io_multihomed.t (Wstat: 0 Tests: 4 Failed: 0)
  Parse errors: Tests out of sequence.  Found (5) but expected (2)
                Tests out of sequence.  Found (6) but expected (3)
                Tests out of sequence.  Found (8) but expected (4)
                Bad plan.  You planned 8 tests but ran 4.
Files=1, Tests=4, 15 wallclock secs ( 0.01 usr +  0.02 sys =  0.03 CPU)
Result: FAIL

C:\p517\perl\t>
_____________________________________________________________
No OS exception popup (AKA crash). (egh, you never know if its being trapped somewhere).
_____________________________________________________________
C:\p517\perl>perl -V
Summary of my perl5 (revision 5 version 17 subversion 6 patch blead 2012-11-18.2
3:41:32 c25879556450ce505da635587b26749395569e08 v5.17.5-532-gc258795) configura
tion:
  Snapshot of: c25879556450ce505da635587b26749395569e08
  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 -MD -Zi -DNDEBUG -O1  -GL -G7 -arch:SSE2
-DWIN32 -D_CONSOLE -DNO_STRICT  -DPERL_TEXTMODE_SCRIPTS -DPERL_IMPLICIT_CONTEXT
-DPERL_IMPLICIT_SYS -DUSE_PERLIO -D_USE_32BIT_TIME_T',
    optimize='-MD -Zi -DNDEBUG -O1  -GL -G7 -arch:SSE2',
    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 -ltcg  -libpa
th:"c:\perl517\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=perl517.lib
    gnulibc_version=''
  Dynamic Linking:
    dlsrc=dl_win32.xs, dlext=dll, d_dlsymun=undef, ccdlflags=' '
    cccdlflags=' ', lddlflags='-dll -nologo -nodefaultlib -debug -opt:ref,icf -l
tcg  -libpath:"c:\perl517\lib\CORE"  -machine:x86'


Characteristics of this binary (from libperl):
  Compile-time options: HAS_TIMES HAVE_INTERP_INTERN MULTIPLICITY
                        PERLIO_LAYERS PERL_DONT_CREATE_GVSV
                        PERL_IMPLICIT_CONTEXT PERL_IMPLICIT_SYS
                        PERL_MALLOC_WRAP PERL_PRESERVE_IVUV 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 Nov 18 2012 21:44:22
  @INC:
    C:/p517/perl/lib
    .

C:\p517\perl>
_______________________________________________________
Line numbers should be correct with the git commit mentioned above. I won't be researching what commit started the failures at the moment. Done for today.

[bulk88]

resending to Perl RT, from ML

[bulk88 via RT]

http://www.nntp.perl.org/group/perl.daily-build.reports/2012/11/msg131790.html
10ff failed, 7dc8 didn't,
http://www.nntp.perl.org/group/perl.daily-build.reports/2012/11/msg131780.html
.
41 hours ago
Father Chrysostomos Increase $XS::APItest::VERSION to 0.45 [FAILED]
41 hours ago
Daniel Dragan refactor pp_rand
41 hours ago
Father Chrysostomos [perl #115756] Fix XS::APItest::SvIsCOW
41 hours ago
Father Chrysostomos 8c34e50dc slowed down detruction with no DESTROY
44 hours ago
Yves Orton Hash Function Change - Murmur hash and true per process...
[OKAY]

The perl used to make the callstacks in the previous post was O1
compiled so the args are invalid, if someone wants a callstack with
correct args ask me.

I reverted
http://perl5.git.perl.org/perl.git/commit/7cc6787e9dbebdd83799d997361188ab6dfe8ead
and the 2 tests passed.
___________________________________________________________________
C:\p517\perl\t>perl.exe -I..\lib harness -v ../dist/IO/t/io_multihomed.t

../dist/IO/t/io_multihomed.t ..
1..8
ok 1

ok 2
ok 3
ok 4
ok 5
ok 6
ok 7

ok 8
# Test process timed out - terminating

ok
All tests successful.
Files=1, Tests=8, 15 wallclock secs ( 0.05 usr + 0.00 sys = 0.05 CPU)
Result: PASS

C:\p517\perl\t>perl.exe -I..\lib harness -v ../dist/IO/t/io_sock.t
../dist/IO/t/io_sock.t ..
1..26
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
ok 26
ok
All tests successful.
Files=1, Tests=26, 19 wallclock secs ( 0.00 usr + 0.03 sys = 0.03 CPU)
Result: PASS

C:\p517\perl\t>perl.exe -I..\lib harness -v ../dist/IO/t/io_sock.t
________________________________________________________________



---
via perlbug: queue: perl5 status: new
https://rt.perl.org:443/rt3/Ticket/Display.html?id=115830

[Father Chrysostomos via RT]

On Mon Nov 19 07:53:53 2012, bulk88 wrote:
> http://www.nntp.perl.org/group/perl.daily-

> build.reports/2012/11/msg131790.html
> 10ff failed, 7dc8 didn't,
> http://www.nntp.perl.org/group/perl.daily-
> build.reports/2012/11/msg131780.html
> .
> 41 hours ago
> Father Chrysostomos Increase $XS::APItest::VERSION to 0.45 [FAILED]
> 41 hours ago
> Daniel Dragan refactor pp_rand
> 41 hours ago
> Father Chrysostomos [perl #115756] Fix XS::APItest::SvIsCOW
> 41 hours ago
> Father Chrysostomos 8c34e50dc slowed down detruction with no DESTROY
> 44 hours ago
> Yves Orton Hash Function Change - Murmur hash and true per process...
> [OKAY]
>
> The perl used to make the callstacks in the previous post was O1
> compiled so the args are invalid, if someone wants a callstack with
> correct args ask me.
>
> I reverted
>
http://perl5.git.perl.org/perl.git/commit/7cc6787e9dbebdd83799d997361188ab6dfe8ead

(rjbs: Please don’t release 5.17.6 until this is reverted or we find a
fix. Thank you.)

--

Father Chrysostomos


---
via perlbug: queue: perl5 status: open
https://rt.perl.org:443/rt3/Ticket/Display.html?id=115830

[Father Chrysostomos via RT]

On Mon Nov 19 07:22:18 2012, bulk88 wrote:
> Curcop for 2nd thread says "t/io_sock.t", line 0. Probably invalid. The
> console for the test says
> ____________________________________________________________________
> C:\p517\perl\t>..\perl.exe -I..\lib harness ../dist/IO/t/io_sock.t
> ../dist/IO/t/io_sock.t .. 1/26 Use of uninitialized value $self in
> scalar derefe
> rence at ../../lib/SelectSaver.pm line 51.

That’s lib/SelectSaver.pm’s destructor.

Do you think you could get a C backtrace from that line, including
arguments?

Usually I add ‘study;’ to the perl code and then break on Perl_pp_study.

What is the value of tmpref in sv.c:S_curse in that call?

Can you do Perl_sv_dump(my_perl, tmpref) on it in addition to a debugger
struct dump?

[bulk88 via RT]

On Mon Nov 19 08:50:42 2012, sprout wrote:
> That’s lib/SelectSaver.pm’s destructor.
>
> Do you think you could get a C backtrace from that line, including
> arguments?
>
> Usually I add ‘study;’ to the perl code and then break on Perl_pp_study.

I personally use "system("pause");" from Perl, or DebugBreak() from C.
Then attach a C debugger once the process froze/waits. Both are Win32
specific. I sometimes wish dump() would call DebugBreak() on win32 perl.

>
> What is the value of tmpref in sv.c:S_curse in that call?

How do I reach S_curse? breakpoint it while running the 2 IO tests?

>
> Can you do Perl_sv_dump(my_perl, tmpref) on it in addition to a debugger
> struct dump?
>

_____________________________________________________________
require 5.000;
use Carp;
use Symbol;
use Devel::Peek 'Dump';

sub new {
@_ >= 1 && @_ <= 2 or croak 'usage: SelectSaver->new( [FILEHANDLE] )';
my $fh = select;
my $self = bless \$fh, $_[0];
select qualify($_[1], caller) if @_ > 1;
$self;
}

sub DESTROY {
Dump($_[0]);
my $self = $_[0];
select $$self;
}

1;
_________________________________________________________________

SelectSaver is pure perl. I attached console output of reverted (good)
and unreverted runs. My perl is now in Od so future callstacks should be
correct for this ticket.


--
bulk88 ~ bulk88 at hotmail.com

[bulk88 via RT]

On Mon Nov 19 08:50:42 2012, sprout wrote:

> On Mon Nov 19 07:22:18 2012, bulk88 wrote:
> > Curcop for 2nd thread says "t/io_sock.t", line 0. Probably invalid.
The
> > console for the test says
> > ____________________________________________________________________
> > C:\p517\perl\t>..\perl.exe -I..\lib harness ../dist/IO/t/io_sock.t
> > ../dist/IO/t/io_sock.t .. 1/26 Use of uninitialized value $self in
> > scalar derefe
> > rence at ../../lib/SelectSaver.pm line 51.
>
> That’s lib/SelectSaver.pm’s destructor.
>
> Do you think you could get a C backtrace from that line, including
> arguments?
>
> Usually I add ‘study;’ to the perl code and then break on Perl_pp_study.
>
> What is the value of tmpref in sv.c:S_curse in that call?
>
> Can you do Perl_sv_dump(my_perl, tmpref) on it in addition to a debugger
> struct dump?
>

Adding the Dump in select saver is changing the crash point. On
io_sock.t without Dump, I have 3 threads.
___________________________________________________________
> perl517.dll!VMem::Free(void * pMem=0x00be0024) Line 202 + 0x3 C
perl517.dll!CPerlHost::Free(void * ptr=0x00be0024) Line 67 + 0x19 C
perl517.dll!PerlMemFree(IPerlMem * piPerl=0x00bcecdc, void *
ptr=0x00be0024) Line 310 C
perl517.dll!Perl_safesysfree(void * where=0x00be0024) Line 276 + 0x1a C
perl517.dll!PerlIO_pop(interpreter * my_perl=0x00bb9b0c, _PerlIO * *
f=0x008f4f5c) Line 759 + 0x9 C
perl517.dll!Perl_PerlIO_close(interpreter * my_perl=0x00bb9b0c,
_PerlIO * * f=0x008f4f5c) Line 1480 + 0xd C
perl517.dll!Perl_io_close(interpreter * my_perl=0x00bb9b0c, io *
io=0x00abc0cc, char not_implicit=0x00) Line 976 + 0x12 C
perl517.dll!Perl_sv_clear(interpreter * my_perl=0x00bb9b0c, sv * const
orig_sv=0x00abc0cc) Line 6054 + 0xf C
perl517.dll!Perl_sv_free2(interpreter * my_perl=0x00bb9b0c, sv * const
sv=0x00abc0cc) Line 6505 + 0xd C
perl517.dll!S_SvREFCNT_dec(interpreter * my_perl=0x00bb9b0c, sv *
sv=0x00abc0cc) Line 60 + 0xd C
perl517.dll!do_clean_named_io_objs(interpreter * my_perl=0x00bb9b0c,
sv * const sv=0x00abc13c) Line 551 + 0xd C
perl517.dll!Perl_sv_clean_objs(interpreter * my_perl=0x00bb9b0c) Line
591 + 0xd C
perl517.dll!perl_destruct(interpreter * my_perl=0x00bb9b0c) Line
771 + 0x9 C
perl517.dll!win32_start_child(void * arg=0x00bb9b0c) Line 1795 + 0x9 C
kernel32.dll!_BaseThreadStart@8() + 0x37
_____________________________________________________________
crashed thread, curcop "t/io_sock.t" line 0

next
_____________________________________________________________

ntdll.dll!_KiFastSystemCallRet@0()
ntdll.dll!_ZwWaitForMultipleObjects@20() + 0xc
kernel32.dll!_WaitForMultipleObjectsEx@20() - 0x48
kernel32.dll!_WaitForMultipleObjects@16() + 0x18

> perl517.dll!win32_wait_for_children(interpreter * my_perl=0x00344684)
Line 1225 C
perl517.dll!perl_destruct(interpreter * my_perl=0x00344684) Line
535 + 0x9 C
perl517.dll!RunPerl(int argc=0x00000004, char * * argv=0x00342cf0,
char * * env=0x00345cd8) Line 274 + 0x9 C

perl.exe!mainCRTStartup() Line 398 + 0xe C
kernel32.dll!_BaseProcessStart@4() + 0x23
_____________________________________________________________

next
______________________________________________________________
ntdll.dll!_KiFastSystemCallRet@0()
ntdll.dll!_ZwDeviceIoControlFile@40() + 0xc
mswsock.dll!_WSPSelect@24() - 0x16a
ws2_32.dll!_select@20() + 0xa7
> perl517.dll!win32_select(int nfds=0x00000010, Perl_fd_set *
rd=0x00e0f79c, Perl_fd_set * wr=0x00000000, Perl_fd_set * ex=0x00000000,
const timeval * timeout=0x013dfef4) Line 276 + 0x35 C
perl517.dll!PerlSockSelect(IPerlSock * piPerl=0x00ccd450, int
nfds=0x00000010, char * readfds=0x00e0f79c, char * writefds=0x00000000,
char * exceptfds=0x00000000, const timeval * timeout=0x013dfef4) Line
1395 + 0x19 C
perl517.dll!Perl_pp_sselect(interpreter * my_perl=0x00cfcd64) Line
1200 + 0x30 C
perl517.dll!Perl_runops_standard(interpreter * my_perl=0x00cfcd64)
Line 42 + 0xa C
perl517.dll!win32_start_child(void * arg=0x00cfcd64) Line 1740 + 0xd C
kernel32.dll!_BaseThreadStart@8() + 0x37
____________________________________________________________________
cop_file 0x00b0007c "../../lib/IO/Select.pm" char *
cop_line 111 unsigned long

--
bulk88 ~ bulk88 at hotmail.com

[Jan Dubois]

On Mon, Nov 19, 2012 at 9:27 AM, bulk88 via RT
<perlbug-...@perl.org> wrote:
> I personally use "system("pause");" from Perl, or DebugBreak() from C.
> Then attach a C debugger once the process froze/waits. Both are Win32
> specific. I sometimes wish dump() would call DebugBreak() on win32 perl.

I think this is a good idea. We already do this on Win32 in the "Free
to wrong pool" case
in win32/vmem.h:

int *nowhere = NULL;
Perl_warn_nocontext("Free to wrong pool %p not %p",this,ptr->owner);
*nowhere = 0; /* this segfault is deliberate,
so you can see the stack trace */

When you have just-in-time debugging configured (AeDebug), this will
pop up the dialog that lets you start and attach that debugger
automatically. I guess DebugBreak() is somewhat more obvious in its
intend. so maybe vmem.h should be changed to match. Alternatively, I'm
fine with adding Win32::DebugBreak() to the Win32 module; it already
has Win32::OutputDebugString().

Cheers,
-Jan

[bulk88 via RT]

Adding the Dump to select saver, for io_sock.t caused a different crash
____________________________________________________________________
> perl517.dll!Perl_pad_push(interpreter * my_perl=0x00907004, padlist *
padlist=0x009a0a54, int depth=2) Line 2277 + 0xc C
perl517.dll!Perl_pp_entersub(interpreter * my_perl=0x00907004) Line
2750 + 0x1c C
perl517.dll!Perl_call_sv(interpreter * my_perl=0x00907004, sv *
sv=0x009d5284, volatile long flags=45) Line 2730 + 0x17 C
perl517.dll!S_curse(interpreter * my_perl=0x00907004, sv * const
sv=0x00bbec2c, const char check_refcnt=' ') Line 6374 + 0xf C
perl517.dll!Perl_sv_clear(interpreter * my_perl=0x00907004, sv * const
orig_sv=0x00bbec2c) Line 6024 + 0xf C
perl517.dll!Perl_sv_free2(interpreter * my_perl=0x00907004, sv * const
sv=0x00bbec2c) Line 6506 + 0xd C
perl517.dll!S_SvREFCNT_dec(interpreter * my_perl=0x00907004, sv *
sv=0x00bbec2c) Line 60 + 0xd C
perl517.dll!Perl_sv_unref_flags(interpreter * my_perl=0x00907004, sv *
const ref=0x00b82ef4, const unsigned long flags=5) Line 9604 + 0xd C
perl517.dll!Perl_sv_force_normal_flags(interpreter *
my_perl=0x00907004, sv * const sv=0x00b82ef4, const unsigned long
flags=5) Line 4808 + 0x11 C
perl517.dll!Perl_leave_scope(interpreter * my_perl=0x00907004, long
base=22) Line 930 + 0xf C
perl517.dll!Perl_pop_scope(interpreter * my_perl=0x00907004) Line
110 + 0x18 C
perl517.dll!Perl_pp_leavesub(interpreter * my_perl=0x00907004) Line
2603 + 0x9 C
perl517.dll!Perl_runops_standard(interpreter * my_perl=0x00907004)

Line 42 + 0xa C

perl517.dll!win32_start_child(void * arg=0x00907004) Line 1740 + 0xd C
kernel32.dll!_BaseThreadStart@8() + 0x37
_______________________________________________________________
curcop file "../../lib/IO/Socket.pm" line 45

next thread
_______________________________________________________________

ntdll.dll!_KiFastSystemCallRet@0()
ntdll.dll!_ZwDeviceIoControlFile@40() + 0xc
mswsock.dll!_WSPSelect@24() - 0x16a
ws2_32.dll!_select@20() + 0xa7

> perl517.dll!win32_select(int nfds=8, Perl_fd_set * rd=0x00b7df2c,

Perl_fd_set * wr=0x00000000, Perl_fd_set * ex=0x00000000, const timeval

* timeout=0x0012fad0) Line 276 + 0x35 C
perl517.dll!PerlSockSelect(IPerlSock * piPerl=0x00346c60, int nfds=8,
char * readfds=0x00b7df2c, char * writefds=0x00000000, char *
exceptfds=0x00000000, const timeval * timeout=0x0012fad0) Line 1395 +
0x19 C
perl517.dll!Perl_pp_sselect(interpreter * my_perl=0x00344684) Line
1200 + 0x30 C
perl517.dll!Perl_runops_standard(interpreter * my_perl=0x00344684)

Line 42 + 0xa C

perl517.dll!S_run_body(interpreter * my_perl=0x00344684, long
oldscope=1) Line 2431 + 0xd C
perl517.dll!perl_run(interpreter * my_perl=0x00344684) Line 2350 C
perl517.dll!RunPerl(int argc=4, char * * argv=0x00342cf0, char * *
env=0x00345cd8) Line 270 + 0x9 C

perl.exe!mainCRTStartup() Line 398 + 0xe C
kernel32.dll!_BaseProcessStart@4() + 0x23

______________________________________________________________________
+ cop_file 0x00aed5a4 "../../lib/IO/Select.pm" char *
cop_line 111 unsigned long


For the record, there is a 3rd OS thread, but it has nothing to do with
perl and is an artifact of the Visual Studio C debugger doing code
injection (probably trying to minimize the console window).
_________________________________________________________________-
> ntdll.dll!_KiFastSystemCallRet@0()
user32.dll!_NtUserPostThreadMessage@16() + 0xc
MSCTF.dll!MakeSetFocusNotify() + 0x4209
MSCTF.dll!UninitThread() + 0x5f
MSCTF.dll!_DllMain@12() + 0x434
MSCTF.dll!__DllMainCRTStartup@12() + 0x48
ntdll.dll!_LdrpCallInitRoutine@16() + 0x14
ntdll.dll!_LdrShutdownThread@0() + 0xed
ntdll.dll!_RtlExitUserThread@4() + 0xa
ntdll.dll!_DbgUiRemoteBreakin@4() + 0x4b
_________________________________________________________________

The pad_push crash happened because names looks like an array of mostly
garbage SV *s. The PV slot is NULL, doing SvPVX[0] on it is access vio.
______________________________________________________________________
- names[ix] 0x00344df8 {sv_any=0x00000000 sv_refcnt=0x7ffffb20
sv_flags=0x08000000 ...} sv *
sv_any 0x00000000 void *
sv_refcnt 0x7ffffb20 unsigned long
sv_flags 0x08000000 unsigned long
+ sv_u {svu_pv=0x00000000 <Bad Ptr> svu_iv=0x00000000
svu_uv=0x00000000 ...} sv::__unnamed
______________________________________________________________________
ix is 8 at the crash, dumping all of names array only 1 valid looking SV
* in it
______________________________________________________________________
- names,10 0x009a0284 sv * * const
+ [0x0] 0x00344df8 {sv_any=0x00000000 sv_refcnt=0x7ffffb20
sv_flags=0x08000000 ...} sv *
+ [0x1] 0x00344df8 {sv_any=0x00000000 sv_refcnt=0x7ffffb20
sv_flags=0x08000000 ...} sv *
+ [0x2] 0x00344df8 {sv_any=0x00000000 sv_refcnt=0x7ffffb20
sv_flags=0x08000000 ...} sv *
+ [0x3] 0x00344df8 {sv_any=0x00000000 sv_refcnt=0x7ffffb20
sv_flags=0x08000000 ...} sv *
+ [0x4] 0x00344df8 {sv_any=0x00000000 sv_refcnt=0x7ffffb20
sv_flags=0x08000000 ...} sv *
- [0x5] 0x009d5324 {sv_any=0x009a994c sv_refcnt=0x00000001
sv_flags=0x00004406 ...} sv *
sv_any 0x009a994c void *
sv_refcnt 0x00000001 unsigned long
sv_flags 0x00004406 unsigned long
+ sv_u {svu_pv=0x0096a9e4 "$self" svu_iv=0x0096a9e4 svu_uv=0x0096a9e4
...} sv::__unnamed
+ [0x6] 0x00344df8 {sv_any=0x00000000 sv_refcnt=0x7ffffb20
sv_flags=0x08000000 ...} sv *
+ [0x7] 0x00344df8 {sv_any=0x00000000 sv_refcnt=0x7ffffb20
sv_flags=0x08000000 ...} sv *
+ [0x8] 0x00344df8 {sv_any=0x00000000 sv_refcnt=0x7ffffb20
sv_flags=0x08000000 ...} sv *
+ [0x9] 0x00344df8 {sv_any=0x00000000 sv_refcnt=0x7ffffb20
sv_flags=0x08000000 ...} sv *
____________________________________________________________________
I dumped 2 extra slices of the array on purpose.

S_curse was modified to
_____________________________________________________________________
/* This routine curses the sv itself, not the object referenced by sv. So
sv does not have to be ROK. */

static bool
S_curse(pTHX_ SV * const sv, const bool check_refcnt) {
dVAR;

PERL_ARGS_ASSERT_CURSE;
assert(SvOBJECT(sv));

if (PL_defstash && /* Still have a symbol table? */
SvDESTROYABLE(sv))
{
dSP;
HV* stash;
do {
if ((stash = SvSTASH(sv)) && HvNAME(stash)) {
CV* destructor = NULL;
if (!SvOBJECT(stash)) destructor = (CV *)SvSTASH(stash);
if (!destructor) {
GV * const gv =
gv_fetchmeth_autoload(stash, "DESTROY", 7, 0);
if (gv) destructor = GvCV(gv);
if (!SvOBJECT(stash))
SvSTASH(stash) =
destructor ? (HV *)destructor : ((HV *)0)+1;
}
if (destructor && destructor != ((CV *)0)+1
/* A constant subroutine can have no side effects, so
don't bother calling it. */
&& !CvCONST(destructor)
/* Don't bother calling an empty destructor or one that
returns immediately. */
&& (CvISXSUB(destructor)
|| (CvSTART(destructor)
&& (CvSTART(destructor)->op_next->op_type
!= OP_LEAVESUB)
&& (CvSTART(destructor)->op_next->op_type
!= OP_PUSHMARK
|| CvSTART(destructor)->op_next->op_next->op_type
!= OP_RETURN
)
))
)
{
SV* const tmpref = newRV(sv);
SvREADONLY_on(tmpref); /* DESTROY() could be naughty */
ENTER;
PUSHSTACKi(PERLSI_DESTROY);
EXTEND(SP, 2);
PUSHMARK(SP);
PUSHs(tmpref);
Perl_warn(aTHX_ "dumping SV from C\n");
sv_dump(tmpref);
PUTBACK;
call_sv(MUTABLE_SV(destructor),
G_DISCARD|G_EVAL|G_KEEPERR|G_VOID);
POPSTACK;
SPAGAIN;
LEAVE;
if(SvREFCNT(tmpref) < 2) {
/* tmpref is not kept alive! */
SvREFCNT(sv)--;
SvRV_set(tmpref, NULL);
SvROK_off(tmpref);
}
SvREFCNT_dec(tmpref);
}
}
} while (SvOBJECT(sv) && SvSTASH(sv) != stash);


if (check_refcnt && SvREFCNT(sv)) {
if (PL_in_clean_objs)
Perl_croak(aTHX_
"DESTROY created new reference to dead object '%"HEKf"'",
HEKfARG(HvNAME_HEK(stash)));
/* DESTROY gave object new lease on life */
return FALSE;
}
}

if (SvOBJECT(sv)) {
SvREFCNT_dec(SvSTASH(sv)); /* possibly of changed persuasion */
SvOBJECT_off(sv); /* Curse the object. */
if (SvTYPE(sv) != SVt_PVIO)
--PL_sv_objcount;/* XXX Might want something more general */
}
return TRUE;
}
______________________________________________________________________

Attached is console output of io_sock.t with the sv_dump in curse.

[bulk88 via RT]

I changed multihomed.t
___________________________________________________
print $sock "ok 6\n";
sleep(1); # race condition
Dump($sock);
print $sock->getline();

$sock->close;

exit;
} else {
die;
}
___________________________________________________
All the Dumps on (select saver, curse, and now multihomed.t), it passes
if the Dump in the snippet above is added. Attached console.

[bulk88 via RT]

This is interesting, if I redirect to a text file, it fails, if I let it
print to console, it succeeds. copied from console
__________________________________________________________________________

C:\p517\perl\t>perl.exe -I..\lib harness -v ../dist/IO/t/io_multihomed.t
../dist/IO/t/io_multihomed.t ..
1..8

dumping SV from C
SV = IV(0xa43d60) at 0xa43d64
REFCNT = 1
FLAGS = (ROK,READONLY)
RV = 0xa94d4c
SV = PVMG(0xa69034) at 0xa94d4c
REFCNT = 1
FLAGS = (PADMY,OBJECT,POK,pPOK)
IV = 0
NV = 0
PV = 0xaf584c "main::STDOUT"\0
CUR = 12
LEN = 16
STASH = 0xa873c4 "SelectSaver"
SV = IV(0xa43d60) at 0xa43d64
REFCNT = 1
FLAGS = (ROK,READONLY)
RV = 0xa94d4c
SV = PVMG(0xa69034) at 0xa94d4c
REFCNT = 1
FLAGS = (PADMY,OBJECT,POK,pPOK)
IV = 0
NV = 0
PV = 0xaf584c "main::STDOUT"\0
CUR = 12
LEN = 16
STASH = 0xa873c4 "SelectSaver"
ok 1
dumping SV from C
SV = dumping SV from C
IV(0xb6d048) at 0xb6d04c
SV = IV(0xdbb6f0) at 0xdbb6f4
REFCNT = 1
REFCNT = 1
FLAGS = (ROK,READONLY)
FLAGS = (ROK,READONLY)
RV = 0xa43d44
RV = 0xd9d1bc
SV = SV = PVMG(0xdb0e04) at 0xd9d1bc
PVMG(0xa69034) at 0xa43d44
REFCNT = 1
REFCNT = 1
FLAGS = (PADMY,OBJECT,POK,pPOK)
FLAGS = (PADMY,OBJECT,POK,pPOK)
IV = 0
NV = 0
IV = 0 PV = 0xb69e4c "main::STDOUT"\0

CUR = 12
LEN = 16
STASH = 0xd9d0ac "SelectSaver"
NV = 0
SV = IV(0xac32b0) at 0xac32b4
REFCNT = 1
PV = 0xb53dfc FLAGS = (PADMY,ROK)
"main::STDOUT"\0 RV = 0xb6d03c

SV = PVGV(0xb6e7ac) at 0xb6d03c
REFCNT = 2
CUR = 12
FLAGS = (OBJECT,MULTI)
STASH = 0x90f434 "IO::Socket::INET"
LEN = 16
NAME = "GEN1"
STASH = 0xa873c4 NAMELEN = 4
"SelectSaver"
GvSTASH = 0xa872d4 "Symbol"
SV = GP = 0xd810ac
IV(0xb6d048) at 0xb6d04c
SV = 0x0
REFCNT = 1
REFCNT = 1
FLAGS = (ROK,READONLY)
IO = 0xb6d08c
RV = 0xa43d44
FORM = 0x0
AV = 0x0
SV = HV = 0x0
PVMG(0xa69034) at 0xa43d44
CV = 0x0
REFCNT = 1
CVGEN = 0x0
FLAGS = (PADMY,OBJECT,POK,pPOK)
LINE = 102
IV = 0 FILE = "../../lib/Symbol.pm"

FLAGS = 0x2
NV = 0
EGV = 0xb6d03c "GEN1"
PV = 0xb53dfc "main::STDOUT"\0
CUR = 12
ok 2 LEN = 16

STASH = 0xa873c4 "SelectSaver"

ok 3
ok 4
ok 5
ok 6

SV = IV(0xce3050) at 0xce3054
REFCNT = 1
FLAGS = (ROK)
RV = 0xdbb6d4
SV = PVGV(0xdc8e24) at 0xdbb6d4
REFCNT = 1
FLAGS = (OBJECT,MULTI)
STASH = 0xd467dc "Multi"
NAME = "GEN1"
NAMELEN = 4
GvSTASH = 0xbe16c4 "Symbol"
GP = 0xd813cc
SV = 0x0
REFCNT = 1
IO = 0xdbb734
FORM = 0x0
AV = 0x0
HV = 0xdbb714
CV = 0x0
CVGEN = 0x0
LINE = 102
FILE = "../../lib/Symbol.pm"
FLAGS = 0x2
EGV = 0xdbb6d4 "GEN1"

ok 7
ok 8
# Test process timed out - terminating
ok
All tests successful.

Files=1, Tests=8, 19 wallclock secs ( 0.03 usr + 0.01 sys = 0.05 CPU)

Result: PASS

C:\p517\perl\t>

_________________________________________________________________
IDK what to think.

[bulk88 via RT]

On Mon Nov 19 17:52:04 2012, perl...@rjbs.manxome.org wrote:
> Right now, my local release-5.17.6 is descended from 5ce83ae, which
> does not
> include the merge at 7cc6787e. Unless I hear some hollering that
> blead has
> become okay for everyone, I will just release from that branch.
>

According to
http://perl5.git.perl.org/perl.git/shortlog/5ce83ae94edf2f0edeb8f5cba4ca66d24a883236
, 5ce83ae includes "8c34e50dc slowed down detruction with no DESTROY"
AKA 7cc6787e .

--
bulk88 ~ bulk88 at hotmail.com

[Father Chrysostomos via RT]

On Mon Nov 19 17:52:04 2012, perl...@rjbs.manxome.org wrote:

> * Father Chrysostomos via RT <perlbug-...@perl.org> [2012-11-
> 19T11:45:28]

> > > I reverted
> > >
> >
>
http://perl5.git.perl.org/perl.git/commit/7cc6787e9dbebdd83799d997361188ab6dfe8ead
> >
> > (rjbs: Please don’t release 5.17.6 until this is reverted or we find
> a
> > fix. Thank you.)
>

> So, what's up with this now?
>
> I'm hoping to release 5.17.6 in about 24 hours. I'm going to release
> come Hell
> or high water.

Well, I didn’t mean it quite like that! There was no need to bring up
deluge and torment. :-)

What I meant was that I would revert it before the release if I did not
have time to fix it (which I have now done as 95f9781bc), and I wanted
you to make sure to include the revert in the release, rather than using
your current release branch as-is.

[Father Chrysostomos via RT]

...

>
> The pad_push crash happened because names looks like an array of mostly
> garbage SV *s. The PV slot is NULL, doing SvPVX[0] on it is access vio.
> ______________________________________________________________________
> - names[ix] 0x00344df8 {sv_any=0x00000000 sv_refcnt=0x7ffffb20
> sv_flags=0x08000000 ...} sv *
> sv_any 0x00000000 void *
> sv_refcnt 0x7ffffb20 unsigned long
> sv_flags 0x08000000 unsigned long
> + sv_u {svu_pv=0x00000000 <Bad Ptr> svu_iv=0x00000000
> svu_uv=0x00000000 ...} sv::__unnamed
> ______________________________________________________________________
> ix is 8 at the crash, dumping all of names array only 1 valid looking SV
> * in it

Thank you for your help in debugging this.

Those look like PL_sv_undef to me.

The line in question in 2277 in pad.c:

2276 if (names_fill >= ix && names[ix] != &PL_sv_undef) {
2277 const char sigil = SvPVX_const(names[ix])[0];
2278 if ((SvFLAGS(names[ix]) & SVf_FAKE)

That can only be reached if the SV is *not* PL_sv_undef. Judging by the
memory addresses in the backtrace, I suspect this is the PL_sv_undef
field of the parent thread.

So I suspect the child thread is trying to use a CV belonging to the parent.

What happens if you apply the attached patch? Bear in mind that I have
reverted 7cc6787e9d in blead. Please try this against 7cc6787e9d or any
commit before the revert.

(I suspect 8c34e50dc is actually the cause of this. 7cc6787e9d probably
just changed the order of things enough to trigger the crash.)

--

Father Chrysostomos

[bulk88 via RT]

On Tue Nov 20 14:56:51 2012, sprout wrote:
>
> Thank you for your help in debugging this.
>
> Those look like PL_sv_undef to me.

You guessed right, but the problem is, the undefs (or what I called
garbage SV *s earlier, i didn't realize it was an immortal because of
the refcount not being a perfect 0x80000000 or 0x7FFFFFFF), the undefs
are from the other thread/interp, at the crash in pad_push
______________________________________________________________

- names,10 0x009d1c3c sv * * const
+ [0] 0x00346628 {sv_any=0x00000000 sv_refcnt=2147482388
sv_flags=134217728 ...} sv *
+ [1] 0x00346628 {sv_any=0x00000000 sv_refcnt=2147482388
sv_flags=134217728 ...} sv *
+ [2] 0x00346628 {sv_any=0x00000000 sv_refcnt=2147482388
sv_flags=134217728 ...} sv *
+ [3] 0x00346628 {sv_any=0x00000000 sv_refcnt=2147482388
sv_flags=134217728 ...} sv *
+ [4] 0x00346628 {sv_any=0x00000000 sv_refcnt=2147482388
sv_flags=134217728 ...} sv *
+ [5] 0x009e420c {sv_any=0x009b46a4 sv_refcnt=1 sv_flags=17414 ...} sv *
+ [6] 0x00346628 {sv_any=0x00000000 sv_refcnt=2147482388
sv_flags=134217728 ...} sv *
+ [7] 0x00346628 {sv_any=0x00000000 sv_refcnt=2147482388
sv_flags=134217728 ...} sv *
+ [8] 0x00346628 {sv_any=0x00000000 sv_refcnt=2147482388
sv_flags=134217728 ...} sv *
+ [9] 0x00346628 {sv_any=0x00000000 sv_refcnt=2147482388
sv_flags=134217728 ...} sv *
__________________________________________________________________
> perl517.dll!Perl_pad_push(interpreter * my_perl=0x00bc060c, padlist *
padlist=0x00995bc4, int depth=3) Line 2277 + 0xc C
perl517.dll!Perl_pp_entersub(interpreter * my_perl=0x00bc060c) Line
2750 + 0x1c C
perl517.dll!Perl_call_sv(interpreter * my_perl=0x00bc060c, sv *
sv=0x009e416c, volatile long flags=45) Line 2730 + 0x17 C
perl517.dll!S_curse(interpreter * my_perl=0x00bc060c, sv * const
sv=0x00ce4794, const char check_refcnt=' ') Line 6373 + 0xf C
perl517.dll!Perl_sv_clear(interpreter * my_perl=0x00bc060c, sv * const
orig_sv=0x00ce4794) Line 6024 + 0xf C
perl517.dll!Perl_sv_free2(interpreter * my_perl=0x00bc060c, sv * const
sv=0x00ce4794) Line 6505 + 0xd C
perl517.dll!S_SvREFCNT_dec(interpreter * my_perl=0x00bc060c, sv *
sv=0x00ce4794) Line 60 + 0xd C
perl517.dll!Perl_sv_unref_flags(interpreter * my_perl=0x00bc060c, sv *
const ref=0x00bac154, const unsigned long flags=5) Line 9603 + 0xd C
perl517.dll!Perl_sv_force_normal_flags(interpreter *
my_perl=0x00bc060c, sv * const sv=0x00bac154, const unsigned long

flags=5) Line 4808 + 0x11 C

perl517.dll!Perl_leave_scope(interpreter * my_perl=0x00bc060c, long
base=24) Line 930 + 0xf C
perl517.dll!Perl_pop_scope(interpreter * my_perl=0x00bc060c) Line
110 + 0x18 C
perl517.dll!Perl_pp_leavesub(interpreter * my_perl=0x00bc060c) Line
2603 + 0x9 C
perl517.dll!Perl_runops_standard(interpreter * my_perl=0x00bc060c)

Line 42 + 0xa C

perl517.dll!win32_start_child(void * arg=0x00bc060c) Line 1740 + 0xd C
kernel32.dll!_BaseThreadStart@8() + 0x37
____________________________________________________________

SV * 0x00346628 is the undef immortal from this thread
_____________________________________________________________
- &my_perl->Isv_undef 0x00346628 {sv_any=0x00000000 sv_refcnt=2147482387
sv_flags=134217728 ...} sv *
sv_any 0x00000000 void *
sv_refcnt 2147482387 unsigned long
sv_flags 134217728 unsigned long
+ sv_u {svu_pv=0x00000000 <Bad Ptr> svu_iv=0 svu_uv=0 ...} sv::__unnamed

_____________________________________________________________
____________________________________________________________
ntdll.dll!_KiFastSystemCallRet@0()
ntdll.dll!_ZwRequestWaitReplyPort@12() + 0xc
ntdll.dll!_CsrClientCallServer@16() + 0x57
kernel32.dll!_WriteConsoleInternal@20() + 0x94
kernel32.dll!_WriteConsoleA@20() + 0x18
kernel32.dll!_WriteFile@20() + 0xbe62
> msvcr71.dll!_write_lk(int fh=671500209, const void * buf=0x00d2caca,
unsigned int cnt=672681368) Line 198 + 0x14 C
msvcr71.dll!_write(int fh=2, const void * buf=0x00ae3fec, unsigned int
cnt=26) Line 79 + 0xc C
perl517.dll!win32_write(int fd=2, const void * buf=0x00ae3fec,
unsigned int cnt=26) Line 3303 + 0x12 C
perl517.dll!PerlLIOWrite(IPerlLIO * piPerl=0x0034436c, int handle=2,
const void * buffer=0x00ae3fec, unsigned int count=26) Line 1080 + 0x11 C
perl517.dll!PerlIOUnix_write(interpreter * my_perl=0x00345eb4, _PerlIO
* * f=0x008f4a44, const void * vbuf=0x00ae3fec, unsigned int count=26)
Line 2817 + 0x22 C
perl517.dll!Perl_PerlIO_write(interpreter * my_perl=0x00345eb4,
_PerlIO * * f=0x008f4a44, const void * vbuf=0x00ae3fec, unsigned int
count=26) Line 1694 + 0x3e C
perl517.dll!PerlIOBuf_flush(interpreter * my_perl=0x00345eb4, _PerlIO
* * f=0x008f4474) Line 3928 + 0x1b C
perl517.dll!PerlIOCrlf_flush(interpreter * my_perl=0x00345eb4, _PerlIO
* * f=0x008f4474) Line 4764 + 0xd C
perl517.dll!Perl_PerlIO_flush(interpreter * my_perl=0x00345eb4,
_PerlIO * * f=0x008f4474) Line 1718 + 0xe C
perl517.dll!PerlIOCrlf_write(interpreter * my_perl=0x00345eb4, _PerlIO
* * f=0x008f4474, const void * vbuf=0x00d2ca8c, unsigned int count=63)
Line 4736 + 0xd C
perl517.dll!Perl_PerlIO_write(interpreter * my_perl=0x00345eb4,
_PerlIO * * f=0x008f4474, const void * vbuf=0x00d2ca8c, unsigned int
count=63) Line 1694 + 0x3e C
perl517.dll!PerlIO_vprintf(_PerlIO * * f=0x008f4474, const char *
fmt=0x28184d94, char * ap=0x0012f25c) Line 4970 + 0x15 C
perl517.dll!PerlIO_printf(_PerlIO * * f=0x008f4474, const char *
fmt=0x28184d94, ...) Line 4982 + 0x11 C
perl517.dll!Perl_do_sv_dump(interpreter * my_perl=0x00345eb4, long
level=0, _PerlIO * * file=0x008f4474, sv * sv=0x00958c94, long nest=0,
long maxnest=4, char dumpops=0, unsigned int pvlim=0) Line 1587 + 0x1d C
Peek.dll!XS_Devel__Peek_Dump(interpreter * my_perl=0x00000000, cv *
cv=0x009e42dc) Line 607 C
perl517.dll!Perl_pp_entersub(interpreter * my_perl=0x00345eb4) Line
2833 + 0x10 C
perl517.dll!Perl_runops_standard(interpreter * my_perl=0x00345eb4)

Line 42 + 0xa C

perl517.dll!Perl_call_sv(interpreter * my_perl=0x00345eb4, sv *
sv=0x009e416c, volatile long flags=45) Line 2730 + 0x36 C
perl517.dll!S_curse(interpreter * my_perl=0x00345eb4, sv * const
sv=0x00b59f0c, const char check_refcnt=' ') Line 6373 + 0xf C
perl517.dll!Perl_sv_clear(interpreter * my_perl=0x00345eb4, sv * const
orig_sv=0x00b59f0c) Line 6024 + 0xf C
perl517.dll!Perl_sv_free2(interpreter * my_perl=0x00345eb4, sv * const
sv=0x00b59f0c) Line 6505 + 0xd C
perl517.dll!S_SvREFCNT_dec(interpreter * my_perl=0x00345eb4, sv *
sv=0x00b59f0c) Line 60 + 0xd C
perl517.dll!Perl_sv_unref_flags(interpreter * my_perl=0x00345eb4, sv *
const ref=0x009f4774, const unsigned long flags=5) Line 9603 + 0xd C
perl517.dll!Perl_sv_force_normal_flags(interpreter *
my_perl=0x00345eb4, sv * const sv=0x009f4774, const unsigned long

flags=5) Line 4808 + 0x11 C

perl517.dll!Perl_leave_scope(interpreter * my_perl=0x00345eb4, long
base=37) Line 930 + 0xf C
perl517.dll!Perl_pop_scope(interpreter * my_perl=0x00345eb4) Line
110 + 0x18 C
perl517.dll!Perl_pp_leavesub(interpreter * my_perl=0x00345eb4) Line
2603 + 0x9 C
perl517.dll!Perl_runops_standard(interpreter * my_perl=0x00345eb4)

Line 42 + 0xa C

perl517.dll!S_run_body(interpreter * my_perl=0x00345eb4, long

oldscope=1) Line 2431 + 0xd C

perl517.dll!perl_run(interpreter * my_perl=0x00345eb4) Line 2350 C
perl517.dll!RunPerl(int argc=4, char * * argv=0x00342478, char * *
env=0x003451f8) Line 270 + 0x9 C

perl.exe!mainCRTStartup() Line 398 + 0xe C
kernel32.dll!_BaseProcessStart@4() + 0x23

__________________________________________________________________

AKA the root interp, note how close the my_perl * and immortal undef *
are. Same struct.

>
> The line in question in 2277 in pad.c:
>
> 2276 if (names_fill >= ix && names[ix] != &PL_sv_undef) {
> 2277 const char sigil = SvPVX_const(names[ix])[0];
> 2278 if ((SvFLAGS(names[ix]) & SVf_FAKE)
>
> That can only be reached if the SV is *not* PL_sv_undef. Judging by the
> memory addresses in the backtrace, I suspect this is the PL_sv_undef
> field of the parent thread.

Egh, your right. Ignore last paragraph.

>
> So I suspect the child thread is trying to use a CV belonging to the
parent.
>
> What happens if you apply the attached patch? Bear in mind that I have
> reverted 7cc6787e9d in blead. Please try this against 7cc6787e9d or any
> commit before the revert.
>
> (I suspect 8c34e50dc is actually the cause of this. 7cc6787e9d probably
> just changed the order of things enough to trigger the crash.)
>

Your patch worked, io_multihomed.t and io_sock.t passed.


Another problem, IDK if it is related since I didn't run this before the
crashing commit, this might be totally benign and irrelevant. Its more
for anyone else reading the thread than you. Previously I ran the
process without a debugger, waited for it to crash, then attached
debugger. Now I started the process from the debugger, this turns on
special developer features on in the kernel/os runtime layer like
Window's malloc poisoning and other kernel tweaks.


child thread, cop_line 384 unsigned long
+ cop_file 0x009ee1e4 "../../lib/IO/Handle.pm" char *
Kernel handle 0xf18 was passed to NtClose, (msvcr71.dll translates C
handles to kernel/OS handles).
__________________________________________________________________
ntdll.dll!_KiRaiseUserExceptionDispatcher@0() + 0x37
ntdll.dll!_KiFastSystemCall@0() + 0x3
ntdll.dll!_NtClose@4() + 0xc
kernel32.dll!_CloseHandle@4() + 0x44
msvcr71.dll!_close_lk(int fh=5) Line 115 + 0x3f C
msvcr71.dll!_close(int fh=5) Line 60 + 0x6 C
perl517.dll!my_close(int fd=5) Line 436 + 0xa C
perl517.dll!win32_close(int fd=5) Line 3251 + 0x9 C
perl517.dll!PerlLIOClose(IPerlLIO * piPerl=0x00ad97dc, int handle=5)
Line 947 + 0x9 C
perl517.dll!PerlIOUnix_close(interpreter * my_perl=0x00906fbc, _PerlIO
* * f=0x00bb2634) Line 2858 + 0x1a C
perl517.dll!PerlIOBase_close(interpreter * my_perl=0x00906fbc, _PerlIO
* * f=0x00af09ec) Line 2207 + 0xe C
perl517.dll!PerlIOBuf_close(interpreter * my_perl=0x00906fbc, _PerlIO
* * f=0x00af09ec) Line 4223 + 0xd C
perl517.dll!PerlIO__close(interpreter * my_perl=0x00906fbc, _PerlIO *
* f=0x00af09ec) Line 1465 + 0xe C
perl517.dll!Perl_PerlIO_close(interpreter * my_perl=0x00906fbc,
_PerlIO * * f=0x00af09ec) Line 1478 + 0xd C
perl517.dll!Perl_io_close(interpreter * my_perl=0x00906fbc, io *
io=0x00cfba24, char not_implicit=' ') Line 977 + 0x10 C
perl517.dll!Perl_do_close(interpreter * my_perl=0x00906fbc, gv *
gv=0x00cfb9d4, char not_implicit=' ') Line 942 + 0x11 C
> perl517.dll!Perl_pp_close(interpreter * my_perl=0x00906fbc) Line
663 + 0xf C
perl517.dll!Perl_runops_standard(interpreter * my_perl=0x00906fbc)

Line 42 + 0xa C

perl517.dll!win32_start_child(void * arg=0x00906fbc) Line 1740 + 0xd C
kernel32.dll!_BaseThreadStart@8() + 0x37
_______________________________________________________________________

parent thread,
+ cop_file 0x009ee1e4 "../../lib/IO/Handle.pm" char *
cop_line 384 unsigned long
kernel handle to CloseHandle was 0xf30
_______________________________________________________________________
ntdll.dll!_KiFastSystemCallRet@0()
ntdll.dll!_NtQueryVirtualMemory@24() + 0xc
kernel32.dll!__ValidateEH3RN() + 0xb6
kernel32.dll!__except_handler3() + 0x39
ntdll.dll!ExecuteHandler2@20() + 0x26
ntdll.dll!ExecuteHandler@20() + 0x24
ntdll.dll!_KiUserExceptionDispatcher@8() + 0xe
ntdll.dll!_KiRaiseUserExceptionDispatcher@0() + 0x37
ntdll.dll!_KiFastSystemCall@0() + 0x3
ntdll.dll!_NtClose@4() + 0xc
kernel32.dll!_CloseHandle@4() + 0x44
> msvcr71.dll!_close_lk(int fh=4) Line 115 + 0x3f C
msvcr71.dll!_close(int fh=4) Line 60 + 0x6 C
perl517.dll!my_close(int fd=4) Line 436 + 0xa C
perl517.dll!win32_close(int fd=4) Line 3251 + 0x9 C
perl517.dll!PerlLIOClose(IPerlLIO * piPerl=0x0034436c, int handle=4)
Line 947 + 0x9 C
perl517.dll!PerlIOUnix_close(interpreter * my_perl=0x00345eb4, _PerlIO
* * f=0x00aeb624) Line 2858 + 0x1a C
perl517.dll!PerlIOBase_close(interpreter * my_perl=0x00345eb4, _PerlIO
* * f=0x008f44a4) Line 2207 + 0xe C
perl517.dll!PerlIOBuf_close(interpreter * my_perl=0x00345eb4, _PerlIO
* * f=0x008f44a4) Line 4223 + 0xd C
perl517.dll!PerlIO__close(interpreter * my_perl=0x00345eb4, _PerlIO *
* f=0x008f44a4) Line 1465 + 0xe C
perl517.dll!Perl_PerlIO_close(interpreter * my_perl=0x00345eb4,
_PerlIO * * f=0x008f44a4) Line 1478 + 0xd C
perl517.dll!Perl_io_close(interpreter * my_perl=0x00345eb4, io *
io=0x00ae2b8c, char not_implicit=' ') Line 977 + 0x10 C
perl517.dll!Perl_do_close(interpreter * my_perl=0x00345eb4, gv *
gv=0x00ae2b3c, char not_implicit=' ') Line 942 + 0x11 C
perl517.dll!Perl_pp_close(interpreter * my_perl=0x00345eb4) Line
663 + 0xf C
perl517.dll!Perl_runops_standard(interpreter * my_perl=0x00345eb4)

Line 42 + 0xa C

perl517.dll!S_run_body(interpreter * my_perl=0x00345eb4, long

oldscope=1) Line 2431 + 0xd C

perl517.dll!perl_run(interpreter * my_perl=0x00345eb4) Line 2350 C
perl517.dll!RunPerl(int argc=4, char * * argv=0x00342478, char * *
env=0x003451f8) Line 270 + 0x9 C

perl.exe!mainCRTStartup() Line 398 + 0xe C
kernel32.dll!_BaseProcessStart@4() + 0x23
______________________________________________________________________

exception was "Unhandled exception at 0x7c90e4ff (ntdll.dll) in
perl.exe: 0xC0000008: An invalid HANDLE was specified."

--
bulk88 ~ bulk88 at hotmail.com

[Father Chrysostomos via RT]

On Tue Nov 20 16:52:31 2012, bulk88 wrote:
> On Tue Nov 20 14:56:51 2012, sprout wrote:
> >
> > Thank you for your help in debugging this.
> >
> > Those look like PL_sv_undef to me.
>
> You guessed right, but the problem is, the undefs (or what I called
> garbage SV *s earlier, i didn't realize it was an immortal because of
> the refcount not being a perfect 0x80000000 or 0x7FFFFFFF),

Yes, immortals can have any reference count.

> > What happens if you apply the attached patch? Bear in mind that I have
> > reverted 7cc6787e9d in blead. Please try this against 7cc6787e9d or any
> > commit before the revert.
> >
> > (I suspect 8c34e50dc is actually the cause of this. 7cc6787e9d probably
> > just changed the order of things enough to trigger the crash.)
> >
>
> Your patch worked, io_multihomed.t and io_sock.t passed.

Thank you. I pushed it as fef5350ad7.

--

Father Chrysostomos