testutil: NewLogBuffer - buffer logs until a test fails #7948
Conversation
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Closed
|
Another nice property of this approach seems to be that when multiple agents are run in a test case, all of the logs for a single agent are grouped together. I suspect previously they would have been interspersed. It also means that all assertion failures will appear first before any logs, which should make them easier to find in the output. |
dnephin
force-pushed
the
dnephin/buffer-test-logs
branch
2 times, most recently
from
7312c44
to
3e038dd
Compare
Replaces #7559 Running tests in parallel, with background goroutines, results in test output not being associated with the correct test. `go test` does not make any guarantees about output from goroutines being attributed to the correct test case. Attaching log output from background goroutines also cause data races. If the goroutine outlives the test, it will race with the test being marked done. Previously this was noticed as a panic when logging, but with the race detector enabled it is shown as a data race. The previous solution did not address the problem of correct test attribution because test output could still be hidden when it was associated with a test that did not fail. You would have to look at all of the log output to find the relevant lines. It also made debugging test failures more difficult because each log line was very long. This commit attempts a new approach. Instead of printing all the logs, only print when a test fails. This should work well when there are a small number of failures, but may not work well when there are many test failures at the same time. In those cases the failures are unlikely a result of a specific test, and the log output is likely less useful. All of the logs are printed from the test goroutine, so they should be associated with the correct test. Also removes some test helpers that were not used, or only had a single caller. Packages which expose many functions with similar names can be difficult to use correctly. Related: golang/go#38458 (may be fixed in go1.15) golang/go#38382 (comment)
dnephin
force-pushed
the
dnephin/buffer-test-logs
branch
from
3e038dd
to
51efba2
Compare
|
🍒✅ Cherry pick of commit 3570ce6 onto |
hashicorp-ci
pushed a commit
that referenced
this pull request
Jul 21, 2020
testutil: NewLogBuffer - buffer logs until a test fails
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.
This suggestion is invalid because no changes were made to the code.
Suggestions cannot be applied while the pull request is closed.
Suggestions cannot be applied while viewing a subset of changes.
Only one suggestion per line can be applied in a batch.
Add this suggestion to a batch that can be applied as a single commit.
Applying suggestions on deleted lines is not supported.
You must change the existing code in this line in order to create a valid suggestion.
Outdated suggestions cannot be applied.
This suggestion has been applied or marked resolved.
Suggestions cannot be applied from pending reviews.
Suggestions cannot be applied on multi-line comments.
Suggestions cannot be applied while the pull request is queued to merge.
Suggestion cannot be applied right now. Please check back later.
Replaces #7559
Fixes this data race (and likely many others): #8329 (comment)
Running tests in parallel, with background goroutines, results in test output not being associated with the correct test.
go testdoes not make any guarantees about output from goroutines being attributed to the correct test case.Attaching log output from background goroutines also cause data races. If the goroutine outlives the test, it will race with the test being marked done. Previously this was noticed as a panic when logging, but with the race detector enabled it is shown as a data race.
This commit attempts a new approach. Instead of printing all the logs, only print when a test fails. All of the logs are printed from the test goroutine, so they should be associated with the correct test.
Another nice property of this approach is that when multiple agents are run in a test case, all of the logs for a single agent are grouped together. Previously they would have been interspersed.
Also removes some test helpers that were not used, or only had a single caller. Packages which expose many functions with similar names can be difficult to use correctly.
Tested some of the data races locally with
-count=100to ensure they no long race with this change.Related:
golang/go#38458 (a regression in go1.14 that was just fixed in go1.14.6)
golang/go#38382 (comment)