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.

Sign up for GitHub

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

Jump to bottom

cmd/test2json: missing pass/fail action on individual benchmark #61767

Open
hugelgupf opened this issue Aug 4, 2023 · 2 comments
Open

cmd/test2json: missing pass/fail action on individual benchmark #61767

hugelgupf opened this issue Aug 4, 2023 · 2 comments
Labels
help wanted NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one.
Milestone
Backlog

Comments

@hugelgupf
Copy link
Contributor

hugelgupf commented Aug 4, 2023 •
edited

What version of Go are you using (go version)?

$ go version
go1.22-20230729-RC00

What operating system and processor architecture are you using (go env)?

Not relevant - omitting

What did you do?

File foo_test.go:

package foo_x_test

import (
        "testing"
)

func TestFoo(t *testing.T) {
        t.Logf("hello")
}

func fib(n int) int {
        if n < 2 {
                return n
        }
        return fib(n-1) + fib(n-2)
}

func BenchmarkFib10(b *testing.B) {
        for n := 0; n < b.N; n++ {
                fib(10)
        }
}

Run go test -json -bench=. foo_test.go

Result:

{"Time":"2023-08-04T12:37:32.630848007-07:00","Action":"start","Package":"command-line-arguments"}
{"Time":"2023-08-04T12:37:32.674050117-07:00","Action":"run","Package":"command-line-arguments","Test":"TestFoo"}
{"Time":"2023-08-04T12:37:32.674089527-07:00","Action":"output","Package":"command-line-arguments","Test":"TestFoo","Output":"=== RUN   TestFoo\n"}
{"Time":"2023-08-04T12:37:32.674121806-07:00","Action":"output","Package":"command-line-arguments","Test":"TestFoo","Output":"    foo_test.go:8: hello\n"}
{"Time":"2023-08-04T12:37:32.674136934-07:00","Action":"output","Package":"command-line-arguments","Test":"TestFoo","Output":"--- PASS: TestFoo (0.00s)\n"}
{"Time":"2023-08-04T12:37:32.674152436-07:00","Action":"pass","Package":"command-line-arguments","Test":"TestFoo","Elapsed":0}
{"Time":"2023-08-04T12:37:32.67656493-07:00","Action":"output","Package":"command-line-arguments","Output":"goos: linux\n"}
{"Time":"2023-08-04T12:37:32.676585644-07:00","Action":"output","Package":"command-line-arguments","Output":"goarch: amd64\n"}
{"Time":"2023-08-04T12:37:32.676599219-07:00","Action":"output","Package":"command-line-arguments","Output":"cpu: Intel(R) Xeon(R) W-2135 CPU @ 3.70GHz\n"}
{"Time":"2023-08-04T12:37:32.676610204-07:00","Action":"run","Package":"command-line-arguments","Test":"BenchmarkFib10"}
{"Time":"2023-08-04T12:37:32.676619064-07:00","Action":"output","Package":"command-line-arguments","Test":"BenchmarkFib10","Output":"=== RUN   BenchmarkFib10\n"}
{"Time":"2023-08-04T12:37:32.676630118-07:00","Action":"output","Package":"command-line-arguments","Test":"BenchmarkFib10","Output":"BenchmarkFib10\n"}
{"Time":"2023-08-04T12:37:34.248814597-07:00","Action":"output","Package":"command-line-arguments","Test":"BenchmarkFib10","Output":"BenchmarkFib10-6   \t 1922632\t       602.9 ns/op\n"}
{"Time":"2023-08-04T12:37:34.248879794-07:00","Action":"output","Package":"command-line-arguments","Output":"PASS\n"}
{"Time":"2023-08-04T12:37:34.250175678-07:00","Action":"output","Package":"command-line-arguments","Output":"ok  \tcommand-line-arguments\t1.619s\n"}
{"Time":"2023-08-04T12:37:34.250212919-07:00","Action":"pass","Package":"command-line-arguments","Elapsed":1.619}

What did you expect to see?

Note that TestFoo gets a line with an individual test result --

{"Time":"2023-08-04T12:37:32.674152436-07:00","Action":"pass","Package":"command-line-arguments","Test":"TestFoo","Elapsed":0}

This is missing for BenchmarkFib10.

Expected to see:

{"Time":"<>","Action":"pass","Package":"command-line-arguments","Test":"BenchmarkFib10","Elapsed":0}

After Fib10 passes.

Really, this likely means that BenchmarkFib10 needs to be framed with a --- (PASS|SKIP|FAIL): BenchmarkFib10 (0.00s)\n at the end when -test.v=test2json is passed to the test binary as well.

(Previous work in this area fixed most of the test2json issues I've seen, cc @rsc -- https://go-review.googlesource.com/c/go/+/443596)
@dr2chase
Copy link
Contributor

dr2chase commented Aug 4, 2023

This might be working-as-intended. Consider the output of test -v when running a single test or a single benchmark:

go test -count=1 -v foo_test.go
=== RUN   TestFoo
    foo_test.go:8: hello
--- PASS: TestFoo (0.00s)
PASS
ok  	command-line-arguments	0.153s

and

go test -count=1 -bench=. -run=asdfasdf -v foo_test.go
goos: darwin
goarch: amd64
cpu: Intel(R) Core(TM) i5-1038NG7 CPU @ 2.00GHz
BenchmarkFib10
BenchmarkFib10-8   	 3682909	       323.3 ns/op
PASS
ok  	command-line-arguments	1.676s

Notice how there's no "PASS" printed for the benchmark itself, only the summary "PASS" at the end.

On the other hand, maybe that was a mistake, and it can be fixed in the json case.

cc @bcmills also.

@dr2chase dr2chase added the NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. label Aug 4, 2023
@hugelgupf
Copy link
Contributor Author

hugelgupf commented Aug 5, 2023 •
edited

Hey David!

This is why I left the breadcrumb of https://go-review.googlesource.com/c/go/+/443596. That CL intentionally introduces the behavior that when -test.v=test2json is set, === RUN BenchmarkFib10 is emitted, but it failed to add the finishing PASS|FAIL|SKIP line for benchmarks. (I don't know what the status of fuzz tests is, I haven't tried, but they may suffer from the same?)

Try this:

$ go test -c -o foo_test foo_test.go

$ ./foo_test -test.v -test.bench=.
=== RUN   TestFoo
    foo_test.go:8: hello
--- PASS: TestFoo (0.00s)
goos: linux
goarch: amd64
cpu: Intel(R) Xeon(R) W-2135 CPU @ 3.70GHz
BenchmarkFib10
BenchmarkFib10-6         1958179               601.7 ns/op
PASS

$ ./foo_test -test.v=test2json -test.bench=.
# OR evidently this works too:
$ go test -v=test2json -bench=. foo_test.go
=== RUN   TestFoo
    foo_test.go:8: hello
--- PASS: TestFoo (0.00s)
=== NAME  
goos: linux
goarch: amd64
cpu: Intel(R) Xeon(R) W-2135 CPU @ 3.70GHz
=== RUN   BenchmarkFib10
BenchmarkFib10
BenchmarkFib10-6         1920415               600.3 ns/op
=== NAME  
PASS

@bcmills bcmills added this to the Backlog milestone Aug 7, 2023
@AlekSi AlekSi mentioned this issue Oct 16, 2023
Merged
9 tasks
@lmb lmb mentioned this issue Dec 1, 2023
Open
lmb added a commit to lmb/ebpf that referenced this issue Dec 1, 2023
@lmb
CI: remove gotestsum postprocessing
5ca206d 
gotestsum can't properly process benchmark results due to a go toolchain
bug. Remove the postprocessing, since we don't benefit as much now that
we don't use Semaphore CI anymore (which had nice visualisation for
JUnit output).

See golang/go#61767

Signed-off-by: Lorenz Bauer <lmb@isovalent.com>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
help wanted NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one.
Projects
None yet
Milestone
Backlog
Development

No branches or pull requests
3 participants
@dr2chase @hugelgupf @bcmills