Login | Register For Free | Help
Search for: (Advanced)

Mailing List Archive: Perl: porters

[perl #88840] t/op/fork.t blocks in external process test on Win32

 

 

Perl porters RSS feed   Index | Next | Previous | View Threaded


perlbug-followup at perl

Aug 2, 2012, 4:17 PM

Post #1 of 11 (154 views)
Permalink
[perl #88840] t/op/fork.t blocks in external process test on Win32

I am using
__________________________________________________________
C:\>perl -V
Summary of my perl5 (revision 5 version 17 subversion 3 patch blead
2012-08-02.1
5:28:40 4276fd3639b8e3fdebe28a2eb81d455f0f33fd05 v5.17.2-193-g4276fd3)
configura
tion:
Snapshot of: 4276fd3639b8e3fdebe28a2eb81d455f0f33fd05
Platform:
osname=MSWin32, osvers=5.2, 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 -DWIN
32 -D_CONSOLE -DNO_STRICT -DWIN64 -DCONSERVATIVE
-D_CRT_SECURE_NO_DEPRECATE -D_C
RT_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', lsee
ksize=8
alignbytes=8, prototype=define
Linker and Libraries:
ld='link', ldflags ='-nologo -nodefaultlib -debug
-libpath:"c:\p517\lib\COR
E" -machine:AMD64 "/manifestdependency:type='Win32'
name='Microsoft.Windows.Com
mon-Controls' version='6.0.0.0' processorArchitecture='*'
publicKeyToken='6595b6
4144ccf1df' language='*'"'
libpth=\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
-libpath:"c:\p
517\lib\CORE" -machine:AMD64 "/manifestdependency:type='Win32'
name='Microsoft.
Windows.Common-Controls' version='6.0.0.0' processorArchitecture='*'
publicKeyTo
ken='6595b64144ccf1df' language='*'"'


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 USE_64_BIT_INT 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 Aug 2 2012 17:01:32
@INC:
C:/p517/site/lib
C:/p517/lib
.

C:\>
______________________________________________________________
VS 2008 and Server 2003 x64, and a x64 perl.


The /op/fork.t freeze is this being run "perl -e "if ($pid=fork){kill(9,
$pid)} else {sleep 5}"".
The callstack from the only thread at that point in the process is
___________________________________________________
ntdll.dll!ZwWaitForSingleObject() + 0xa bytes
ntdll.dll!RtlpWaitOnCriticalSection() - 0x1aa bytes
ntdll.dll!LdrUnloadDll() - 0x1d9a0 bytes
kernel32.dll!FreeLibrary() + 0x71 bytes
> perl517.dll!VMem::~VMem() Line 159 C++
perl517.dll!VMem::`scalar deleting destructor'() + 0x17 bytes C++
perl517.dll!VMem::Release() Line 268 + 0x2b bytes C++
perl517.dll!CPerlHost::~CPerlHost() Line 2081 C++
perl517.dll!CPerlHost::`scalar deleting destructor'() + 0x17 bytes C++
perl517.dll!win32_delete_internal_host(void * h=0x0000000000346e60)
Line 202 + 0x2b bytes C++
perl517.dll!perl_free(interpreter * my_perl=0x0000000001aa6a08)
Line 1335 C
perl517.dll!RunPerl(int argc=3, char * * argv=0x0000000000343d90, char
* * env=0x00000000003441b0) Line 277 C++
perl.exe!main(int argc=3, char * * argv=0x0000000000343d90, char * *
env=0x0000000000344820) Line 24 C
perl.exe!__tmainCRTStartup() Line 586 + 0x19 bytes C
kernel32.dll!BaseProcessStart() + 0x2c bytes
__________________________________________________
This is the parent "process" in ithreads, the child thread would have a
different callstack begining.

In vmem.h at line 158.
_____________________________________________
VMem::~VMem(void)
{
#ifdef _USE_LINKED_LIST
while (m_Dummy.pNext != &m_Dummy) {
Free(m_Dummy.pNext+1);
}
#endif
if (m_hLib)
FreeLibrary(m_hLib);
DeleteCriticalSection(&m_cs);
}
____________________________________________

m_hLib is 0x000007ff7fc00000 which is C:\WINDOWS\system32\msvcrt.dll
according to Process Explorer (HMODULEs are pointers to a memory mapped
DLL PE file header). The problem with vmem.h is that it calls msvcrt.dll
instead of being hard coded to whatever the static linked malloc or
static linked CRT is, so 2 CRTs wind up in the process space always
unless its compiled with Platform SDK or VC 6 (ActivePerl is made this
way) which doesnt use VS specific CRTs but msvcrt.dll for a c std lib.
This is an optimization issue but is not the cause of the deadlock,
since vmem.h and msvcrt.dll have been around for almost a decade ( added
in
http://perl5.git.perl.org/perl.git/commit/f57e8d3bb1a36000e1951a4d2d5b0104b39bde4b
)

So I got private symbol global variable "LdrpLoaderLock" (google it)
from ntdll and dumped it.

---
via perlbug: queue: perl5 status: new
https://rt.perl.org:443/rt3/Ticket/Display.html?id=88840
Attachments: ldrpdump.PNG (74.7 KB)


perlbug-followup at perl

Aug 2, 2012, 6:03 PM

Post #2 of 11 (149 views)
Permalink
[perl #88840] t/op/fork.t blocks in external process test on Win32 [In reply to]

A half baked solution is to not have perlhost.h load a 2nd C std Lib
into the perl OS process, and therefore never need to call FreeLibrary
in ~Vmem destroyer which will freeze the parent interp. Why the loader
lock never times out with a software exception (similar to access vio
GUI wise) IDK enough about windows to say. Any XS library that does a
FreeLibrary or a LoadLibrary, either explicitly or secretly in a pure
C/C++ DLL it wraps, probably even Dynaloader bootstrap will freeze
indefinitely, aslong as you Perl Lang kill 9ed a child fork "process"
earlier in runtime fast enough to never run win32_start_child.

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


perlbug-followup at perl

Aug 2, 2012, 6:06 PM

Post #3 of 11 (147 views)
Permalink
[perl #88840] t/op/fork.t blocks in external process test on Win32 [In reply to]

I am done, I am waiting for comments from the rest of P5P now.

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


perlbug-followup at perl

Aug 3, 2012, 12:59 PM

Post #4 of 11 (143 views)
Permalink
[perl #88840] t/op/fork.t blocks in external process test on Win32 [In reply to]

I've been wondering, has this test always failed? or it only fails on
SMP >1 CPU Windows (fails for me on 2 core and 8 core PCs)? Or does it
only fail on fast CPUs? or on Server 2003 (my machine) or NT 6 and not
XP (does for me) or 2000 because kernel scheduler tweaks by MS over the
years. Does it only fail on Visual Studio compiled Perl that uses a VS
specific CRT instead of msvcrt.dll (ActivePerl's C lib) (I blindly
guess, because a FreeLibrary that lowers the reference count but doesn't
free the DLL does so without using the loader lock maybe???). How was
5.16.0 released with this failing supposedly since 5.14 according to
tony cook?

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


perlbug-followup at perl

Aug 6, 2012, 9:10 PM

Post #5 of 11 (141 views)
Permalink
[perl #88840] t/op/fork.t blocks in external process test on Win32 [In reply to]

Another more rare way of deadlocking, child thread was killed while
holding malloc/heap lock, on fast kill 9 on psuedo fork process test.
_______________________________________________________
ntdll.dll!_KiFastSystemCallRet@0()
ntdll.dll!_ZwWaitForSingleObject [at] 1() + 0xc
ntdll.dll!_RtlpWaitForCriticalSection@4() + 0x8c
ntdll.dll!_RtlEnterCriticalSection@4() + 0x46
ntdll.dll!_RtlDebugFreeHeap [at] 1() + 0x6a
ntdll.dll!_RtlFreeHeapSlowly [at] 1() + 0x246cf
ntdll.dll!_RtlFreeHeap [at] 1() + 0x17646
msvcrt.dll!_free() + 0xc3
> perl510.dll!VMem::Free(void * pMem=0x0183780c) Line 230 C++
perl510.dll!PerlMemFree(IPerlMem * piPerl=0x002342a4, void *
ptr=0x0183780c) Line 310 C++
perl510.dll!Perl_safesysfree(void * where=0x0183780c) Line 250 + 0xe C
perl510.dll!Perl_sv_clear(interpreter * my_perl=0x00235ffc, sv *
sv=0x00000006) Line 5260 C
perl510.dll!Perl_sv_free2(interpreter * my_perl=0x00235ffc, sv *
sv=0x0182bee4) Line 5367 C
perl510.dll!Perl_sv_free(interpreter * my_perl=0x00235ffc, sv *
sv=0x0182bee4) Line 5345 + 0xa C
perl510.dll!Perl_av_undef(interpreter * my_perl=0x00235ffc, av *
av=0x0023ad5c) Line 485 + 0xd C
perl510.dll!Perl_sv_clear(interpreter * my_perl=0x0183780c, sv *
sv=0x0140fa94) Line 5191 + 0x7 C
perl510.dll!Perl_sv_2pv_flags(interpreter * my_perl=0x00000ff0, sv *
sv=0x00081414, unsigned int * lp=0x0000007c, long flags=4080) Line 2776 C
0000007b()
_________________________________________________
Symbols files werent perfect for this run but it shows of the point of
deadlock on heap lock. I will have more comments in the next day or 2 on
this bug.

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


perlbug-followup at perl

Aug 6, 2012, 9:15 PM

Post #6 of 11 (146 views)
Permalink
[perl #88840] t/op/fork.t blocks in external process test on Win32 [In reply to]

https://rt.cpan.org/Ticket/Display.html?id=66016 one of these is a
duplicate of the other, or atleast they are related. Someone link them
in RT. I only noticed the older bug just now.

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


perlbug-followup at perl

Aug 6, 2012, 9:15 PM

Post #7 of 11 (141 views)
Permalink
[perl #88840] t/op/fork.t blocks in external process test on Win32 [In reply to]

On Mon Aug 06 21:15:09 2012, bulk88 wrote:
> https://rt.cpan.org/Ticket/Display.html?id=66016 one of these is a
> duplicate of the other, or atleast they are related. Someone link them
> in RT. I only noticed the older bug just now.
NVM. Different RTs.


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


perlbug-followup at perl

Aug 9, 2012, 5:07 PM

Post #8 of 11 (127 views)
Permalink
[perl #88840] t/op/fork.t blocks in external process test on Win32 [In reply to]

On Wed Aug 08 17:59:27 2012, bulk88 wrote:
> Wrote up a patch. fork.t/"fast kill 9 after fork" stopped deadlocking
> for me. I wonder if the 5 ms delay is enough (I really dont know). I
> came up with the 5 ms delay from the previous code that did 5 "Sleep(0)"s.

My last post made it to Perl RT but not P5P. This one hopefully will.

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


perlbug-followup at perl

Aug 10, 2012, 9:42 AM

Post #9 of 11 (115 views)
Permalink
[perl #88840] t/op/fork.t blocks in external process test on Win32 [In reply to]

On Fri Aug 10 00:33:07 2012, tonyc wrote:
> I tried this and ran t/op/fork.t in a loop.
>
> First time it deadlocked after 7 runs, second it deadlocked after 27
> runs.
>
> I increased delay to 10 ms and it successfully ran the test 500 times.
>
> Also, please use git format-patch to produce patches.
>
> Tony
>
I wrote a script
_______________________________
for(0..1000) {
system $^X, "-e", "if (\$pid=fork){sleep 1;kill(9, \$pid)} else
{sleep 5}";
}
print "done\n";
_______________________________
Ran it twice on a DEBUGGING 5.17 with my patch, each one succeeded, no
deadlock and no timeout message (this machine did previously deadlock as
I described above). Did it deadlock (no message) for you or it hit the
croak I put in? Are you using a DEBUGGING perl or not (according to
smokes, it only affects DEBUGGING builds,
http://www.nntp.perl.org/group/perl.daily-build.reports/2012/08/msg125162.html
)? Did you change the ms time to 10 (so 10 x Sleep(1)s happened), or you
put in a Sleep(10)?

If it deadlocked for you, I am very interested in that, since my patch
is supposed to die or succeed, not deadlock. The only thing I can think
of, unless you can produce a callstack that shows otherwise (that would
be greatly appreciated), you are probably deadlocking on the heap
critical section (but how timing wise? child interp is supposed to be in
a sleep 5;, is it really taking that long from the hwnd message send,
thus unlocking get_hwnd_delay to runops calling the sleep opcode
function?), since the DLL loader lock is guaranteed to not be on in the
child interp unless your doing XS. In child interp's VMem, the
LoadLibrary on msvcrt.dll is done in the parent interp thread and it
does use the loader lock even though msvcrt.dll is already in the
process from the parent interp's VMem. Why MS uses the loader lock on a
refcount increase only LoadLibrary IDK.
____________________________________________________________
> ntdll.dll!RtlEnterCriticalSection() + 0xa bytes
ntdll.dll!LdrLockLoaderLock() + 0x78 bytes
ntdll.dll!LdrLoadDll() + 0xeb bytes
kernel32.dll!LoadLibraryExW() + 0x120 bytes
kernel32.dll!LoadLibraryA() + 0x86 bytes
perl517.dll!VMem::VMem() Line 142 + 0xd bytes C++
perl517.dll!CPerlHost::CPerlHost() Line 1949 + 0x21 bytes C++
perl517.dll!perl_alloc() Line 179 + 0x21 bytes C++
perl517.dll!RunPerl(int argc=0x00000003, char * *
argv=0x0000000000343d90, char * * env=0x0000000000344820) Line 248 +
0x5 bytes C++
perl.exe!main(int argc=0x00000003, char * * argv=0x0000000000343d90,
char * * env=0x0000000000344820) Line 24 C
perl.exe!__tmainCRTStartup() Line 586 + 0x19 bytes C
kernel32.dll!BaseProcessStart() + 0x2c bytes

________________________________________________________
The FreeLibrary of the child interp's VMem happens in the child thread,
unlike the LoadLibrary of the child interp (" perl -e "if
($pid=fork){waitpid($pid,0);} else {sleep 1;}"") but this code is never
reached in a early kill 9 after fork scenario. I stepped through the
FreeLibrary asm, it does not get/use the loader lock unless refcount
reaches 0 and instead uses inlined Interlocked* asm ops to decrease
refcount. So even if get_hwnd_delay took 5 clock seconds (a better
question is why? Perl's fault or user's fault?) (the Perl sleep period
in the child fork), since FreeLibrary doesn't get the loader lock, a
TerminateThread wouldn't deadlock there, unless, TerminateThread was
called after the win32_start_child "exited" and was in DLL_THREAD_DETACH
which will have the loader lock. I haven't seen this scenario happen on
my machine.
________________________________________________________
> kernel32.dll!FreeLibrary()
perl517.dll!VMem::~VMem() Line 159 C++
perl517.dll!VMem::`scalar deleting destructor'() + 0x17 bytes C++
perl517.dll!VMem::Release() Line 268 + 0x2b bytes C++
perl517.dll!CPerlHost::~CPerlHost() Line 2081 C++
perl517.dll!CPerlHost::`scalar deleting destructor'() + 0x17 bytes C++
perl517.dll!win32_delete_internal_host(void * h=0x000000000034aae0)
Line 202 + 0x2b bytes C++
perl517.dll!perl_free(interpreter * my_perl=0x0000000001af8888)
Line 1335 C
perl517.dll!win32_start_child(void * arg=0x0000000001af8888) Line
1804 C++
kernel32.dll!BaseThreadStart() + 0x3a bytes
________________________________________________________

---
via perlbug: queue: perl5 status: open
https://rt.perl.org:443/rt3/Ticket/Display.html?id=88840
Attachments: 0001-fix-RT-88840-don-t-terminate-a-child-fork-psuedo-pro.patch (6.29 KB)


perlbug-followup at perl

Aug 14, 2012, 1:12 AM

Post #10 of 11 (117 views)
Permalink
[perl #88840] t/op/fork.t blocks in external process test on Win32 [In reply to]

Can someone apply the patch to perl git?

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


perlbug-followup at perl

Aug 14, 2012, 9:57 AM

Post #11 of 11 (106 views)
Permalink
[perl #88840] t/op/fork.t blocks in external process test on Win32 [In reply to]

On Tue Aug 14 01:15:45 2012, Steve.Hay [at] verosoftware wrote:
> bulk 88 via RT wrote on 2012-08-14:
> > Can someone apply the patch to
> perl git?
> >
> > ---
> > via perlbug: queue: perl5 status: open
> >
> https://rt.perl.org:443/rt3/Ticket/Display.html?id=88840
>
> Apologies
> for the delay. I will test it and expect to apply it in a few hours.
> Thanks for your contributions!

Thanks again, now committed in d903973c05.

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

Perl porters RSS feed   Index | Next | Previous | View Threaded
 
 


Interested in having your list archived? Contact Gossamer Threads
 
  Web Applications & Managed Hosting Powered by Gossamer Threads Inc.