From 7546322e994c4a23ea3cae0cf0a2a8019de12c03 Mon Sep 17 00:00:00 2001 From: Daniel Sweet Date: Thu, 9 May 2019 13:14:20 -0400 Subject: [PATCH] Ensure all integration daemon logging happens before test exit As of Go 1.12, the `testing` package panics if a goroutine logs to a `testing.T` after the relevant test has completed. This was not documented as a change at all; see the commit 95d06ab6c982f58b127b14a52c3325acf0bd3926 in the Go repository for the relevant change. At any point in the integration tests, tests could panic with the message "Log in goroutine after TEST_FUNCTION has completed". This was exacerbated by less direct logging I/O, e.g. running `make test` with its output piped instead of attached to a TTY. The most common cause of panics was that there was a race condition between an exit logging goroutine and the `StopWithError` method: `StopWithError` could return, causing the calling test method to return, causing the `testing.T` to be marked as finished, before the goroutine could log that the test daemon had exited. The fix is simple: capture the result of `cmd.Wait()`, _then_ log, _then_ send the captured result over the `Wait` channel. This ensures that the message is logged before `StopWithError` can return, blocking the test method so that the target `testing.T` is not marked as finished. Signed-off-by: Daniel Sweet --- internal/test/daemon/daemon.go | 5 ++++- 1 file changed, 4 insertions(+), 1 deletion(-) diff --git a/internal/test/daemon/daemon.go b/internal/test/daemon/daemon.go index d9bf53dbd9..cb94d80631 100644 --- a/internal/test/daemon/daemon.go +++ b/internal/test/daemon/daemon.go @@ -271,8 +271,11 @@ func (d *Daemon) StartWithLogFile(out *os.File, providedArgs ...string) error { wait := make(chan error) go func() { - wait <- d.cmd.Wait() + ret := d.cmd.Wait() d.log.Logf("[%s] exiting daemon", d.id) + // If we send before logging, we might accidentally log _after_ the test is done. + // As of Go 1.12, this incurs a panic instead of silently being dropped. + wait <- ret close(wait) }()