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 <danieljsweet@icloud.com>
This commit is contained in:
Daniel Sweet 2019-05-09 13:14:20 -04:00
parent 994007dd89
commit 7546322e99
1 changed files with 4 additions and 1 deletions

View File

@ -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)
}()