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/go: failures in TestScript/cover_statements due to unexpected linker invocations #64014

Open
bcmills opened this issue Nov 8, 2023 · 16 comments
Open

cmd/go: failures in TestScript/cover_statements due to unexpected linker invocations #64014

bcmills opened this issue Nov 8, 2023 · 16 comments
Assignees
@thanm
Labels
compiler/runtime Issues related to the Go compiler and/or runtime. GoCommand cmd/go NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one.
Milestone
Go1.23

Comments

@bcmills
Copy link
Contributor

bcmills commented Nov 8, 2023 •
edited 

#!watchflakes
post <- pkg == "cmd/go" && test == "TestScript" && `cover_.*.txt:\d+: .*link.* unexpected success`
@bcmills bcmills added GoCommand cmd/go compiler/runtime Issues related to the Go compiler and/or runtime. NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. labels Nov 8, 2023
@bcmills bcmills added this to the Go1.22 milestone Nov 8, 2023
@gopherbot

This comment was marked as resolved.

Sign in to view
@gopherbot
Copy link

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "cmd/go" && test == "TestScript" && `cover_.*.txt:\d+: .*link.* unexpected success`
2023-10-05 08:26 linux-386-longtest go@bc150700 cmd/go.TestScript (log) 
vcs-test.golang.org rerouted to http://127.0.0.1:43029
https://vcs-test.golang.org rerouted to https://127.0.0.1:34699
go test proxy running at GOPROXY=http://127.0.0.1:44193/mod
2023/10/05 09:00:46 http: TLS handshake error from 127.0.0.1:60490: read tcp 127.0.0.1:34699->127.0.0.1:60490: read: connection reset by peer
2023/10/05 09:00:46 http: TLS handshake error from 127.0.0.1:60506: EOF
2023/10/05 09:00:53 http: TLS handshake error from 127.0.0.1:55872: EOF
2023/10/05 09:00:53 http: TLS handshake error from 127.0.0.1:55866: EOF
2023/10/05 09:00:53 http: TLS handshake error from 127.0.0.1:55886: EOF
2023/10/05 09:00:53 http: TLS handshake error from 127.0.0.1:55920: EOF
--- FAIL: TestScript (0.06s)
    --- FAIL: TestScript/cover_statements (2.42s)
        script_test.go:132: 2023-10-05T09:02:26Z
        script_test.go:134: $WORK=/workdir/tmp/cmd-go-test-1922464838/tmpdir1252880670/cover_statements2287602560
        script_test.go:156: 
            > [short] skip
            [condition not met]
            # Initial run with simple coverage. (1.058s)
            # Second run to make sure that caching works properly. (1.365s)
            > go test -x -cover ./pkg1 ./pkg2 ./pkg3 ./pkg4
            [stdout]
...
            matched: 	m/pkg1		coverage: 0.0% of statements
            > stdout 'pkg2	\S+	coverage: 0.0% of statements \[no tests to run\]'
            matched: ok  	m/pkg2	0.088s	coverage: 0.0% of statements [no tests to run]
            > stdout 'pkg3	\S+	coverage: 100.0% of statements'
            matched: ok  	m/pkg3	(cached)	coverage: 100.0% of statements
            > stdout 'pkg4	\S+	coverage: \[no statements\]'
            matched: ok  	m/pkg4	(cached)	coverage: [no statements]
            > [GOEXPERIMENT:coverageredesign] ! stderr 'link(\.exe"?)? -'
            matched: /workdir/go/pkg/tool/linux_386/link -o $WORK/b047/pkg2.test -importcfg $WORK/b047/importcfg.link -s -w -X=runtime.godebugDefault=httplaxcontentlength=1,httpmuxgo121=1,panicnil=1 -buildmode=exe -buildid=1BWKmgEnCU21Oj1f0gkA/HK804ap0zd0idPSRTcj5/F8AskLlmrL-dE7grkc-4/1BWKmgEnCU21Oj1f0gkA -X testing.testBinary=1 -extld=gcc /workdir/gocache/5f/5fb80e32ad043755b99726a94820c897b70ac988c144532873ee891e84691075-d
        script_test.go:156: FAIL: testdata/script/cover_statements.txt:18: stderr 'link(\.exe"?)? -': unexpected success
2023-10-09 22:19 linux-386-longtest go@fce6be15 cmd/go.TestScript (log) 
vcs-test.golang.org rerouted to http://127.0.0.1:36317
https://vcs-test.golang.org rerouted to https://127.0.0.1:44941
go test proxy running at GOPROXY=http://127.0.0.1:37555/mod
2023/10/09 22:55:02 http: TLS handshake error from 127.0.0.1:43484: EOF
2023/10/09 22:55:15 http: TLS handshake error from 127.0.0.1:52446: EOF
2023/10/09 22:55:15 http: TLS handshake error from 127.0.0.1:52466: EOF
2023/10/09 22:55:15 http: TLS handshake error from 127.0.0.1:52436: EOF
2023/10/09 22:55:22 http: TLS handshake error from 127.0.0.1:53842: EOF
2023/10/09 22:55:22 http: TLS handshake error from 127.0.0.1:53870: EOF
--- FAIL: TestScript (0.06s)
    --- FAIL: TestScript/cover_statements (2.96s)
        script_test.go:132: 2023-10-09T22:55:25Z
        script_test.go:134: $WORK=/workdir/tmp/cmd-go-test-3216620379/tmpdir2544150257/cover_statements3804014372
        script_test.go:156: 
            > [short] skip
            [condition not met]
            # Initial run with simple coverage. (1.332s)
            # Second run to make sure that caching works properly. (1.626s)
            > go test -x -cover ./pkg1 ./pkg2 ./pkg3 ./pkg4
            [stdout]
...
            matched: 	m/pkg1		coverage: 0.0% of statements
            > stdout 'pkg2	\S+	coverage: 0.0% of statements \[no tests to run\]'
            matched: ok  	m/pkg2	0.045s	coverage: 0.0% of statements [no tests to run]
            > stdout 'pkg3	\S+	coverage: 100.0% of statements'
            matched: ok  	m/pkg3	0.050s	coverage: 100.0% of statements
            > stdout 'pkg4	\S+	coverage: \[no statements\]'
            matched: ok  	m/pkg4	0.037s	coverage: [no statements]
            > [GOEXPERIMENT:coverageredesign] ! stderr 'link(\.exe"?)? -'
            matched: /workdir/go/pkg/tool/linux_386/link -o $WORK/b111/pkg4.test -importcfg $WORK/b111/importcfg.link -s -w -X=runtime.godebugDefault=httplaxcontentlength=1,httpmuxgo121=1,panicnil=1 -buildmode=exe -buildid=9sAcyRu-0VjcdqhJTlF4/KLVevTW2FkQuntybWQqt/kuvCZ3hsHKk1RChBCP2p/9sAcyRu-0VjcdqhJTlF4 -X testing.testBinary=1 -extld=gcc /workdir/gocache/19/19456b09302ba04e152607bf26113f5e47bee5a300263fc4eef749dcb7af1cc1-d
        script_test.go:156: FAIL: testdata/script/cover_statements.txt:18: stderr 'link(\.exe"?)? -': unexpected success
2023-10-17 20:36 linux-386-longtest go@ab2e3ce7 cmd/go.TestScript (log) 
vcs-test.golang.org rerouted to http://127.0.0.1:45051
https://vcs-test.golang.org rerouted to https://127.0.0.1:37757
go test proxy running at GOPROXY=http://127.0.0.1:33421/mod
2023/10/17 21:16:35 http: TLS handshake error from 127.0.0.1:36702: EOF
2023/10/17 21:16:39 http: TLS handshake error from 127.0.0.1:58982: EOF
2023/10/17 21:16:39 http: TLS handshake error from 127.0.0.1:58980: EOF
2023/10/17 21:16:39 http: TLS handshake error from 127.0.0.1:58998: EOF
2023/10/17 21:16:39 http: TLS handshake error from 127.0.0.1:59046: EOF
--- FAIL: TestScript (0.06s)
    --- FAIL: TestScript/cover_statements (3.54s)
...
            matched: 	m/pkg1		coverage: 0.0% of statements
            > stdout 'pkg2	\S+	coverage: 0.0% of statements \[no tests to run\]'
            matched: ok  	m/pkg2	0.086s	coverage: 0.0% of statements [no tests to run]
            > stdout 'pkg3	\S+	coverage: 100.0% of statements'
            matched: ok  	m/pkg3	0.096s	coverage: 100.0% of statements
            > stdout 'pkg4	\S+	coverage: \[no statements\]'
            matched: ok  	m/pkg4	0.042s	coverage: [no statements]
            > [GOEXPERIMENT:coverageredesign] ! stderr 'link(\.exe"?)? -'
            matched: /workdir/go/pkg/tool/linux_386/link -o $WORK/b111/pkg4.test -importcfg $WORK/b111/importcfg.link -s -w -X=runtime.godebugDefault=httplaxcontentlength=1,httpmuxgo121=1,panicnil=1 -buildmode=exe -buildid=EpcY1XiVD61fvmnVShz6/9xlma-sJROW0Gq1MtEe7/jT4eoGU4jMZOpOJ8EGb5/EpcY1XiVD61fvmnVShz6 -X testing.testBinary=1 -extld=gcc /workdir/gocache/77/7754c4b42e8b5b7e90f7ecb95ef0b9ee857ddd241b63a4dcc5e5630936c7fb25-d
        script_test.go:156: FAIL: testdata/script/cover_statements.txt:18: stderr 'link(\.exe"?)? -': unexpected success
2023-10-18 14:06 linux-386-longtest go@7ee99801 cmd/go.TestScript (log) 
vcs-test.golang.org rerouted to http://127.0.0.1:45635
https://vcs-test.golang.org rerouted to https://127.0.0.1:36365
go test proxy running at GOPROXY=http://127.0.0.1:39823/mod
2023/10/18 14:43:06 http: TLS handshake error from 127.0.0.1:49254: read tcp 127.0.0.1:36365->127.0.0.1:49254: read: connection reset by peer
2023/10/18 14:43:14 http: TLS handshake error from 127.0.0.1:41224: EOF
2023/10/18 14:43:20 http: TLS handshake error from 127.0.0.1:41366: EOF
2023/10/18 14:43:20 http: TLS handshake error from 127.0.0.1:41374: EOF
2023/10/18 14:43:20 http: TLS handshake error from 127.0.0.1:41350: EOF
2023/10/18 14:43:20 http: TLS handshake error from 127.0.0.1:41442: read tcp 127.0.0.1:36365->127.0.0.1:41442: read: connection reset by peer
2023/10/18 14:43:20 http: TLS handshake error from 127.0.0.1:41380: read tcp 127.0.0.1:36365->127.0.0.1:41380: read: connection reset by peer
...
--- FAIL: TestScript (0.06s)
    --- FAIL: TestScript/cover_statements (4.13s)
        script_test.go:132: 2023-10-18T14:43:52Z
        script_test.go:134: $WORK=/workdir/tmp/cmd-go-test-2505932493/tmpdir3741079956/cover_statements3099111569
        script_test.go:156: 
            > [short] skip
            [condition not met]
            # Initial run with simple coverage. (2.023s)
            # Second run to make sure that caching works properly. (2.100s)
            > go test -x -cover ./pkg1 ./pkg2 ./pkg3 ./pkg4
...
            matched: 	m/pkg1		coverage: 0.0% of statements
            > stdout 'pkg2	\S+	coverage: 0.0% of statements \[no tests to run\]'
            matched: ok  	m/pkg2	0.043s	coverage: 0.0% of statements [no tests to run]
            > stdout 'pkg3	\S+	coverage: 100.0% of statements'
            matched: ok  	m/pkg3	(cached)	coverage: 100.0% of statements
            > stdout 'pkg4	\S+	coverage: \[no statements\]'
            matched: ok  	m/pkg4	(cached)	coverage: [no statements]
            > [GOEXPERIMENT:coverageredesign] ! stderr 'link(\.exe"?)? -'
            matched: /workdir/go/pkg/tool/linux_386/link -o $WORK/b047/pkg2.test -importcfg $WORK/b047/importcfg.link -s -w -X=runtime.godebugDefault=httplaxcontentlength=1,httpmuxgo121=1,panicnil=1 -buildmode=exe -buildid=ffJL2F_6s0qqnc-TO3O2/W-W0szQxj5WMDe3boDq2/q-uS4UG6WxnuROwDLWlg/ffJL2F_6s0qqnc-TO3O2 -X testing.testBinary=1 -extld=gcc /workdir/gocache/63/63762bf0eda9583a553c6f24efeb8c9b1cfbdff8057dd53d0a4f767bf5aaf547-d
        script_test.go:156: FAIL: testdata/script/cover_statements.txt:18: stderr 'link(\.exe"?)? -': unexpected success
2023-10-31 17:13 linux-arm64-longtest go@cbc403af cmd/go.TestScript (log) 
vcs-test.golang.org rerouted to http://127.0.0.1:44381
https://vcs-test.golang.org rerouted to https://127.0.0.1:43099
go test proxy running at GOPROXY=http://127.0.0.1:40071/mod
2023/10/31 17:39:40 http: TLS handshake error from 127.0.0.1:41768: EOF
2023/10/31 17:39:40 http: TLS handshake error from 127.0.0.1:41766: read tcp 127.0.0.1:43099->127.0.0.1:41766: read: connection reset by peer
2023/10/31 17:39:40 http: TLS handshake error from 127.0.0.1:41750: EOF
--- FAIL: TestScript (0.06s)
    --- FAIL: TestScript/cover_statements (1.70s)
        script_test.go:132: 2023-10-31T17:39:56Z
        script_test.go:134: $WORK=/tmp/workdir/tmp/cmd-go-test-871142671/tmpdir4130506320/cover_statements1330079677
...
            matched: 	m/pkg1		coverage: 0.0% of statements
            > stdout 'pkg2	\S+	coverage: 0.0% of statements \[no tests to run\]'
            matched: ok  	m/pkg2	0.081s	coverage: 0.0% of statements [no tests to run]
            > stdout 'pkg3	\S+	coverage: 100.0% of statements'
            matched: ok  	m/pkg3	0.068s	coverage: 100.0% of statements
            > stdout 'pkg4	\S+	coverage: \[no statements\]'
            matched: ok  	m/pkg4	0.042s	coverage: [no statements]
            > [GOEXPERIMENT:coverageredesign] ! stderr 'link(\.exe"?)? -'
            matched: /tmp/workdir/go/pkg/tool/linux_arm64/link -o $WORK/b108/pkg3.test -importcfg $WORK/b108/importcfg.link -s -w -X=runtime.godebugDefault=httplaxcontentlength=1,httpmuxgo121=1,panicnil=1 -buildmode=exe -buildid=zg1NNjykVDQGK74qT8wb/G_Vg2eJbImw1fTJRFieD/nZ2zZj6OBknKwiVf_9qv/zg1NNjykVDQGK74qT8wb -X testing.testBinary=1 -extld=gcc /tmp/workdir/gocache/99/9999add8847a25d1214893829134bf2641c47a7dbfa52f52b622e7705b02384c-d
        script_test.go:156: FAIL: testdata/script/cover_statements.txt:18: stderr 'link(\.exe"?)? -': unexpected success
2023-11-08 17:51 windows-amd64-longtest go@eebeca80 cmd/go.TestScript (log) 
vcs-test.golang.org rerouted to http://127.0.0.1:54791
https://vcs-test.golang.org rerouted to https://127.0.0.1:54792
go test proxy running at GOPROXY=http://127.0.0.1:54793/mod
--- FAIL: TestScript (0.14s)
    --- FAIL: TestScript/cover_statements (13.38s)
        script_test.go:132: 2023-11-08T18:32:10Z
        script_test.go:134: $WORK=C:\Users\gopher\AppData\Local\Temp\1\cmd-go-test-1817490941\tmpdir2292983102\cover_statements2904642151
        script_test.go:156: 
            > [short] skip
            [condition not met]
...
            matched: 	m/pkg1		coverage: 0.0% of statements
            > stdout 'pkg2	\S+	coverage: 0.0% of statements \[no tests to run\]'
            matched: ok  	m/pkg2	0.156s	coverage: 0.0% of statements [no tests to run]
            > stdout 'pkg3	\S+	coverage: 100.0% of statements'
            matched: ok  	m/pkg3	0.185s	coverage: 100.0% of statements
            > stdout 'pkg4	\S+	coverage: \[no statements\]'
            matched: ok  	m/pkg4	0.144s	coverage: [no statements]
            > [GOEXPERIMENT:coverageredesign] ! stderr 'link(\.exe"?)? -'
            matched: "C:\\workdir\\go\\pkg\\tool\\windows_amd64\\link.exe" -o "$WORK\\b049\\pkg2.test.exe" -importcfg "$WORK\\b049\\importcfg.link" -s -w -X=runtime.godebugDefault=httplaxcontentlength=1,httpmuxgo121=1,panicnil=1 -buildmode=pie -buildid=yjN4m9BZ8F-UXTzPn3DO/NslB3yILncvHKk9ehmo4/wLToUOFgDiNoXeGaaIN2/yjN4m9BZ8F-UXTzPn3DO -X testing.testBinary=1 -extld=gcc "C:\\workdir\\gocache\\4f\\4f96789f56a4553a93cbc60a4dc374fcab81dffa9d3e97d26a40aa4d8656e5ad-d"
        script_test.go:156: FAIL: testdata\script\cover_statements.txt:18: stderr 'link(\.exe"?)? -': unexpected success
2023-11-08 17:55 linux-amd64-longtest-race go@5cb0839e cmd/go.TestScript (log) 
vcs-test.golang.org rerouted to http://127.0.0.1:40101
https://vcs-test.golang.org rerouted to https://127.0.0.1:43389
go test proxy running at GOPROXY=http://127.0.0.1:46789/mod
2023/11/08 19:01:29 http: TLS handshake error from 127.0.0.1:39942: EOF
2023/11/08 19:02:24 http: TLS handshake error from 127.0.0.1:36922: read tcp 127.0.0.1:43389->127.0.0.1:36922: read: connection reset by peer
--- FAIL: TestScript (1.15s)
    --- FAIL: TestScript/cover_statements (3.68s)
        script_test.go:132: 2023-11-08T19:02:59Z
        script_test.go:134: $WORK=/workdir/tmp/cmd-go-test-652114270/tmpdir2385451142/cover_statements2126372759
        script_test.go:156: 
...
            matched: 	m/pkg1		coverage: 0.0% of statements
            > stdout 'pkg2	\S+	coverage: 0.0% of statements \[no tests to run\]'
            matched: ok  	m/pkg2	0.017s	coverage: 0.0% of statements [no tests to run]
            > stdout 'pkg3	\S+	coverage: 100.0% of statements'
            matched: ok  	m/pkg3	0.004s	coverage: 100.0% of statements
            > stdout 'pkg4	\S+	coverage: \[no statements\]'
            matched: ok  	m/pkg4	0.006s	coverage: [no statements]
            > [GOEXPERIMENT:coverageredesign] ! stderr 'link(\.exe"?)? -'
            matched: /workdir/go/pkg/tool/linux_amd64/link -o $WORK/b108/pkg3.test -importcfg $WORK/b108/importcfg.link -s -w -X=runtime.godebugDefault=httplaxcontentlength=1,httpmuxgo121=1,panicnil=1 -buildmode=exe -buildid=Qx1SNAD1Eh1PXqFsE669/PMZVjvsiCsnDnXAkVjkg/Gf1pA7FfOZbSRMqOdFpg/Qx1SNAD1Eh1PXqFsE669 -X testing.testBinary=1 -extld=gcc /workdir/gocache/7f/7fcdf37723f9037f78bba9988b2b2649388cd76a710318685e01dbc276ffd5de-d
        script_test.go:156: FAIL: testdata/script/cover_statements.txt:18: stderr 'link(\.exe"?)? -': unexpected success

— watchflakes

@bcmills
Copy link
Contributor Author

bcmills commented Nov 8, 2023

(attn @thanm)

@thanm thanm self-assigned this Nov 9, 2023
@thanm
Copy link
Contributor

thanm commented Nov 9, 2023

Seems pretty clear from the failing logs that for some reason the Go command decided that the the cache entry was stale and the action needed to be redone... which is a puzzle to me: seems like all the action inputs should be deterministic. Not sure how we could have flakiness in such a situation.

@bcmills
Copy link
Contributor Author

bcmills commented Nov 10, 2023

Hmm. I wonder if this is related to #49267?

@thanm
Copy link
Contributor

thanm commented Nov 10, 2023

That does look related, thanks

@gopherbot
Copy link

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "cmd/go" && test == "TestScript" && `cover_.*.txt:\d+: .*link.* unexpected success`
2023-11-10 16:18 windows-amd64-longtest go@abf84221 cmd/go.TestScript (log) 
vcs-test.golang.org rerouted to http://127.0.0.1:54799
https://vcs-test.golang.org rerouted to https://127.0.0.1:54800
go test proxy running at GOPROXY=http://127.0.0.1:54801/mod
--- FAIL: TestScript (0.14s)
    --- FAIL: TestScript/cover_statements (8.28s)
        script_test.go:132: 2023-11-10T16:58:51Z
        script_test.go:134: $WORK=C:\Users\gopher\AppData\Local\Temp\1\cmd-go-test-1443132979\tmpdir447030789\cover_statements4198832878
        script_test.go:156: 
            > [short] skip
            [condition not met]
...
            matched: 	m/pkg1		coverage: 0.0% of statements
            > stdout 'pkg2	\S+	coverage: 0.0% of statements \[no tests to run\]'
            matched: ok  	m/pkg2	0.173s	coverage: 0.0% of statements [no tests to run]
            > stdout 'pkg3	\S+	coverage: 100.0% of statements'
            matched: ok  	m/pkg3	0.186s	coverage: 100.0% of statements
            > stdout 'pkg4	\S+	coverage: \[no statements\]'
            matched: ok  	m/pkg4	0.157s	coverage: [no statements]
            > [GOEXPERIMENT:coverageredesign] ! stderr 'link(\.exe"?)? -'
            matched: "C:\\workdir\\go\\pkg\\tool\\windows_amd64\\link.exe" -o "$WORK\\b049\\pkg2.test.exe" -importcfg "$WORK\\b049\\importcfg.link" -s -w -X=runtime.godebugDefault=httplaxcontentlength=1,httpmuxgo121=1,panicnil=1 -buildmode=pie -buildid=7ulqAd2gOl3c6oL6GgRV/u4ry91Kwt2A4WkVpycrE/EhOjZxOyGxI-VzFi6cDN/7ulqAd2gOl3c6oL6GgRV -X testing.testBinary=1 -extld=gcc "C:\\workdir\\gocache\\f9\\f99628f6fc396e7ca2e264621ecb7bf50ef03bbcb8542f8bf6c42678f0895d8d-d"
        script_test.go:156: FAIL: testdata\script\cover_statements.txt:18: stderr 'link(\.exe"?)? -': unexpected success

— watchflakes

@gopherbot
Copy link

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "cmd/go" && test == "TestScript" && `cover_.*.txt:\d+: .*link.* unexpected success`
2023-11-15 14:26 linux-amd64-longtest go@15fa7a84 cmd/go.TestScript (log) 
vcs-test.golang.org rerouted to http://127.0.0.1:39689
https://vcs-test.golang.org rerouted to https://127.0.0.1:37663
go test proxy running at GOPROXY=http://127.0.0.1:44233/mod
--- FAIL: TestScript (0.06s)
    --- FAIL: TestScript/cover_statements (3.07s)
        script_test.go:132: 2023-11-15T14:59:28Z
        script_test.go:134: $WORK=/workdir/tmp/cmd-go-test-1432273878/tmpdir1357569098/cover_statements1380616716
        script_test.go:156: 
            > [short] skip
            [condition not met]
...
            matched: 	m/pkg1		coverage: 0.0% of statements
            > stdout 'pkg2	\S+	coverage: 0.0% of statements \[no tests to run\]'
            matched: ok  	m/pkg2	0.102s	coverage: 0.0% of statements [no tests to run]
            > stdout 'pkg3	\S+	coverage: 100.0% of statements'
            matched: ok  	m/pkg3	0.042s	coverage: 100.0% of statements
            > stdout 'pkg4	\S+	coverage: \[no statements\]'
            matched: ok  	m/pkg4	0.055s	coverage: [no statements]
            > [GOEXPERIMENT:coverageredesign] ! stderr 'link(\.exe"?)? -'
            matched: /workdir/go/pkg/tool/linux_amd64/link -o $WORK/b111/pkg4.test -importcfg $WORK/b111/importcfg.link -s -w -X=runtime.godebugDefault=httplaxcontentlength=1,httpmuxgo121=1,panicnil=1,tls10server=1,tlsrsakex=1 -buildmode=exe -buildid=wyqz9MLXuDJBlHFbnRGm/3a1RYFW0jp6EidnNVxI7/jJpVYbmBpInYkK-fXVzk/wyqz9MLXuDJBlHFbnRGm -X testing.testBinary=1 -extld=gcc /workdir/gocache/eb/eb5fb4e4354ea294437b67df721fe7e0f6a97dad5eb574a8b5b1f9fca6accdd4-d
        script_test.go:156: FAIL: testdata/script/cover_statements.txt:18: stderr 'link(\.exe"?)? -': unexpected success

— watchflakes

@gopherbot
Copy link

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "cmd/go" && test == "TestScript" && `cover_.*.txt:\d+: .*link.* unexpected success`
2023-11-16 20:37 linux-arm64-longtest go@a95c5d37 cmd/go.TestScript (log) 
vcs-test.golang.org rerouted to http://127.0.0.1:39839
https://vcs-test.golang.org rerouted to https://127.0.0.1:42355
go test proxy running at GOPROXY=http://127.0.0.1:46545/mod
2023/11/16 21:01:20 http: TLS handshake error from 127.0.0.1:60688: read tcp 127.0.0.1:42355->127.0.0.1:60688: read: connection reset by peer
2023/11/16 21:01:28 http: TLS handshake error from 127.0.0.1:39318: read tcp 127.0.0.1:42355->127.0.0.1:39318: read: connection reset by peer
2023/11/16 21:01:28 http: TLS handshake error from 127.0.0.1:39344: read tcp 127.0.0.1:42355->127.0.0.1:39344: read: connection reset by peer
--- FAIL: TestScript (0.06s)
    --- FAIL: TestScript/cover_statements (1.84s)
        script_test.go:132: 2023-11-16T21:02:21Z
        script_test.go:134: $WORK=/tmp/workdir/tmp/cmd-go-test-3279418308/tmpdir3152271524/cover_statements1640250974
...
            matched: 	m/pkg1		coverage: 0.0% of statements
            > stdout 'pkg2	\S+	coverage: 0.0% of statements \[no tests to run\]'
            matched: ok  	m/pkg2	0.162s	coverage: 0.0% of statements [no tests to run]
            > stdout 'pkg3	\S+	coverage: 100.0% of statements'
            matched: ok  	m/pkg3	(cached)	coverage: 100.0% of statements
            > stdout 'pkg4	\S+	coverage: \[no statements\]'
            matched: ok  	m/pkg4	(cached)	coverage: [no statements]
            > [GOEXPERIMENT:coverageredesign] ! stderr 'link(\.exe"?)? -'
            matched: /tmp/workdir/go/pkg/tool/linux_arm64/link -o $WORK/b047/pkg2.test -importcfg $WORK/b047/importcfg.link -s -w -X=runtime.godebugDefault=httplaxcontentlength=1,httpmuxgo121=1,panicnil=1,tls10server=1,tlsrsakex=1 -buildmode=exe -buildid=VZIf1cBS_eIKR5TrNyAy/nfGNx-gC6vQO2eb8-2tW/AibIcCguYxp7mG-WbdDl/VZIf1cBS_eIKR5TrNyAy -X testing.testBinary=1 -extld=gcc /tmp/workdir/gocache/53/536e84c0a10ac8013c517ea1328bde83c9fba4a71fd2499e64d2d70aa98c1d51-d
        script_test.go:156: FAIL: testdata/script/cover_statements.txt:18: stderr 'link(\.exe"?)? -': unexpected success

— watchflakes

@gopherbot
Copy link

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "cmd/go" && test == "TestScript" && `cover_.*.txt:\d+: .*link.* unexpected success`
2023-11-21 18:57 linux-amd64-longtest-race go@4bfed5ce cmd/go.TestScript (log) 
vcs-test.golang.org rerouted to http://127.0.0.1:44879
https://vcs-test.golang.org rerouted to https://127.0.0.1:45617
go test proxy running at GOPROXY=http://127.0.0.1:36921/mod
--- FAIL: TestScript (1.15s)
    --- FAIL: TestScript/cover_statements (3.54s)
        script_test.go:132: 2023-11-21T20:05:31Z
        script_test.go:134: $WORK=/workdir/tmp/cmd-go-test-2382459804/tmpdir4055794895/cover_statements119868286
        script_test.go:156: 
            > [short] skip
            [condition not met]
...
            matched: 	m/pkg1		coverage: 0.0% of statements
            > stdout 'pkg2	\S+	coverage: 0.0% of statements \[no tests to run\]'
            matched: ok  	m/pkg2	0.009s	coverage: 0.0% of statements [no tests to run]
            > stdout 'pkg3	\S+	coverage: 100.0% of statements'
            matched: ok  	m/pkg3	0.014s	coverage: 100.0% of statements
            > stdout 'pkg4	\S+	coverage: \[no statements\]'
            matched: ok  	m/pkg4	0.007s	coverage: [no statements]
            > [GOEXPERIMENT:coverageredesign] ! stderr 'link(\.exe"?)? -'
            matched: /workdir/go/pkg/tool/linux_amd64/link -o $WORK/b111/pkg4.test -importcfg $WORK/b111/importcfg.link -s -w -X=runtime.godebugDefault=httplaxcontentlength=1,httpmuxgo121=1,panicnil=1,tls10server=1,tlsrsakex=1,tlsunsafeekm=1 -buildmode=exe -buildid=ivqq1PEW5xmKS4Rio2Nh/LmlkiQ0whRRjH_CPRBYJ/XMA0tlrxNZjPGECUXBEl/ivqq1PEW5xmKS4Rio2Nh -X testing.testBinary=1 -extld=gcc /workdir/gocache/42/424e4cd609d8d4b158b8084a2dc2c3df5b06caab85f46117e0441283fb63e9df-d
        script_test.go:156: FAIL: testdata/script/cover_statements.txt:18: stderr 'link(\.exe"?)? -': unexpected success

— watchflakes

@gopherbot
Copy link

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "cmd/go" && test == "TestScript" && `cover_.*.txt:\d+: .*link.* unexpected success`
2023-11-21 21:29 linux-arm64-longtest go@4e3ac99a cmd/go.TestScript (log) 
vcs-test.golang.org rerouted to http://127.0.0.1:45741
https://vcs-test.golang.org rerouted to https://127.0.0.1:46685
go test proxy running at GOPROXY=http://127.0.0.1:45395/mod
2023/11/21 21:56:28 http: TLS handshake error from 127.0.0.1:40648: EOF
2023/11/21 21:56:28 http: TLS handshake error from 127.0.0.1:40632: read tcp 127.0.0.1:46685->127.0.0.1:40632: read: connection reset by peer
--- FAIL: TestScript (0.06s)
    --- FAIL: TestScript/cover_statements (2.52s)
        script_test.go:132: 2023-11-21T21:57:29Z
        script_test.go:134: $WORK=/tmp/workdir/tmp/cmd-go-test-1168611034/tmpdir2103483836/cover_statements827332114
        script_test.go:156: 
...
            matched: 	m/pkg1		coverage: 0.0% of statements
            > stdout 'pkg2	\S+	coverage: 0.0% of statements \[no tests to run\]'
            matched: ok  	m/pkg2	0.058s	coverage: 0.0% of statements [no tests to run]
            > stdout 'pkg3	\S+	coverage: 100.0% of statements'
            matched: ok  	m/pkg3	(cached)	coverage: 100.0% of statements
            > stdout 'pkg4	\S+	coverage: \[no statements\]'
            matched: ok  	m/pkg4	(cached)	coverage: [no statements]
            > [GOEXPERIMENT:coverageredesign] ! stderr 'link(\.exe"?)? -'
            matched: /tmp/workdir/go/pkg/tool/linux_arm64/link -o $WORK/b047/pkg2.test -importcfg $WORK/b047/importcfg.link -s -w -X=runtime.godebugDefault=httplaxcontentlength=1,httpmuxgo121=1,panicnil=1,tls10server=1,tlsrsakex=1,tlsunsafeekm=1 -buildmode=exe -buildid=OCaoAHkppMCd_1Y29S1x/N_Z1ucoYHPnMP6YVpDxi/ZKmrzv3cK5o0bd-bxpLg/OCaoAHkppMCd_1Y29S1x -X testing.testBinary=1 -extld=gcc /tmp/workdir/gocache/0d/0d494c93e65d487fa6107ebfb973747a034b67bed231d7f19807134a3b43d544-d
        script_test.go:156: FAIL: testdata/script/cover_statements.txt:18: stderr 'link(\.exe"?)? -': unexpected success

— watchflakes

@thanm
Copy link
Contributor

thanm commented Nov 27, 2023

It looks like I can reproduce the problem with this script:

bash_script.txt

I still don't have a good idea as to why caching fails in the first place, however. I think given that the test is sensitive to caching behavior and cache invalidation, it is probably a good idea to run the test with its own local cache. I will send a CL for that.

@gopherbot
Copy link

Change https://go.dev/cl/545235 mentions this issue: cmd/go: use local go cache for cover_statements script test

gopherbot pushed a commit that referenced this issue Dec 6, 2023
@thanm
cmd/go: use local go cache for cover_statements script test
6e33a63 
Use a test-local directory for GOCACHE in "cover_statements" script
test, as a workaround for issue 64014.

For the portion of this test that verifies that caching works
correctly, the cache should theoretically always behave
reliably/deterministically, however if other tests are concurrently
accessing the cache while this test is running, it can lead to cache
lookup failures, which manifest as a flaky failure. To avoid such
flakes, use a separate isolated GOCACHE for this test.

For #64014.

Cq-Include-Trybots: luci.golang.try:gotip-linux-amd64-longtest
Change-Id: Ia66798215a75b7c41188ed15920c17b73f40152a
Reviewed-on: https://go-review.googlesource.com/c/go/+/545235
LUCI-TryBot-Result: Go LUCI <golang-scoped@luci-project-accounts.iam.gserviceaccount.com>
Reviewed-by: Bryan Mills <bcmills@google.com>
@thanm
Copy link
Contributor

thanm commented Dec 6, 2023

https://go.dev/cl/545235 should in theory fix this bug. Leaving open for now just in case there is more than one underlying problem.

@bcmills
Copy link
Contributor Author

bcmills commented Dec 6, 2023

CL 545235 should stop the failures, but it doesn't fix the underlying caching bug. I think we should leave this open until/unless that bug is understood (or we have reason to believe it may have been fixed).

@thanm
Copy link
Contributor

thanm commented Dec 6, 2023

Indeed. And it's probably useful to have a way to locally reproduce the caching bug (by reverting this change and then using the script from #64014 (comment)

@gopherbot gopherbot modified the milestones: Go1.22, Go1.23 Feb 6, 2024
ezz-no pushed a commit to ezz-no/go-ezzno that referenced this issue Feb 18, 2024
@thanm @ezz-no
cmd/go: use local go cache for cover_statements script test
98efcd9 
Use a test-local directory for GOCACHE in "cover_statements" script
test, as a workaround for issue 64014.

For the portion of this test that verifies that caching works
correctly, the cache should theoretically always behave
reliably/deterministically, however if other tests are concurrently
accessing the cache while this test is running, it can lead to cache
lookup failures, which manifest as a flaky failure. To avoid such
flakes, use a separate isolated GOCACHE for this test.

For golang#64014.

Cq-Include-Trybots: luci.golang.try:gotip-linux-amd64-longtest
Change-Id: Ia66798215a75b7c41188ed15920c17b73f40152a
Reviewed-on: https://go-review.googlesource.com/c/go/+/545235
LUCI-TryBot-Result: Go LUCI <golang-scoped@luci-project-accounts.iam.gserviceaccount.com>
Reviewed-by: Bryan Mills <bcmills@google.com>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@thanm thanm

Labels
compiler/runtime Issues related to the Go compiler and/or runtime. GoCommand cmd/go NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one.
Projects
Go Compiler / Runtime
Status: Todo
Test Flakes
Status: No status
Milestone
Go1.23
Development

No branches or pull requests
3 participants
@bcmills @gopherbot @thanm