winsw keeps crashing and restarting but leaving our process alive each time

[tehdeadone]

We don't have a reliable way to reproduce this, but with the 1.18 binary running as a service, occasionally it crashes after being manually restarted.

The service starts up correctly. Then crashes. Windows then restarts the service and it crashes again. And this loop keeps repeating. However our process, a nodejs app, gets started each time and is not killed - leaving us with multiple nodejs processes running.

The windows event log gives this error for the crash (Event ID: 1001):

   0 
   CLR20r3 
   Not available 
   0 
   warningcenterprobemanager.exe 
   1.18.0.0 
   55d98359 
   mscorlib 
   2.0.0.0 
   53a11de1 
   34aa 
   1c5 
   System.IO.IOException 

   C:\Windows\Temp\WERDC32.tmp.WERInternalMetadata.xml C:\Windows\Temp\WERDC33.tmp.hdmp C:\Windows\Temp\WERE74B.tmp.mdmp 
   C:\ProgramData\Microsoft\Windows\WER\ReportQueue\AppCrash_warningcenterpro_a3e4127b311e5b4aef23108e2064c783b99b758_cab_de96e7e5 

   0 
   a8b0caf5-7ef4-11e5-bc70-d0509909aad9 
   4

The contents of the AppCrash report(s) are:

Version=1
EventType=CLR20r3
EventTime=130906761245341806
ReportType=2
Consent=1
ReportIdentifier=b863badd-7ef4-11e5-bc70-d0509909aad9
Response.type=4
Sig[0].Name=Problem Signature 01
Sig[0].Value=warningcenterprobemanager.exe
Sig[1].Name=Problem Signature 02
Sig[1].Value=1.18.0.0
Sig[2].Name=Problem Signature 03
Sig[2].Value=55d98359
Sig[3].Name=Problem Signature 04
Sig[3].Value=mscorlib
Sig[4].Name=Problem Signature 05
Sig[4].Value=2.0.0.0
Sig[5].Name=Problem Signature 06
Sig[5].Value=53a11de1
Sig[6].Name=Problem Signature 07
Sig[6].Value=34aa
Sig[7].Name=Problem Signature 08
Sig[7].Value=1c5
Sig[8].Name=Problem Signature 09
Sig[8].Value=System.IO.IOException
DynamicSig[1].Name=OS Version
DynamicSig[1].Value=6.1.7601.2.1.0.256.48
DynamicSig[2].Name=Locale ID
DynamicSig[2].Value=2057
UI[2]=C:\Program Files\Warning Center Probe Manager\probemanager\WarningCenterProbeManager.exe
LoadedModule[0]=C:\Program Files\Warning Center Probe Manager\probemanager\WarningCenterProbeManager.exe
LoadedModule[1]=C:\Windows\SYSTEM32\ntdll.dll
LoadedModule[2]=C:\Windows\SYSTEM32\MSCOREE.DLL
LoadedModule[3]=C:\Windows\system32\KERNEL32.dll
LoadedModule[4]=C:\Windows\system32\KERNELBASE.dll
LoadedModule[5]=C:\Windows\system32\ADVAPI32.dll
LoadedModule[6]=C:\Windows\system32\msvcrt.dll
LoadedModule[7]=C:\Windows\SYSTEM32\sechost.dll
LoadedModule[8]=C:\Windows\system32\RPCRT4.dll
LoadedModule[9]=C:\Windows\Microsoft.NET\Framework64\v4.0.30319\mscoreei.dll
LoadedModule[10]=C:\Windows\system32\SHLWAPI.dll
LoadedModule[11]=C:\Windows\system32\GDI32.dll
LoadedModule[12]=C:\Windows\system32\USER32.dll
LoadedModule[13]=C:\Windows\system32\LPK.dll
LoadedModule[14]=C:\Windows\system32\USP10.dll
LoadedModule[15]=C:\Windows\system32\IMM32.DLL
LoadedModule[16]=C:\Windows\system32\MSCTF.dll
LoadedModule[17]=C:\Windows\Microsoft.NET\Framework64\v2.0.50727\mscorwks.dll
LoadedModule[18]=C:\Windows\WinSxS\amd64_microsoft.vc80.crt_1fc8b3b9a1e18e3b_8.0.50727.4940_none_88df89932faf0bf6\MSVCR80.dll
LoadedModule[19]=C:\Windows\system32\shell32.dll
LoadedModule[20]=C:\Windows\system32\ole32.dll
LoadedModule[21]=C:\Windows\system32\profapi.dll
LoadedModule[22]=C:\Windows\assembly\NativeImages_v2.0.50727_64\mscorlib\fe6ac93181b40a571892e14bfb9d65f2\mscorlib.ni.dll
LoadedModule[23]=C:\Windows\system32\CRYPTBASE.dll
LoadedModule[24]=C:\Windows\system32\CRYPTSP.dll
LoadedModule[25]=C:\Windows\system32\rsaenh.dll
LoadedModule[26]=C:\Windows\assembly\NativeImages_v2.0.50727_64\System\62a2ae4ad514f18668a321ed9a69b1e2\System.ni.dll
LoadedModule[27]=C:\Windows\assembly\NativeImages_v2.0.50727_64\System.ServiceProce#\72c3df4b0f40787ef5940ce4719f3245\System.ServiceProcess.ni.dll
LoadedModule[28]=C:\Windows\Microsoft.NET\Framework64\v2.0.50727\mscorjit.dll
LoadedModule[29]=C:\Windows\assembly\NativeImages_v2.0.50727_64\System.Xml\f5c71a31db3e6506d5ee4c9050ff160d\System.Xml.ni.dll
LoadedModule[30]=C:\Windows\system32\apphelp.dll
LoadedModule[31]=C:\Windows\system32\VERSION.dll
FriendlyEventName=Stopped working
ConsentKey=CLR20r3
AppName=Windows Service Wrapper
AppPath=C:\Program Files\Warning Center Probe Manager\probemanager\WarningCenterProbeManager.exe
ReportDescription=Stopped working

[oleg-nenashev]

Have you seen an exception trace in the event log? I wonder why Windows does not print it by default, but IIRC there's an option, which allows enabling it.

[tehdeadone]

No. I double checked the event log and I couldn't find one. What's the option to enable it?

[ErikLundJensen]

Did you get any errors in the wrapper log? We have like 1 out of 1000+ restarts that fails with the same System.IO.IOException.
Below is output from the wrapper log. It would probably help putting a try/catch into winsw.WrapperService.StopProcess.

2016-08-19 15:17:22 - Found child process: 5512 Name: csrss.exe
2016-08-19 15:17:22 - Found child process: 3696 Name: winlogon.exe
2016-08-19 15:17:22 - Found child process: 3708 Name: conhost.exe
2016-08-19 15:17:22 - Stopping process 5512
2016-08-19 15:17:22 - Send SIGINT 5512
2016-08-19 15:17:22 - SIGINT to 5512 failed - Killing as fallback
2016-08-19 15:17:23 - Stop exception
Message:Access is denied
Stacktrace: at System.Diagnostics.ProcessManager.OpenProcess(Int32 processId, Int32 access, Boolean throwIfExited)
at System.Diagnostics.Process.GetProcessHandle(Int32 access, Boolean throwIfExited)
at System.Diagnostics.Process.Kill()
at winsw.WrapperService.StopProcess(Int32 pid)
at winsw.WrapperService.StopProcessAndChildren(Int32 pid)
at winsw.WrapperService.StopProcessAndChildren(Int32 pid)
at winsw.WrapperService.StopIt()
at winsw.WrapperService.OnStop()

[oleg-nenashev]

Crashes can be partially worked around by #125

[oleg-nenashev]

So there are several related issues fixed in 2.0. In particular, #59, #159 and #124 address the process termination logic. #125 also provides a Runaway Process Killer extension point, which can be used as a fail-safe. The issue needs to be retested

Closing this issue for now. If it still appears in WinSW 2, please reopen it