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

[bcmills]

#!watchflakes
post <- pkg == "cmd/go" && test == "TestScript" && `cover_.*.txt:\d+: .*link.* unexpected success`

[gopherbot]

Sorry, but there were parse errors in the watch flakes script.
The script I found was:

#!watchflakes
post <- pkg == "cmd/go" && test == "TestScript" && `cover_.*.txt:\d+: .*link.* unexpected success

And the problems were:

script:2.52: newline in backquoted regexp

See https://go.dev/wiki/Watchflakes for details.

— watchflakes

[gopherbot]

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]

(attn @thanm)

[thanm]

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]

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

[thanm]

That does look related, thanks

[gopherbot]

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]

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