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

x/build: race builder mixes benchmark and test failure output #9717

Closed
bradfitz opened this issue Jan 28, 2015 · 10 comments
Closed

x/build: race builder mixes benchmark and test failure output #9717

bradfitz opened this issue Jan 28, 2015 · 10 comments
Labels
Builders x/build issues (builders, bots, dashboards) FrozenDueToAge
Milestone

Comments

@bradfitz
Copy link
Contributor

The output of race.bash is a mess. e.g.:

http://build.golang.org/log/0a062dae109415840b118fbc4189c83e7b5c068a

It's hard to see anything.

We plan to rewrite run.bash into Go. It's probably time that race.bash is also rewritten in Go, so it can capture the output of child processes and not interleave them all.

Dmitry, can you fix?

@dvyukov
Copy link
Member

dvyukov commented Jan 29, 2015

What exactly is a mess?
I do not see any interleaved output from different processes.
The bulk of the log is just output of 'go test -bench.* std'. So maybe there is something to fix in go test...

@minux
Copy link
Member

minux commented Jan 29, 2015

I think Brad just complains about the fact that if the race build breaks,
it's relatively hard to figure out what's happening by looking at the log.
(the real message is buried inside a lot of unrelated benchmark results.)

@dvyukov
Copy link
Member

dvyukov commented Jan 29, 2015

Hey, it is a punishment for anybody who introduces a data race.

Speaking seriously, ^F "data race" always worked for me.

@minux
Copy link
Member

minux commented Jan 29, 2015

Right. It's easy if you know what you're looking for.

But looking at the output of other builders doesn't require
searching, just scrolling down from the top, and it's quite
easy to spot the problem.

@bradfitz
Copy link
Contributor Author

Here's an example of garble:

https://storage.googleapis.com/go-build-log/df6b9696/linux-amd64-race_b0f4624a.log

ok      net 9.493s
PASS
BenchmarkHeaderWriteSubset-4                   10000         10202 ns/op         192 B/op          2 allocs/op
BenchmarkReadRequestChrome-4                    3000         37263 ns/op      16.40 MB/s        1664 B/op         16 allocs/op
BenchmarkReadRequestCurl-4                     10000         17212 ns/op       4.53 MB/s         896 B/op         11 allocs/op
BenchmarkReadRequestApachebench-4              10000         16772 ns/op       4.89 MB/s         896 B/op         11 allocs/op
BenchmarkReadRequestSiege-4                     5000         24549 ns/op       6.15 MB/s        1008 B/op         13 allocs/op
BenchmarkReadRequestWrk-4                      10000         11401 ns/op       3.51 MB/s         848 B/op          9 allocs/op
BenchmarkClientServer-4                          500        358113 ns/op       16030 B/op         81 allocs/op
BenchmarkClientServerParallel4-4                1000        155262 ns/op       16318 B/op         81 allocs/op
BenchmarkClientServerParallel64-4                300        635056 ns/op       26025 B/op        116 allocs/op
BenchmarkClientServerParallelTLS4-4                1     108462942 ns/op      202848 B/op       2940 allocs/op
BenchmarkClientServerParallelTLS64-4               1     118529698 ns/op      328888 B/op       4027 allocs/op
BenchmarkServer-4                                300        456277 ns/op        4213 B/op         24 allocs/op
BenchmarkClient-4                           --- FAIL: BenchmarkClient-4
    serve_test.go:2960: subprocess does not respond
BenchmarkServerFakeConnNoKeepAlive-4             500        330695 ns/op       13096 B/op         34 allocs/op
BenchmarkServerFakeConnWithKeepAlive-4          2000         65067 ns/op        4421 B/op         25 allocs/op
BenchmarkServerFakeConnWithKeepAliveLite-4      3000         44822 ns/op        3203 B/op         14 allocs/op
BenchmarkServerHandlerTypeLen-4                 2000         54727 ns/op        4116 B/op         23 allocs/op
BenchmarkServerHandlerNoLen-4                   3000         51966 ns/op        4035 B/op         20 allocs/op
BenchmarkServerHandlerNoType-4                  2000         54172 ns/op        4052 B/op         21 allocs/op
BenchmarkServerHandlerNoHeader-4                3000         47455 ns/op        3203 B/op         14 allocs/op
BenchmarkServerHijack-4                          500        242131 ns/op       11892 B/op         23 allocs/op
Too many goroutines running after net/http test(s).
1 instances of:
net/http_test.func·157()
    /tmp/buildlet-scatch184350621/go/src/net/http/serve_test.go:2949 +0x9d
created by net/http_test.BenchmarkClient
    /tmp/buildlet-scatch184350621/go/src/net/http/serve_test.go:2950 +0x8bb
exit status 1
FAIL    net/http    8.601s
PASS
ok      net/http/cgi    0.011s
PASS
ok      net/http/cookiejar  0.010s
PASS
ok      net/http/fcgi   0.011s
PASS
ok      net/http/httptest   0.011s
PASS
ok      net/http/httputil   0.010s
PASS
ok      net/http/internal   0.008s
?       net/http/pprof  [no test files]
PASS
ok      net/mail    0.007s
PASS
BenchmarkEndToEnd-4             2015/02/12 22:15:25 Test RPC server listening on 127.0.0.1:53559
2015/02/12 22:15:25 Test HTTP RPC server listening on 127.0.0.1:36029
     500        227635 ns/op
BenchmarkEndToEndHTTP-4              500        226008 ns/op
BenchmarkEndToEndAsync-4             500        218588 ns/op
BenchmarkEndToEndAsyncHTTP-4         500        228622 ns/op
ok      net/rpc 0.565s
PASS
ok      net/rpc/jsonrpc 0.015s
PASS
ok      net/smtp    0.011s
PASS
BenchmarkReadMIMEHeader-4       3000         36915 ns/op        1342 B/op         14 allocs/op
BenchmarkUncommon-4            20000          7419 ns/op         464 B/op          5 allocs/op
ok      net/textproto   0.358s
PASS
BenchmarkString-4       3000         50870 ns/op        2336 B/op         42 allocs/op
ok      net/url 0.177s
PASS
ok      os  0.009s

What is happening there?

@dvyukov
Copy link
Member

dvyukov commented Feb 13, 2015

^F "fail" is my second secret

@dvyukov dvyukov changed the title build: the race output is a mess cmd/gc: test output is a mess Feb 13, 2015
@rsc
Copy link
Contributor

rsc commented Apr 10, 2015

I don't see what this has to do with cmd/gc.

@rsc rsc changed the title cmd/gc: test output is a mess build: race.bash output is a mess Apr 10, 2015
@rsc rsc added this to the Unplanned milestone Apr 10, 2015
@dvyukov dvyukov changed the title build: race.bash output is a mess cmd/go: test output is a mess Apr 10, 2015
@dvyukov
Copy link
Member

dvyukov commented Apr 10, 2015

Sorry, the title meant to be cmd/go (or maybe testing:)
This is not race-related, as if you run the same command w/o -race output will be the same.
I don't think we need to fix anything here. Search on the page works well. And this is the only context where this came up.

@bradfitz
Copy link
Contributor Author

I'll fix this for free when the builders do test sharding probably.

@rsc rsc changed the title cmd/go: test output is a mess x/build: race builder mixes benchmark and test failure output Apr 14, 2015
@rsc rsc removed the builder label Apr 14, 2015
@rsc rsc modified the milestones: Unreleased, Unplanned Apr 14, 2015
@rsc rsc added the Builders x/build issues (builders, bots, dashboards) label Jun 11, 2015
@bradfitz
Copy link
Contributor Author

bradfitz commented Sep 4, 2019

Closing for now. I think this is fixed, or at least works totally differently from 2015.

@bradfitz bradfitz closed this as completed Sep 4, 2019
@golang golang locked and limited conversation to collaborators Sep 3, 2020
@rsc rsc unassigned dvyukov Jun 23, 2022
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
Builders x/build issues (builders, bots, dashboards) FrozenDueToAge
Projects
None yet
Development

No branches or pull requests

5 participants