go: x/build/cmd/coordinator: test “ran over” time limit output doesn't make it easy to tell where
#!watchflakes
default <- log ~ `^Test .* ran over .* limit`
From https://storage.googleapis.com/go-build-log/a1471cf8/openbsd-amd64-68_eba704c3.log (a TryBot on CL 400376):
openbsd-amd64-68 at a1471cf8dea8e0a6025e5ca649cc94871d436211
:: Running /tmp/workdir/go/src/make.bash with args ["/tmp/workdir/go/src/make.bash"] and env ["HOME=/" "PATH=/sbin:/bin:/usr/sbin:/usr/bin:/usr/local/bin" "PWD=/" "INRC=1" "_=/bin/sh" "WORKDIR=/tmp/workdir" "GOROOT_BOOTSTRAP=/tmp/workdir/go1.4" "GO_BUILDER_NAME=openbsd-amd64-68" "GOBIN=" "TMPDIR=/tmp/workdir/tmp" "GOCACHE=/tmp/workdir/gocache"] in dir /tmp/workdir/go/src
…
Test "go_test:crypto/internal/subtle" ran over 20m0s limit (20m0.000698974s); saw output:
XXXBANNERXXX:Test execution environment.
# GOARCH: amd64
# CPU: Intel(R) Xeon(R) CPU @ 0.00GHz
# GOOS: openbsd
# OS Version: OpenBSD 6.8 OpenBSD 6.8 (GENERIC.MP) #2: Sat Dec 5 07:17:48 MST 2020 root@syspatch-68-amd64.openbsd.org:/usr/src/sys/arch/amd64/compile/GENERIC.MP amd64
XXXBANNERXXX:Testing packages.
ok crypto/internal/subtle 0.017s
ok crypto/md5 0.023s
ok crypto/rand 0.054s
Error: tests failed: dist test failed: go_test:crypto/internal/subtle: Test "go_test:crypto/internal/subtle" ran over 20m0s limit (20m0.000698974s); saw output:
XXXBANNERXXX:Test execution environment.
# GOARCH: amd64
# CPU: Intel(R) Xeon(R) CPU @ 0.00GHz
# GOOS: openbsd
# OS Version: OpenBSD 6.8 OpenBSD 6.8 (GENERIC.MP) #2: Sat Dec 5 07:17:48 MST 2020 root@syspatch-68-amd64.openbsd.org:/usr/src/sys/arch/amd64/compile/GENERIC.MP amd64
XXXBANNERXXX:Testing packages.
ok crypto/internal/subtle 0.017s
ok crypto/md5 0.023s
ok crypto/rand 0.054s
There are a few issues with this result:
- The error message claims that
go_test:crypto/internal/subtle
ran over the time limit, but AFAICT it actually completed in 17ms. I’m not sure how to reconcile that. - The output from the test run is duplicated. (But duplicated is better than missing, at least! 😅)
- The
XXXBANNERXXX
lines have not been stripped as expected.
Of those, I am most concerned with (1), so I’d like to focus this issue on that (but incidentally fixing the others would be nice too).
(attn @golang/release; I think this may be a latent issue uncovered by @dmitshur’s recent timeout fix in CL 407555.)
About this issue
- Original URL
- State: open
- Created 2 years ago
- Comments: 57 (7 by maintainers)
I looked into this a while back, and wanted to do more, but never got around to it. For now I’ll just update this issue with a summary of what I found.
I think the timeout is accurate, but there’s not enough information in the log to point out where. It likely wasn’t
crypto/internal/subtle
but one of the packages aftercrypto/rand
, i.e.,crypto/rc4
or later. Our build error reporting can be improved to make investigating these types of findings easier.