Bug #64575 for Win32-Daemon: Start callback not called with Strawberry Perl 5.10 / 5.12

Fri Jan 07 10:14:39 2011 haiko [...] strotbek.com - Ticket created

Subject:	Start callback not called with Strawberry Perl 5.10 / 5.12
Date:	Fri, 07 Jan 2011 16:14:28 +0100
To:	bug-Win32-Daemon [...] rt.cpan.org
From:	Haiko Strotbek <haiko [...] strotbek.com>

Hi, after upgrading Win32::Daemon from 2002xxxx to 20101014, the module failed to start callback in my script. After some debugging I figgured out that the main thread id won't be set when working with callbacks. So a PostMessage() call tries to access a non existing thread instead of the main thread and the start message is never processed. I could fix the problem by adding the following lines at Daemon.xs:1229 if( 0 == gMainThreadId ) { gMainThreadId = GetCurrentThreadId(); } Perhaps you can verify the patch and include it in the next version? Regards Haiko Strotbek

Fri Jan 07 16:57:08 2011 jand [...] ActiveState.com - Correspondence added

Subject:	RE: [rt.cpan.org #64575] Start callback not called with Strawberry Perl 5.10 / 5.12
Date:	Fri, 7 Jan 2011 13:57:00 -0800
To:	<bug-Win32-Daemon [...] rt.cpan.org>
From:	"Jan Dubois" <jand [...] activestate.com>

On Fri, 07 Jan 2011, Haiko Strotbek via RT wrote: Show quoted text

> Ticket <URL: https://rt.cpan.org/Ticket/Display.html?id=64575 > > > After some debugging I figgured out that the main thread id won't be set > when working with callbacks. So a PostMessage() call tries to access a > non existing thread instead of the main thread and the start message is > never processed. > > I could fix the problem by adding the following lines at Daemon.xs:1229 > > if( 0 == gMainThreadId ) > { > gMainThreadId = GetCurrentThreadId(); > } > > Perhaps you can verify the patch and include it in the next version?

I don't understand how that could make a difference. I find only 2 references to gMainThreadId in the sources: In the DllMain() function (in Daemon.xs line 952) the variable is initialized: gMainThreadId = GetCurrentThreadId(); This code is executed when the DLL is loaded into the process, before any other code in the same DLL can run. Since GetCurrentThreadId() cannot fail, and thread ids are never 0, I can't see how gMainThreadId can ever be 0 at a later point in time. The only other reference to gMainThreadId is a PostThreadMessage() call, which is not supposed to change the value of the thread id. So how can gMainThreadId still be 0 inside the StartService() function? Cheers, -Jan

Fri Jan 07 16:57:09 2011 The RT System itself - Status changed from 'new' to 'open'

Sat Jan 08 01:50:42 2011 haiko [...] strotbek.com - Correspondence added

Subject:	[rt.cpan.org #64575] Start callback not called with Strawberry Perl 5.10 / 5.12
Date:	Sat, 08 Jan 2011 07:50:27 +0100
To:	bug-Win32-Daemon [...] rt.cpan.org
From:	Haiko Strotbek <haiko [...] strotbek.com>

Show quoted text

> I don't understand how that could make a difference. I find only 2 > references to gMainThreadId in the sources: > > In the DllMain() function (in Daemon.xs line 952) the variable is initialized: > > gMainThreadId = GetCurrentThreadId(); > > This code is executed when the DLL is loaded into the process, before > any other code in the same DLL can run. Since GetCurrentThreadId() > cannot fail, and thread ids are never 0, I can't see how gMainThreadId > can ever be 0 at a later point in time. > > The only other reference to gMainThreadId is a PostThreadMessage() > call, which is not supposed to change the value of the thread id. > > So how can gMainThreadId still be 0 inside the StartService() function?

According to my debug messages the DllMain() function isn't called, so the gMainThreadId remains 0.

Mon Jan 10 20:10:38 2011 jand [...] ActiveState.com - Correspondence added

Subject:	RE: [rt.cpan.org #64575] Start callback not called with Strawberry Perl 5.10 / 5.12
Date:	Mon, 10 Jan 2011 17:10:25 -0800
To:	<bug-Win32-Daemon [...] rt.cpan.org>
From:	"Jan Dubois" <jand [...] activestate.com>

On Fri, 07 Jan 2011, Haiko Strotbek via RT wrote: Show quoted text

> > I don't understand how that could make a difference. I find only 2 > > references to gMainThreadId in the sources: > > > > In the DllMain() function (in Daemon.xs line 952) the variable is initialized: > > > > gMainThreadId = GetCurrentThreadId(); > > > > This code is executed when the DLL is loaded into the process, before > > any other code in the same DLL can run. Since GetCurrentThreadId() > > cannot fail, and thread ids are never 0, I can't see how gMainThreadId > > can ever be 0 at a later point in time.

[...] Show quoted text

> According to my debug messages the DllMain() function isn't called, so > the gMainThreadId remains 0.

I find that hard to believe. Did you sprinkle some OutputDebugString() calls into the function and then watch either with the Sysinternals Debug viewer, or Visual Studio etc. to see where the control flow goes through. If DllMain() isn't called, then all the other initializations in the DLL_PROCESS_ATTACH entry in the switch statement won't happen either. Cheers, -Jan

Tue Jan 11 13:27:22 2011 haiko [...] strotbek.com - Correspondence added

Subject:	Re: [rt.cpan.org #64575] Start callback not called with Strawberry Perl 5.10 / 5.12
Date:	Tue, 11 Jan 2011 19:27:07 +0100
To:	bug-Win32-Daemon [...] rt.cpan.org
From:	Haiko Strotbek <haiko [...] strotbek.com>

Show quoted text

> I find that hard to believe. Did you sprinkle some OutputDebugString() > calls into the function and then watch either with the Sysinternals > Debug viewer, or Visual Studio etc. to see where the control flow > goes through. If DllMain() isn't called, then all the other initializations > in the DLL_PROCESS_ATTACH entry in the switch statement won't happen > either.

Perhaps I made a mistake: I #defined DEBUG in all header files and added these lines at Daemon.xs:955 { char szBuffer[256]; sprintf( szBuffer, "Main thread ID: %lu", gMainThreadId ); ALERT( szBuffer ); } and these at Daemon.xs:918 { char szBuffer[256]; sprintf( szBuffer, "Started for reason: %lu", fdwReason ); ALERT( szBuffer ); } but none of the messages appear in the debug output file. Is there something wrong with this? I also verified that the patch definitely works - and since I tried two different versions of Strawberry Perl I don't think that it's my fault in any way.

Tue Jan 11 19:16:34 2011 jand [...] ActiveState.com - Correspondence added

Subject:	RE: [rt.cpan.org #64575] Start callback not called with Strawberry Perl 5.10 / 5.12
Date:	Tue, 11 Jan 2011 16:16:25 -0800
To:	<bug-Win32-Daemon [...] rt.cpan.org>
From:	"Jan Dubois" <jand [...] activestate.com>

On Tue, 11 Jan 2011, Haiko Strotbek via RT wrote: Show quoted text

>

> > I find that hard to believe. Did you sprinkle some OutputDebugString() > > calls into the function and then watch either with the Sysinternals > > Debug viewer, or Visual Studio etc. to see where the control flow > > goes through. If DllMain() isn't called, then all the other initializations > > in the DLL_PROCESS_ATTACH entry in the switch statement won't happen > > either.

> > Perhaps I made a mistake: > I #defined DEBUG in all header files and added these lines at Daemon.xs:955 > { > char szBuffer[256]; > sprintf( szBuffer, "Main thread ID: %lu", gMainThreadId ); > ALERT( szBuffer ); > } > > and these at Daemon.xs:918 > { > char szBuffer[256]; > sprintf( szBuffer, "Started for reason: %lu", fdwReason ); > ALERT( szBuffer ); > } > > but none of the messages appear in the debug output file. > > Is there something wrong with this?

Yes, ALERT() will write to the log file, which isn't opened until you call Win32::Daemon::DebugOutputPath(). That's why I suggested you use OutputDebugString( szBuffer ); The use the DebugView utility from Sysinternal (now part of Microsoft) to display all debugging output: http://technet.microsoft.com/en-us/sysinternals/bb896647 Show quoted text

> I also verified that the patch definitely works - and since I tried two > different versions of Strawberry Perl I don't think that it's my fault > in any way.

This is not about something being anyone's fault. I simply don't want to apply a patch to code that I haven't written, that I don't understand how/why it would make a difference. Especially since there are no regression tests for this module either. Until I understand *why* the patch makes a difference on your system, I can't really be sure that the patch is correct in the general case, and if it covers the whole problem, or just a part of it. E.g. if the DllMain() function really isn't called, then there are other initializations that aren't happening either. But I don't think this is the root cause of the problem. I really appreciate it that you are helping to uncover the real problem behind the issue you are seeing. Cheers, -Jan

Wed Jan 12 14:29:38 2011 haiko [...] strotbek.com - Correspondence added

Subject:	Re: [rt.cpan.org #64575] Start callback not called with Strawberry Perl 5.10 / 5.12
Date:	Wed, 12 Jan 2011 20:29:27 +0100
To:	bug-Win32-Daemon [...] rt.cpan.org
From:	Haiko Strotbek <haiko [...] strotbek.com>

Show quoted text

> Yes, ALERT() will write to the log file, which isn't opened until you > call Win32::Daemon::DebugOutputPath(). That's why I suggested you use > > OutputDebugString( szBuffer ); > > The use the DebugView utility from Sysinternal (now part of Microsoft) > to display all debugging output: > > http://technet.microsoft.com/en-us/sysinternals/bb896647

Ok, I tried it that way and inserted OutputDebugStringA( "DllMain" ); in line 918 and OutputDebugStringA( "Daemon::StartService: About to start the service thread..." ); in line 1228. In DebugView the second message appears, so receiving the messages work. But the first message doesn't appear although it should be triggered directly after entering DllMain(). I have to admit that it doesn't make sense - perhaps compiling with gcc causes that by changing the signature in an invalid way!? Do other perl modules use DllMain() for initializing?

Mon Jan 17 13:28:30 2011 haiko [...] strotbek.com - Correspondence added

Subject:	Re: [rt.cpan.org #64575] Start callback not called with Strawberry Perl 5.10 / 5.12
Date:	Mon, 17 Jan 2011 19:28:18 +0100
To:	bug-Win32-Daemon [...] rt.cpan.org
From:	Haiko Strotbek <haiko [...] strotbek.com>

Ok, my former patch is useless - my suspicion pointed into the right direction: I found out that adding 'extern "C"' to the DllMain() signature fixes the problem and the DllMain() function is called. Unfortunately I don't know if VC is able to compile the modified code so perhaps the makefile script has to adjust it according to the compiler.

Mon Jan 17 14:39:21 2011 jand [...] ActiveState.com - Correspondence added

Subject:	RE: [rt.cpan.org #64575] Start callback not called with Strawberry Perl 5.10 / 5.12
Date:	Mon, 17 Jan 2011 11:39:11 -0800
To:	<bug-Win32-Daemon [...] rt.cpan.org>, "'undisclosed-recipients:'" [...] bestpractical.com
From:	"Jan Dubois" <jand [...] activestate.com>

On Mon, 17 Jan 2011, Haiko Strotbek via RT wrote: Show quoted text

> > Ok, my former patch is useless - my suspicion pointed into the right > direction: I found out that adding 'extern "C"' to the DllMain() > signature fixes the problem and the DllMain() function is called.

Thanks for persisting in hunting this down! It indeed looks like DllMain() is treated specially by VC to always use the "C" naming convention, but MinGW doesn't copy that special treatment. Show quoted text

> Unfortunately I don't know if VC is able to compile the modified code so > perhaps the makefile script has to adjust it according to the compiler.

Adding the additional extern "C" should be a no-op in VC, so the fix should be trivial. I'll make another release after looking at the 64-bit issues as well. Cheers, -Jan

Mon Jan 17 21:11:06 2011 JDB [...] cpan.org - Correspondence added

Fixed in Win32-Daemon-20110117

Mon Jan 17 21:11:07 2011 JDB [...] cpan.org - Status changed from 'open' to 'resolved'