#413 Windows service startup

Development_Branch
closed-fixed
nobody
PTLib (141)
5
2013-03-25
2013-01-16
Anonymous
No

My Windows service based on PTLib can't start as a service, but properly starts with "debug" command line switch.
Windows Log shows:
A timeout was reached (30000 milliseconds) while waiting for the VM2 service to connect.
The VM2 service failed to start due to the following error:
The service did not respond to the start or control request in a timely fashion.

Previously (with older PTLibs) it was starting without problems.

Discussion

  • It was me.

     
    • status: open --> pending
     
  • How did you try and start the service?

    On windows, the service but be installed and started using commands, it is not simply a case of running the program without any parameter. Are you aware of the mechanism?

     
  • > Are you aware of the mechanism?
    Yes, of course. I've used this service without problems, but it started to fail after updating PTLib some weeks ago.

    I've found the issue: the service hangs on line 127 in winsock.cxx:

    PAssert(QOSCreateHandle(&qosVersion, &m_hQoS), POperatingSystemError);

    while executing "QOSCreateHandle" function (not an Assert).

     
    • status: pending --> open
     
  • Stack trace:

    ntdll.dll\!\_ZwAlpcSendWaitReceivePort@32\(\)  + 0x12 bytes 
    ntdll.dll\!\_ZwAlpcSendWaitReceivePort@32\(\)  + 0x12 bytes 
    rpcrt4.dll\!LRPC\_BASE\_CCALL::DoSendReceive\(\)  + 0x76 bytes  
    rpcrt4.dll\!LRPC\_BASE\_CCALL::SendReceive\(\)  + 0x2f bytes    
    rpcrt4.dll\!LRPC\_CCALL::SendReceive\(\)  + 0x1e bytes  
    rpcrt4.dll\!\_I\_RpcSendReceive@4\(\)  + 0x24 bytes 
    rpcrt4.dll\!\_NdrSendReceive@8\(\)  + 0x2b bytes    
    rpcrt4.dll\!@NdrpSendReceive@4\(\)  + 0x9 bytes 
    rpcrt4.dll\!\_NdrClientCall2\(\)  + 0x144 bytes 
    sechost.dll\!\_RStartServiceA@12\(\)  + 0x19 bytes  
    sechost.dll\!\_StartServiceA@12\(\)  + 0x1e bytes   
    qwave.dll\!QDLHPathDiagnostics\(\)  + 0x21d bytes   
    \[Frames below may be incorrect and/or missing, no symbols loaded for qwave.dll\]
    

    > qwave.dll!QOSCreateHandle() + 0xb4 bytes
    PTLibd.dll!PWinSock::PWinSock() Line 127 + 0x13 bytes C++
    PTLibd.dll!`dynamic initializer for 'WinSock''() Line 140 + 0x13 bytes C++
    msvcr90d.dll!_initterm(void (void)* * pfbegin=0x105a9798, void (void)* * pfend=0x105a9ca0) Line 903 C
    PTLibd.dll!_CRT_INIT(void * hDllHandle=0x10000000, unsigned long dwReason=1, void * lpreserved=0x002cfc18) Line 318 + 0xf bytes C
    PTLibd.dll!__DllMainCRTStartup(void * hDllHandle=0x10000000, unsigned long dwReason=1, void * lpreserved=0x002cfc18) Line 540 + 0x11 bytes C
    PTLibd.dll!_DllMainCRTStartup(void * hDllHandle=0x10000000, unsigned long dwReason=1, void * lpreserved=0x002cfc18) Line 510 + 0x11 bytes C
    ntdll.dll!_LdrpCallInitRoutine@16() + 0x14 bytes
    ntdll.dll!_LdrpRunInitializeRoutines@4() - 0x352 bytes
    ntdll.dll!_LdrpInitializeProcess@8() - 0x765 bytes
    ntdll.dll!__LdrpInitialize@8() + 0xb4f9 bytes
    ntdll.dll!_LdrInitializeThunk@8() + 0x10 bytes

     
  • Quality Windows Audio Video Experience is running.

     
  • Updated stack trace (with MS PDBs):

    ntdll.dll\!\_ZwAlpcSendWaitReceivePort@32\(\)  + 0x12 bytes 
    ntdll.dll\!\_ZwAlpcSendWaitReceivePort@32\(\)  + 0x12 bytes 
    rpcrt4.dll\!LRPC\_BASE\_CCALL::DoSendReceive\(\)  + 0x76 bytes  
    rpcrt4.dll\!LRPC\_BASE\_CCALL::SendReceive\(\)  + 0x2f bytes    
    rpcrt4.dll\!LRPC\_CCALL::SendReceive\(\)  + 0x1e bytes  
    rpcrt4.dll\!\_I\_RpcSendReceive@4\(\)  + 0x24 bytes
    

    > rpcrt4.dll!_NdrSendReceive@8() + 0x2b bytes
    rpcrt4.dll!@NdrpSendReceive@4() + 0x9 bytes
    rpcrt4.dll!_NdrClientCall2() + 0x144 bytes
    sechost.dll!_RStartServiceA@12() + 0x19 bytes
    sechost.dll!_StartServiceA@12() + 0x1e bytes
    qwave.dll!_StartQOS2Service@0() + 0x95 bytes
    qwave.dll!_QOSCreateHandle@8() + 0xb4 bytes
    PTLibd.dll!PWinSock::PWinSock() Line 127 + 0x13 bytes C++
    PTLibd.dll!`dynamic initializer for 'WinSock''() Line 140 + 0x13 bytes C++
    msvcr90d.dll!_initterm(void (void)* * pfbegin=0x105a9798, void (void)* * pfend=0x105a9ca0) Line 903 C
    PTLibd.dll!_CRT_INIT(void * hDllHandle=0x10000000, unsigned long dwReason=1, void * lpreserved=0x0016f578) Line 318 + 0xf bytes C
    PTLibd.dll!__DllMainCRTStartup(void * hDllHandle=0x10000000, unsigned long dwReason=1, void * lpreserved=0x0016f578) Line 540 + 0x11 bytes C
    PTLibd.dll!_DllMainCRTStartup(void * hDllHandle=0x10000000, unsigned long dwReason=1, void * lpreserved=0x0016f578) Line 510 + 0x11 bytes C
    ntdll.dll!_LdrpCallInitRoutine@16() + 0x14 bytes
    ntdll.dll!_LdrpRunInitializeRoutines@4() - 0x352 bytes
    ntdll.dll!_LdrpInitializeProcess@8() - 0x765 bytes
    ntdll.dll!__LdrpInitialize@8() + 0xb4f9 bytes
    ntdll.dll!_LdrInitializeThunk@8() + 0x10 bytes

     
  • Removing WinSock initialization from statically initialized variable fixes this.
    Just for test I'd replaced "WinSock" object with pointer:

    } * WinSock = NULL; // Assure winsock is initialised

    and added a static function to initialize it:

    void PSocket::InitSocket()
    {
    static PWinSock winSock;
    WinSock = &winSock;
    }

     
  • Fix applied to Eridani (PTLib 2.12, OPAL 3.12) and trunk, thank you very much!

     
    • status: open --> closed-fixed
     
  • Meyers singleton is not thread-safe (for the most compilers), so there is a possible bug with simultaneous initialization from several threads.

     
    • status: closed-fixed --> open-fixed
     
    • status: open-fixed --> closed-fixed
     
  • Fixed using thread safe singleton code from PTLib

     
  • It's not fixed. Windows Service can't start.

     
    • status: closed-fixed --> open-fixed
     
  • The current implementation doesn't work because of initial issue (qWAVE/WinSock initialization code starts on library initialization, before DllMain has executed).

     
  • I have just tried opalgw, which is a service process, here on Windows 8, and I don't think it is the same problem as before.

    First, as of the fix on 2013-02-15 , the WinSock initialisation is done after main() is executed, which is long after DllMain is executed. That is why I made the change in the first place. I have confirmed this with logging output.

    Second, the error in the event log states it did not respond in 30 seconds, but the error comes back IMMEDIATELY, not in fact after anywhere near 30 seconds. I think this error is misleading. The problem was in fact the PATH when run as a service not having required DLL's in it.

    Finally, when it still was not working, I eventually tracked the problem down to attempting to create an OpenSSL context too early. I have now fixed this and checked it into Eridani.

    This time for sure!

     
    • status: open-fixed --> closed-fixed