Recently in tests I noticed that my NT service stopped working in Windows Vista machine. There were no crashes, just entry in Event Log saying: “Error 1053: The service did not respond to the start or control request in a timely fashion“.
These type of things are slightly more difficult to debug than usual crashes because usually you have no crash address and no dump generated by WER. At the same time, I had a suspicious feeling that it could be related to initialization of my global object, as it’s constructor function is quite big.
For the sake of the test, I put some logging into my main(…) function and noticed that nothing was logged – entry point of service was not even called. Okay, most likely problem is indeed caused by code in constructors.
These kind of errors are better to debug using WinDbg, because service starts really early, therefore standard debugging would not work.
So, the general approach is to:
1. Setup WinDbg debugging with vmmon to boost debugging speed
2. Put calls to DebugBreak(…) into constructors in your service
3. Reboot machine, and wait until it breaks in debugger
Once it breaks, one has to “attach” to a current process using the following commands in Windbg (otherwise you will be unable to step into your code, which is quite inconvenient, right?):
0: kd> !process
PROCESS 83534d90 SessionId: none Cid: 0004 Peb: 00000000 ParentCid: 0000
0: kd> .process /p /r 83534d90
Implicit process is now 83534d90
.cache forcedecodeuser done
Loading User Symbols
Now, if you’ve done everything properly, you should be able to see your code and normally debug it. Using this technique, I was able to narrow down issue to a call WTSEnumerateSessions(…) which hangs, therefore, CRT does not pass control to entry point of service, and SCM “thinks” it time-outs.
What is so special in this function which makes it hung? Let us take a look at documentation:
To enumerate a session, you must have Query Information permission. For more information, see Remote Desktop Services Permissions. To modify permissions on a session, use the Remote Desktop Services Configuration administrative tool.
To enumerate sessions running on a virtual machine hosted on a RD Virtualization Host server, you must be a member of the Administrators group on the RD Virtualization Host server.
There is nothing about why it could hang, or take long time to execute. Let’s take a look at it’s internals. Fire up Ida:
.text:49CB2CC9 _WTSEnumerateSessionsA@20 proc near
.text:49CB2CFE lea eax, [ebp+arg_0]
.text:49CB2D01 push eax
.text:49CB2D02 lea eax, [ebp+var_4]
.text:49CB2D05 push eax
.text:49CB2D06 push [ebp+arg_0]
.text:49CB2D09 call _WinStationEnumerateW@12 ; WinStationEnumerateW(x,x,x)
.text:49CB2D0E test al, al
As you can see above, a call to WTSEnumerateSessions actually maps into winsta.dll!WinStationEnumerate. OK, fire-up another instance of Ida and disassemble winsta.dll:
.text:410456C4 ; __stdcall WinStationEnumerateW(x, x, x)
.text:410456C4 ; FUNCTION CHUNK AT .text:4104C405 SIZE 00000030 BYTES
.text:410456C4 mov edi, edi
.text:410456C6 push ebp
.text:410456C7 mov ebp, esp
.text:410456C9 push esi
.text:410456CA push [ebp+arg_8]
.text:410456CD push [ebp+arg_4]
.text:410456D0 push [ebp+arg_0]
.text:410456D3 call ?_tsrpcEnumerate@@YGJPAXPAPAU_SESSIONIDW@@PAK@Z
As we can see, WinStationEnumerate calls internally _tsrpcEnumerate function which looks like this:
.text:41045729 push dword ptr [ebp+8]
.text:4104572C lea ecx, [ebp-54h]
.text:4104572F call ??0CSmartPublicBinding@@QAE@PAXH@Z ; CSmartPublicBinding::CSmartPublicBinding(void *,int)
.text:41045734 push 1
.text:41045736 push dword ptr [ebp+8]
.text:41045739 lea ecx, [ebp-48h]
.text:4104573C call ??0CSmartPublicBinding@@QAE@PAXH@Z ; CSmartPublicBinding::CSmartPublicBinding(void *,int)
.text:41045741 lea ecx, [ebp-54h]
.text:41045744 call ??BCSmartPublicBinding@@QAEPAXXZ ; CSmartPublicBinding::operator void *(void)
.text:41045749 test eax, eax
.text:4104574B jz loc_4104CFA8
.text:41045751 lea ecx, [ebp-54h]
.text:41045754 call ??BCSmartPublicBinding@@QAEPAXXZ ; CSmartPublicBinding::operator void *(void)
.text:41045759 push eax
.text:4104575A lea ecx, [ebp-34h]
.text:4104575D call ?Open@CEnum@@QAEJPAX@Z ; CEnum::Open(void *) <--------------------- look here
After some analysis of the function body I eventually see that inside CEnum::Open method there is the following call:
.text:4104561D ?Open@CEnum@@QAEJPAX@Z proc near ; CODE XREF: _tsrpcEnumerate(void *,_SESSIONIDW * *,ulong *)
.text:4104561D push 10h
.text:4104561F push offset dword_41045678 ; char
.text:41045624 call __SEH_prolog4
.text:41045629 mov esi, ecx
.text:4104562B push offset aCenumOpen ; "CEnum::Open"
.text:41045630 push 10h ; int
.text:41045632 call ?_DbgPrintMessage@@YAXHPBDZZ ; _DbgPrintMessage(int,char const *,...)
.text:41045637 pop ecx
.text:41045638 pop ecx
.text:41045639 and dword ptr [ebp-4], 0
.text:4104563D push esi
.text:4104563E push dword ptr [ebp+8]
.text:41045641 call _RpcOpenEnum@8 ; RpcOpenEnum(x,x) <--------------------- look here
.text:41045646 mov [ebp-1Ch], eax
.text:41045649 loc_41045649: ; CODE XREF: .text:4104C11Ej
.text:41045649 mov dword ptr [ebp-4], 0FFFFFFFEh
.text:41045650 push offset aCenumOpen ; "CEnum::Open"
.text:41045655 push 20h ; int
.text:41045657 call ?_DbgPrintMessage@@YAXHPBDZZ ; _DbgPrintMessage(int,char const *,...)
.text:4104565C pop ecx
.text:4104565D pop ecx
.text:4104565E mov eax, [ebp-1Ch]
.text:41045661 call __SEH_epilog4
.text:41045666 retn 4
.text:41045666 ?Open@CEnum@@QAEJPAX@Z endp ; sp = -8
As we can see here, there is a call to RpcOpenEnum(…) function. Well, as it smells RPC, most likely, it is not yet initialized at this point. In order to prove this idea, I setup dependency to service RpcSS, restart machine, and voila, everything works.
The most interesting part is that documentation for WTSEnumerateSessions does not mention any limitations about early calls, RPC time-outs, etc. Of course, one has to be extremly careful when runing services at early boot time, but having a reminder in documentation for API function(s) would be nice to have.
Btw, here is a nice list of dependencies to rpcss: http://technet.microsoft.com/en-us/library/cc787851%28WS.10%29.aspx by Windows services.