Skip to content
This repository has been archived by the owner on Oct 13, 2023. It is now read-only.

[18.09 backport] Ensure all integration daemon logging happens before test exit #246

Conversation

thaJeztah
Copy link
Member

backport of moby#39197 for 18.09

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.

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>
(cherry picked from commit 7546322)
Signed-off-by: Sebastiaan van Stijn <github@gone.nl>
@thaJeztah thaJeztah added this to the 18.09.7 milestone May 25, 2019
@thaJeztah
Copy link
Member Author

@kolyshkin @tiborvass PTAL

Copy link

@andrewhsu andrewhsu left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

LGTM

@andrewhsu andrewhsu merged commit 08f6e9c into docker:18.09 Jun 17, 2019
@thaJeztah thaJeztah deleted the 18.09_backport_log-daemon-exit-before-tests-finish branch June 17, 2019 19:15
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
None yet
Projects
None yet
4 participants