windows: route OS-shutdown SIGTERM through SCM to unblock svc.Run - #2215
windows: route OS-shutdown SIGTERM through SCM to unblock svc.Run#2215ablankz wants to merge 2 commits into
Conversation
972bed4 to
52bfdca
Compare
|
FYI: PR #2215 was revised to route the terminating signal through an SCM |
|
Follow-up (commit
Validated on Windows Server 2022 by injecting a 10 s sleep inside
|
At Windows OS shutdown, when the collector runs as a service child (spawned by start-amazon-cloudwatch-agent.exe), csrss delivers CTRL_SHUTDOWN (mapped to SIGTERM) to the collector but the SCM routes SERVICE_CONTROL_SHUTDOWN through the launcher, not directly here. kardianos/service v1.2.1's non-interactive windowsService.Run waits only on the SCM control channel and does not watch SIGTERM, so svc.Run never returns and the whole OS shutdown deadlocks until the platform's hard-timeout (~4-5 min: Event ID 6008 + Kernel-Power 41). sc stop / Stop-Service is unaffected. On a non-SIGHUP terminating OS signal, reloadLoop's signal goroutine now issues SERVICE_CONTROL_STOP against this process's own SCM entry (found by matching ProcessId, since kardianos's config Name -- 'telegraf' by default -- is not registered in SCM) via x/sys/windows/svc/mgr. That triggers kardianos's normal STOP path (prg.Stop -> close(stop)) and svc.Run returns cleanly, letting main return and OS shutdown proceed. If the SCM path is unavailable (not running as a Windows service, Connect/ListServices/OpenService/Control fails, or prg.Stop doesn't run within stopWaitTimeout=30s), the code falls back to setting a flag that handleTerminatingSignal reads after reloadLoop returns to call os.Exit(0) as a last resort so the OS shutdown is never blocked. No-op on non-Windows, in interactive/console mode, on the SCM STOP path (<-stop), and on SIGHUP reload. No new module dependencies (x/sys is already in go.mod). Tests cover the atomic flag, the dispatch function (cross-platform, via test seam), and the Windows-specific SCM logic and fallback exit (via fake scmManager/scmService and seams over exitFunc / isWinService / ownProcessID / scmConnectFunc). Validated on Windows Server 2022 (EC2 m5.xlarge, WaitToKillServiceTimeout=300000): baseline OS shutdown hung ~290s + 6008/41; with this patch the collector is stopped via its own SCM entry in ~34s (Event ID 6006, no 6008/41). sc stop still ~0.3s.
kardianos/service v1.2.1's windowsService.Run returns as soon as SCM STOP
is processed, which lets main return and the Go runtime call ExitProcess
before otelcol.Shutdown (running on a parallel goroutine) can complete.
In the pristine change this rarely mattered because Shutdown is intrinsically
sub-second, but a slow-shutdown plugin, a network flush, or any future
teardown work could be truncated -- the final "Shutdown complete." log
line and any pending flushes would be dropped without any indication.
Add a done-channel signalled by (*program).run and waited on by main
after s.Run() returns:
- shutdown_signal.go: runCompleteChan (chan struct{}) plus sync.Once
guard, runCompleteTimeout = 30s, signalRunComplete(), waitRunComplete().
- amazon-cloudwatch-agent.go: (*program).run defers signalRunComplete
so it fires on every code path, including the Windows fallback where
handleTerminatingSignal calls os.Exit. main's Windows service branch
waits on runCompleteChan after s.Run returns.
kardianos still reports SERVICE_STOPPED to SCM as soon as prg.Stop
returns, so the OS shutdown of other services proceeds in parallel.
Only this process is held back, and only until its own teardown finishes
-- capped at runCompleteTimeout so a stuck teardown cannot indefinitely
hold up the OS.
Tests: three new unit tests (idempotent signal, wait-then-signal,
wait-then-timeout). All 47 existing + new tests pass.
Empirically validated on Windows Server 2022: with a 10-second sleep
injected inside otelcol Service.Shutdown, the earlier change loses the
"Shutdown complete." log line entirely (main returns before Shutdown
finishes), whereas with this wait the line is preserved and the full
teardown sequence completes. No 6008 / Kernel-Power 41; total OS
shutdown +10s (matching the injected delay).
6359247 to
15cb73d
Compare
|
This PR was marked stale due to lack of activity. |
Description of the issue
Related issue: Fixes #2214
At OS shutdown, when the collector runs as a Windows service child (spawned by
start-amazon-cloudwatch-agent.exe), csrss deliversCTRL_SHUTDOWNto the child (mapped toSIGTERMby the Go runtime) but the SCM does not routeSERVICE_CONTROL_SHUTDOWNto it (that goes to the SCM-registered launcher).kardianos/servicev1.2.1's non-interactiveRun()waits only on the SCM channel and does not watchSIGTERM, sosvc.Runnever returns,mainnever returns, and the runtime'sctrlHandleris parked inblock(). csrss meanwhile waits for the process to exit; the whole system shutdown deadlocks (~4–5 min →Event ID 6008+Kernel-Power 41).sc stop/Stop-Service(SCM STOP viaControlService) is unaffected.The issue is scoped to non-container Windows service installs: Windows containers take the
-console truepath atcmd/start-amazon-cloudwatch-agent/path_windows.go:43and exit cleanly, and non-Windows builds callreloadLoopdirectly frommain, both of which are unaffected.kardianosalready acceptsSERVICE_CONTROL_SHUTDOWNviacmdsAcceptedatservice_windows.go:182, so the handler is present — the deadlock in stage 1 (SIGTERM inblock()) simply prevents stage 2 (the SCM shutdown control) from ever being reached.Description of changes
Minimal, scoped, and no-op outside the affected case. When a non-SIGHUP terminating OS signal reaches
reloadLoop's signal goroutine and we're running as a Windows service, this PR issuesSERVICE_CONTROL_STOPagainst our own SCM entry viax/sys/windows/svc/mgr, then lets kardianos's normal STOP path (prg.Stop→close(stop)) drivesvc.Runto return cleanly. Falls back toos.Exit(0)only if the SCM path is unavailable.Why not
kardianos/service.Service.Stop()directly: kardianos looks up the service by its ownConfig.Name(*fServiceName, default"telegraf"here), which is not registered in the SCM. The collector's real SCM registration isAmazonCloudWatchAgent(or whatever the operator installed under--service-name), and itsProcessIdin the SCM points to the collector (SCM tracks the collector's PID, not the launcher's, after the launcher's SetServiceStatus handoff). We discover this entry by enumerating SCM services and matchingProcessIdagainstos.Getpid()— no hardcoded name, so custom--service-nameinstallations continue to work.cmd/amazon-cloudwatch-agent/amazon-cloudwatch-agent.go(2 hunks / +6 lines):reloadLoop's signal goroutine, on a non-SIGHUP terminating signal, callhandleTerminatingSignalDispatch(stop, stopWaitTimeout). It tries SCM STOP first and blocks on<-stop(bounded bystopWaitTimeout= 30s). On failure or timeout, setsterminatingSignalReceived. Then the existingcancel()runs.(*program).run(), afterreloadLoopreturns, callhandleTerminatingSignal()— the fallback whichos.Exit(0)s iff the flag was set.New files under
cmd/amazon-cloudwatch-agent/:shutdown_signal.go— package-level state (stopWaitTimeout,terminatingSignalReceived atomic.Bool,requestSCMStopFntest seam) and the cross-platformhandleTerminatingSignalDispatch(stopCh, timeout).shutdown_signal_windows.go— the Windows implementation: minimalscmManager/scmServiceinterfaces (so tests can substitute fakes) with concrete adapters overwinmgr.Mgr/winmgr.Service, four test seams (exitFunc,isWinService,ownProcessID,scmConnectFunc),findOwnSCMServiceName(m)(enumerate + match ProcessId, skips ACCESS_DENIED and Query errors),requestSCMStop()(Connect → find → Control(Stop)), andhandleTerminatingSignal()(fallbackexitFunc(0)).shutdown_signal_notwindows.go—requestSCMStop() { return false }andhandleTerminatingSignal() {}under//go:build !windows.shutdown_signal_test.go— cross-platform tests: 3 atomic-flag tests + 3 dispatch tests using therequestSCMStopFnseam (success path, SCM-unavailable path, SCM-accepted-but-timeout path).shutdown_signal_windows_test.go— Windows-only tests using fakescmManager/scmService: 5findOwnSCMServiceNamescenarios (match-by-PID / no-match / ListServices error / skips-OpenService-errors / skips-Query-errors), 5requestSCMStopscenarios (not-a-service / Connect fail / no-matching-service / Control fail / success), and 3handleTerminatingSignalscenarios (flag-unset / not-a-service / flag+service → exit).Follow-up: main waits for teardown before ExitProcess
Once SCM STOP unblocks
svc.Run,mainreturns and the Go runtime callsExitProcess. Butotelcol.Shutdownruns on a parallel goroutine (from otelcol's own SIGTERM handler); if it hasn't finished by the timemainreturns, its teardown is truncated — the final"Shutdown complete."log line and any pending flushes are dropped silently. In practice on this codebaseShutdownis intrinsically sub-second so the race is rarely observable, but a slow-shutdown plugin, a network flush, or any future teardown work would surface it.The second commit (
15cb73d) adds a done-channel signalled by(*program).runand waited on bymainafters.Run()returns:shutdown_signal.go(+30 lines):runCompleteChan(chan struct{}) plussync.Onceguard,runCompleteTimeout = 30s,signalRunComplete(),waitRunComplete().amazon-cloudwatch-agent.go(+4 lines):(*program).rundeferssignalRunCompleteso it fires on every normal return path.main's Windows service branch waits onrunCompleteChanafters.Runreturns.shutdown_signal_test.go(+66 lines): 3 new tests — idempotent signal, wait-then-signal, wait-then-timeout.kardianos still reports
SERVICE_STOPPEDto SCM as soon asprg.Stopreturns, so the OS shutdown of other services proceeds in parallel. Only this process is held back, and only until its own teardown finishes — capped atrunCompleteTimeoutso a stuck teardown cannot indefinitely hold up the OS. The Windows-fallbackos.Exit(0)path is unaffected:deferdoesn't run onos.Exit, but the process terminates immediately anyway, which is the intended behaviour of that fallback.Behaviour matrix:
sc stop→ prg.Stop → close(stop))<-stopbranch of outer select)cancel()cancel()false(compile-time no-op)terminatingSignalReceived.Store(true); cancel()windowsRunAsService()==false)falsetrue<-stopfires →cancel()falsecancel()os.Exit(0)truethen timeoutcancel()os.Exit(0)No new module dependencies (
golang.org/x/sysis already ingo.mod; the workaround uses itswindows/svcandwindows/svc/mgrsubpackages).License
By submitting this pull request, I confirm that you can use, modify, copy, and redistribute this contribution, under the terms of your choice.
Tests
Unit tests (new) — 22 tests in total, all passing.
Cross-platform (
shutdown_signal_test.go, 9 tests):TestTerminatingSignalReceived_DefaultUnset/_SetLoad/_Race: package-levelatomic.Boolsemantics (Race launches 64 goroutines, safe under-race).TestDispatch_SCMUnavailable_SetsFallbackFlag:requestSCMStopFn=false→ fallback flag set.TestDispatch_SCMSuccess_NoFallbackFlag:requestSCMStopFn=true+close(stop)before timeout → fallback flag NOT set.TestDispatch_SCMAcceptedButTimeout_SetsFallbackFlag:requestSCMStopFn=true+ timeout expires → fallback flag set.TestSignalRunComplete_Idempotent:signalRunCompleteusessync.Onceso a double invocation does not panic on a closed channel.TestWaitRunComplete_ReturnsWhenSignaled:waitRunCompletereturns promptly oncesignalRunCompletefires.TestWaitRunComplete_TimesOut:waitRunCompletefalls through afterrunCompleteTimeoutwhen no signal arrives.Windows-only (
shutdown_signal_windows_test.go, 13 tests) using fakescmManager/scmService+ seams:TestFindOwnSCMServiceName_MatchByPID/_NoMatch/_ListServicesError/_SkipsOpenErrors/_SkipsQueryErrors: enumeration finds the entry by ProcessId; robust against per-service ACCESS_DENIED and Query errors; every opened service isClose()d.TestRequestSCMStop_NotAService/_ConnectFail/_NoMatchingService/_ControlSTOPFail/_Success: each failure mode returnsfalseand cleans up (Disconnect,Close); the success path issueswinsvc.Stop.TestHandleTerminatingSignal_FlagUnset_NoExit/_NotAService_NoExit/_FlagSetAndService_Exits:exitFunc(0)is called only when both preconditions hold.Result on the validation host (
go test -v -count=1 ./cmd/amazon-cloudwatch-agent -run '^(TestTerminatingSignalReceived|TestDispatch|TestSignalRunComplete|TestWaitRunComplete|TestFindOwnSCMServiceName|TestRequestSCMStop|TestHandleTerminatingSignal)'):go test -race— same 22 tests, executed withCGO_ENABLED=1and gcc from MinGW-w64 14.2.0 for the race detector. All 22 PASS, no data races reported.Static checks — executed against a fresh clone of
main+ this PR's commit on Windows Server 2022 with Go 1.25.8. Tools installed via the samego install/ release-download commands the Makefile uses.go fmt ./...— clean.goimports -l -local github.com/aws/amazon-cloudwatch-agenton the six touched/new files — all clean.impi --local github.com/aws/amazon-cloudwatch-agent --scheme stdThirdPartyLocalon the six files — all clean.addlicense -check -l MIT -c "Amazon.com, Inc. or its affiliates."on the six files — all rc=0.go vet ./cmd/amazon-cloudwatch-agentreports one finding at line 120 (sigchanyzer: misuse of unbuffered os.Signal channel as argument to signal.Notify, fromsignals := make(chan os.Signal)). This finding is present onmainat HEAD~1 as well and is unrelated to this PR.golangci-lint run --timeout 5m ./cmd/amazon-cloudwatch-agent(v2.12.2 — the Makefile version) reports 7 findings on this PR and 7 findings onmainat HEAD~2.Compare-Objectbetween the two runs: NEW findings: 0, REMOVED findings: 0. The three lines that appear in the raw diff (G706269→273,G114523→530,revive superfluous-else635→642) are the same rules on the same statements, shifted downward by the lines these two commits add above each finding (+4, +7, +7 respectively; total +10 lines added toamazon-cloudwatch-agent.go). All findings are on code paths this PR does not touch.End-to-end (Windows Server 2022, EC2 m5.xlarge) — same host used for the reproduction, with
WaitToKillServiceTimeout=300000to expose the deadlock. Wrapper left pristine; only the collector rebuilt.Five scenarios were run, isolating the effect of each commit:
"Shutdown complete."loggedmain6008+Kernel-Power 41main+ a6a1a93main+ a6a1a93 + 10 s sleep injected insideService.Shutdown(validation only, not part of PR)main+ a6a1a93 + 15cb73d + the same 10 s sleep injected insideService.Shutdownmain+ a6a1a93 + 15cb73d (this PR head)Rows 3 → 4 form the direct A/B: same teardown-slowing patch, only difference is the wait mechanism from commit
15cb73d. In row 3 the process was terminated duringotelcol.Shutdown(Event 7036 recorded the CWA "Stopped" transition at the same millisecond the sleep started); in row 4mainblocked inwaitRunCompleteuntil the full teardown sequence completed and only then returned.Row 5 confirms the wait mechanism adds no observable overhead in the normal case: every teardown log entry lands in the same second, SCM records the "Stopped" transition ~ms later, and total OS shutdown is well within the same range as row 2 (both are within observed EC2 platform variance for this instance).
Agent log around shutdown in scenario 4:
In scenario 3 (same test without the wait) everything after "SCM Control(Stop) accepted" was cut off.
Agent log around shutdown in scenario 5 (production representative — both commits, no injected delay):
System event log in scenarios 2/4/5:
1074(shutdown initiated) →6006(EventLog stopped normally) →7036(AmazonCloudWatchAgenttransitioned to Stopped). No6008, no41.sc stopunchanged (~0.3 s).Requirements
Before commiting your code, please do the following steps.
make fmtandmake fmt-shmake lintIntegration Tests
To run integration tests against this PR, add the
ready for testinglabel.