Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

testing: Logf not reported outside of inner benchmark run #29211

Open
griesemer opened this issue Dec 13, 2018 · 1 comment
Assignees
Milestone

Comments

@griesemer
Copy link
Contributor

@griesemer griesemer commented Dec 13, 2018

Applying the following patch illustrates the problem:

diff --git a/src/go/format/benchmark_test.go b/src/go/format/benchmark_test.go
index 7bd45c0e95..62131e0977 100644
--- a/src/go/format/benchmark_test.go
+++ b/src/go/format/benchmark_test.go
@@ -58,6 +58,7 @@ var tests = []struct {
 }
 
 func BenchmarkFormat(b *testing.B) {
+       b.Logf("foo") // <<< not reported
        var src bytes.Buffer
        for _, t := range tests {
                src.Reset()
@@ -74,6 +75,7 @@ func BenchmarkFormat(b *testing.B) {
                }
 
                b.Run(fmt.Sprintf("%s-%d", t.name, t.n), func(b *testing.B) {
+                       b.Logf("foo") // <<< reported
                        b.SetBytes(int64(len(data)))
                        b.ReportAllocs()
                        b.ResetTimer()

When running this benchmark, the outer b.Logf call doesn't get reported in the output.

I expected to see both.

@griesemer griesemer added this to the Go1.13 milestone Dec 13, 2018
@odeke-em

This comment has been minimized.

Copy link
Member

@odeke-em odeke-em commented Jun 10, 2019

Thank you for this report @griesemer and sorry that we didn't get to this during the Go1.13 cycle!

In deed, this bug appears due to us not following the promise of b.Logf
Screen Shot 2019-06-09 at 4 56 05 PM

while sub-benchmarks follows that the output will ALWAYS be logged.

If you set -v it'll then be printed out.

Seems like this behavior was introduced by CL https://go-review.googlesource.com/c/go/+/21504/ and in particular I believe this line might be the cause

if b.chatty && (len(b.output) > 0 || b.finished) {

Updating it to

diff --git a/src/testing/benchmark.go b/src/testing/benchmark.go
index 0e348be358..2c88f3f2ee 100644
--- a/src/testing/benchmark.go
+++ b/src/testing/benchmark.go
@@ -241,7 +241,7 @@ func (b *B) run1() bool {
 		if b.skipped {
 			tag = "SKIP"
 		}
-		if b.chatty && (len(b.output) > 0 || b.finished) {
+		if len(b.output) > 0 || b.finished {
 			b.trimOutput()
 			fmt.Fprintf(b.w, "--- %s: %s\n%s", tag, b.name, b.output)
 		}

produces the right effect and doesn't fail the pre-existing tests. What do you think @mpvl? Shall we punt this to Go1.14 and label it Early-In-Cycle or can it be added for Go1.13?

@andybons andybons modified the milestones: Go1.13, Go1.14 Jul 8, 2019
@rsc rsc modified the milestones: Go1.14, Backlog Oct 9, 2019
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
5 participants
You can’t perform that action at this time.