Unit test failure "reaper must be started"

[dimaqq]

Happened once in GHA, but I can't reproduce locally (yet).
First seen after merging the UDP syslog from master into the fips branch.

panic: internal error: reaper must be started

goroutine 232 [running]:
github.com/canonical/pebble/internals/reaper.StartCommand(0xc0001afc80)
	/home/runner/work/pebble/pebble/internals/reaper/reaper.go:169 +0x3b2
github.com/canonical/pebble/internals/overlord/checkstate.(*execChecker).check(0xc0004e2310, {0xd5d328, 0xc0001ff6c0})
	/home/runner/work/pebble/pebble/internals/overlord/checkstate/checkers.go:192 +0xd5f
github.com/canonical/pebble/internals/overlord/checkstate.runCheck({0xd5d2b8, 0xc0000e6870}, {0xd584c0, 0xc0004e2310}, 0x5f5e100)
	/home/runner/work/pebble/pebble/internals/overlord/checkstate/handlers.go:137 +0xb9
github.com/canonical/pebble/internals/overlord/checkstate.(*CheckManager).doRecoverCheck.func1()
	/home/runner/work/pebble/pebble/internals/overlord/checkstate/handlers.go:167 +0xe5
github.com/canonical/pebble/internals/overlord/checkstate.(*CheckManager).doRecoverCheck(0xc000023a00, 0xc0001cab40, 0xc0001bc3c0)
	/home/runner/work/pebble/pebble/internals/overlord/checkstate/handlers.go:211 +0xae2
github.com/canonical/pebble/internals/overlord/state.(*TaskRunner).run.func1()
	/home/runner/work/pebble/pebble/internals/overlord/state/taskrunner.go:220 +0xa3
gopkg.in/tomb%2ev2.(*Tomb).run(0xc0001bc3c0, 0xc000193d70)
	/home/runner/go/pkg/mod/gopkg.in/tomb.v2@v2.0.0-20161208151619-d5d1b5820637/tomb.go:163 +0x3c
created by gopkg.in/tomb%2ev2.(*Tomb).Go in goroutine 182
	/home/runner/go/pkg/mod/gopkg.in/tomb.v2@v2.0.0-20161208151619-d5d1b5820637/tomb.go:159 +0x197
FAIL	github.com/canonical/pebble/internals/overlord/servstate	8.239s
?   	github.com/canonical/pebble/internals/overlord/servstate/servstatetest	[no test files]
ok  	github.com/canonical/pebble/internals/overlord/standby	1.125s
ok  	github.com/canonical/pebble/internals/overlord/state	27.535s
ok  	github.com/canonical/pebble/internals/plan	1.168s
ok  	github.com/canonical/pebble/internals/progress	1.952s
?   	github.com/canonical/pebble/internals/progress/progresstest	[no test files]
?   	github.com/canonical/pebble/internals/ptyutil	[no test files]
?   	github.com/canonical/pebble/internals/reaper	[no test files]
ok  	github.com/canonical/pebble/internals/servicelog	2.202s
ok  	github.com/canonical/pebble/internals/systemd	1.096s
ok  	github.com/canonical/pebble/internals/testutil	1.049s
ok  	github.com/canonical/pebble/internals/timeutil	1.031s
ok  	github.com/canonical/pebble/internals/timing	1.019s
ok  	github.com/canonical/pebble/internals/workloads	1.022s
?   	github.com/canonical/pebble/internals/wsutil	[no test files]
FAIL

[dimaqq]

https://github.com/canonical/pebble/actions/runs/20054056749/job/57515630944?pr=734

[dimaqq]

One more, also in the fips branch
https://github.com/canonical/pebble/actions/runs/20120328675/job/57738884233?pr=751

[dimaqq]

Another, in a PR targeting the master branch, should have nothing to do with FIPS, I think.

https://github.com/canonical/pebble/actions/runs/19885968666/job/56993263105

[dimaqq]

Another, non-fips:
https://github.com/canonical/pebble/actions/runs/19885899516/job/56992979175

[benhoyt]

I suspect the unit tests are failing more often on the fips branch due to a test ordering issue (we've removed tests so something is surfacing now that wasn't before). Are you able to repro locally, either on master or on fips perhaps with the stress tool?

Would be great if you can spend some time on this. Perhaps we can look together on Monday?

[dimaqq]

I'm trying the stress tool, however we've got some tests that check timeouts in millisecond range, and stress -p 32 makes those trip, which means it's not trivial to isolate the offender.

[dimaqq]

After the discussion, the likely reason is this:

Several tests start a manager, that runs checks, and when the test is done, replan the manager to disable checks.

However, the checks are not terminated synchronously.

Thus a check may still fire after a test is done.

In some cases, this could happen when the teardown has finished, and there's not "reaper".

The linked CI runs show that all tests have been run to completion (or skipped), and then the test binary panics:

2025-12-03T07:28:29.7737195Z START: manager_test.go:1854: S.TestWorkloadAppliesToService
2025-12-03T07:28:29.7737762Z START: manager_test.go:137: S.SetUpTest
2025-12-03T07:28:29.7738233Z PASS: manager_test.go:137: S.SetUpTest	0.000s
2025-12-03T07:28:29.7738551Z 
2025-12-03T07:28:29.7739059Z 2025-12-03T07:28:29.550Z [test] Service "test1" starting: /bin/sh -c "echo $PATH; sleep 10"
2025-12-03T07:28:29.7740050Z 2025-12-03T07:28:29.621Z [test] Check "chk1" failure 53/1: exec: "will-fail": executable file not found in $PATH
2025-12-03T07:28:29.7740814Z START: manager_test.go:174: S.TearDownTest
2025-12-03T07:28:29.7741303Z 2025-12-03T07:28:29.703Z [test] Service "test1" stopped
2025-12-03T07:28:29.7741838Z PASS: manager_test.go:174: S.TearDownTest	0.001s
2025-12-03T07:28:29.7742163Z 
2025-12-03T07:28:29.7742478Z PASS: manager_test.go:1854: S.TestWorkloadAppliesToService	0.153s
2025-12-03T07:28:29.7742909Z 
2025-12-03T07:28:29.7743187Z START: manager_test.go:1883: S.TestWorkloadReferenceInvalid
2025-12-03T07:28:29.7743745Z START: manager_test.go:137: S.SetUpTest
2025-12-03T07:28:29.7744210Z PASS: manager_test.go:137: S.SetUpTest	0.000s
2025-12-03T07:28:29.7744497Z 
2025-12-03T07:28:29.7744680Z START: manager_test.go:174: S.TearDownTest
2025-12-03T07:28:29.7745163Z PASS: manager_test.go:174: S.TearDownTest	0.000s
2025-12-03T07:28:29.7745495Z 
2025-12-03T07:28:29.7745806Z PASS: manager_test.go:1883: S.TestWorkloadReferenceInvalid	0.001s
2025-12-03T07:28:29.7746238Z 
2025-12-03T07:28:29.7746597Z OK: 50 passed, 1 skipped
2025-12-03T07:28:29.7746973Z PASS
2025-12-03T07:28:29.7747324Z panic: internal error: reaper must be started

[dimaqq]

Note to self: the faster way to repro locally:

• in internals/overlord/servstate/manager_test.go change four plans to period: 1ms
• while go test -race ./internals/overlord/servstate -count=10 -p 16 > /tmp/err; date; end