W3C Logging services goes  in to the  Stop state automatically

W3C Logging services goes  in to the  Stop state unexpectedly/automatically   on Windows server 2016

OBSERVATIONS:

Procmon was not giving us much information on the caller of process issuing stop command to service  . So we collected SCM  ETL using below steps

Start tracing:

logman create trace "base_screg" -ow -o c:\base_screg.etl -p "Service Control Manager" 0xffffffffffffffff 0xff -nb 16 16 -bs 1024 -mode Circular -f bincirc -max 4096 -ets

logman update trace "base_screg" -p "Microsoft-Windows-Services" 0xffffffffffffffff 0xff -ets

logman update trace "base_screg" -p {EBCCA1C2-AB46-4A1D-8C2A-906C2FF25F39} 0xffffffffffffffff 0xff -ets

Stop tracing:

logman stop "base_screg" -ets

TEST PERFORMED LOCALLY:

---default service state  of w3logsvc = manual

--we created  custom field  in IIS logging  for testing

--sent a request and we see w3logsvc service in  "running" state  and we see request getting logged in IIS logs.

--after about 30-40minutes, we see service automatically stopped as i was not sending any active request.

--checked the SCM  logs to see who is the caller and see its PID PID 0x000014a0=5280.

65706 [2] 03D4.9D84::12/26/19-13:32:41.2477953 [SCM] scopen_cxx1159 ScOpenService() - ScOpenService: Service w3logsvc, handle 0x000001E4376E5100, PID 0x000014a0, access 0x00000024, refCount 4

65707 [2] 03D4.9D84::12/26/19-13:32:41.2478933 [SCM] control_cxx651 ScControlService() - ScControlService: Service w3logsvc, control 1, reason 0x00000000, comment NULL

65708 [2] 03D4.9D84::12/26/19-13:32:41.2480347 [SCM] control_cxx4422 ScSendControl() - ScSendControl: Sending control 0x00000001 to service/module w3logsvc, caller PID 0x000014a0, channel 0x000001E437857DC0, refs 0x3

65709 [0] 03D4.82EC::12/26/19-13:32:41.2481432 [SCM] status_cxx291 RSetServiceStatus() - RSetServiceStatus:  Status field accepted, service w3logsvc, state 0x00000003(SERVICE_STOP_PENDING), exit 0, sexit 0, controls 0x00000000

65710 [0] 03D4.82EC::12/26/19-13:32:41.2481461 [SCM] status_cxx414 CWin32ServiceRecord::SetStatus() - Service Record updated with new status for service w3logsvc

65711 [0]03D4.82EC::12/26/19-13:32:41.2481472 [Microsoft-Windows-Services/Diagnostic] ExecutionPhase=0, CurrentState=3, StartType=3, PID=21772, ServiceName=w3logsvc, ImageName=C:\WINDOWS\system32\svchost.exe -k apphost

65712 [5] 03D4.9D84::12/26/19-13:32:41.2483634 [SCM] control_cxx4865 ScSendControl() - ScSendControl: Service w3logsvc, control 1, user S-1-5-18, caller PID 0x000014a0

65713 [5] 03D4.9D84::12/26/19-13:32:41.2483642 [SCM] control_cxx4911 ScReleaseRefAndFreeServiceChannelContextUnlocked() - ScReleaseRefAndFreeServiceChannelContextUnlocked: Channel 0x000001E437857DC0, refs 0x2

65714 [5] 03D4.9D84::12/26/19-13:32:41.2535380 [SCM] status_cxx291 RSetServiceStatus() - RSetServiceStatus:  Status field accepted, service w3logsvc, state 0x00000001(SERVICE_STOPPED), exit 0, sexit 0, controls 0x00000000

65715 [5] 03D4.9D84::12/26/19-13:32:41.2536200 [SCM] status_cxx414 CWin32ServiceRecord::SetStatus() - Service Record updated with new status for service w3logsvc

65716 [5] 03D4.9D84::12/26/19-13:32:41.2537038 [SCM] scopen_cxx457 RCloseServiceHandle() - RCloseServiceHandle: Handle 0x000001E437743820, PID 0x0000550c

65717 [6]03D4.85AC::12/26/19-13:32:41.2539341 [Microsoft-Windows-Services/Diagnostic] ExecutionPhase=0, CurrentState=1, StartType=3, PID=0, ServiceName=w3logsvc, ImageName=

65718 [6] 03D4.85AC::12/26/19-13:32:41.2539370 [SCM] dataman_cxx3728 ScTerminateServiceProcess() - TerminateServiceProcess, sending Control...

So when we don’t have any active request to IIS,  W3SVC service stops the W3logsvc service and  runs it when the site receives a request. This service is stopped by default and set to “manual” startup. When you add a field to enhanced logging and the site receives a request, the service will be started .this is a By design behavior.