x/build: `darwin-amd64` LUCI builders are sometimes too slow

[bcmills]

#!watchflakes
default <- builder ~ `(gotip|go1\.\d\d)-darwin-amd64` && (`test timed out` || `SIGQUIT` || `context deadline exceeded` || `command exceeded time limit` || status == "ABORT")

Go version

aba18d5

Output of go env in your module/workspace:

N/A

What did you do?

Check status of https://ci.chromium.org/p/golang/g/go-gotip/console.

What did you see happen?

Multiple failures involving timeouts on the darwin-amd64_13 builder:

• http://ci.chromium.org/b/8759366472105663201
• http://ci.chromium.org/b/8759455104674769409

What did you expect to see?

No timeouts: go test -short cmd/go takes <20s to run locally, so either the builders should be faster, or they should set a GO_TEST_TIMEOUT_SCALE that is long enough to reliably run the tests.

The only timeouts on the builders should be for (a) true deadlocks, and (b) tests that take a similarly long time (approaching 3 minutes) when run locally.

[dmitshur]

The "darwin-amd64-13" builder on the old dashboard doesn't have GO_TEST_TIMEOUT_SCALE in its configuration, so this isn't a case of that not being ported over. Perhaps our macOS amd64 13 builder configuration is less powerful? If we know by how much, it makes sense to set a corresponding GO_TEST_TIMEOUT_SCALE to compensate and avoid timeouts.

Another possibility is that we're running more tests on Mac builders in LUCI than we are on the old dashboard. For one, the old dashboard uses the macTestPolicy test policy, which attempts to skips some expensive portable tests.

CC @prattmic, @mknyszek.

[dmitshur]

We discussed and looked into this a bit.

This turns out not to be a consistent slowness: looking at https://ci.chromium.org/ui/p/golang/builders/ci/gotip-darwin-amd64_13 briefly shows many builds complete successfully in 15-20 min, with some taking 10 or 30 min, but the failures are taking an hour or longer and reaching timeout.

This builder at this time has two different providers. The two recent timeouts happened on the same darwin-amd64-13--ac2a2248-1530-... bot.

[prattmic]

Update on this. I took a look at median, worst case, etc build times for the main repo builder by bot hostname and there definitely seems to be a lot of variance between different hosts: nearly 4x difference in median runtime between the fastest and slowest hosts.

My first thought was slow network on some hosts, so I eyeballed the difference between a run on the fastest and slowest hosts and found that the slowdown seems to impact pretty much all packages. e.g.,

cmd/go 139s -> 540s
cmd/compile/internal/types2 15s -> 55s (pretty sure there is no network here)

Even small packages, like

cmd/gofmt 0.064s -> 0.79s

Some are similar though

crypto/md5 0.021s -> 0.024s

So it seems unrelated to network.

That slowest machine is https://chromium-swarm.appspot.com/bot?id=darwin-amd64-13--ac2a2248-1530-4adb-bb91-ae854aa7c79c.golang.ca.macservice.goog. Interestingly, it seems to be much faster today. Previously x/tools was timing out, now it is ~15m. x/build is faster, etc.

This definitely still needs more investigation.

[gopherbot]

Found new dashboard test flakes for:

#!watchflakes
post <- builder ~ `gotip-darwin-amd64` && (`test timed out` || `SIGQUIT` || `context deadline exceeded`)

2023-12-08 00:50 gotip-darwin-amd64-nocgo go@4bf1ca4b cmd/fix.TestRewrite/jni.ArrayElement (log)

=== RUN   TestRewrite/jni.ArrayElement
panic: test timed out after 9m0s
running tests:
	TestRewrite (9m0s)
	TestRewrite/jni.ArrayElement (5s)

goroutine 48 gp=0xc0000076c0 m=4 mp=0xc00004b208 [running]:
panic({0xc2ec460?, 0xc0001913e0?})
	/Users/swarming/.swarming/w/ir/x/w/goroot/src/runtime/panic.go:779 +0x158 fp=0xc00016ef10 sp=0xc00016ee60 pc=0xc161398
testing.(*M).startAlarm.func1()
...
cmd/fix.TestRewrite.func3(0xc0001a0ea0)
	/Users/swarming/.swarming/w/ir/x/w/goroot/src/cmd/fix/main_test.go:116 +0xde fp=0xc000179f70 sp=0xc000179eb0 pc=0xc296b1e
testing.tRunner(0xc0001a0ea0, 0xc000191260)
	/Users/swarming/.swarming/w/ir/x/w/goroot/src/testing/testing.go:1689 +0xfb fp=0xc000179fc0 sp=0xc000179f70 pc=0xc1fe63b
testing.(*T).Run.gowrap1()
	/Users/swarming/.swarming/w/ir/x/w/goroot/src/testing/testing.go:1742 +0x25 fp=0xc000179fe0 sp=0xc000179fc0 pc=0xc1ff665
runtime.goexit({})
	/Users/swarming/.swarming/w/ir/x/w/goroot/src/runtime/asm_amd64.s:1695 +0x1 fp=0xc000179fe8 sp=0xc000179fe0 pc=0xc19ad61
created by testing.(*T).Run in goroutine 18
	/Users/swarming/.swarming/w/ir/x/w/goroot/src/testing/testing.go:1742 +0x390

2024-01-08 16:00 gotip-darwin-amd64_13 go@881869dd cmd/go.TestScript (log)

=== RUN   TestScript/cgo_path_space
=== PAUSE TestScript/cgo_path_space
=== CONT  TestScript/cgo_path_space
    script_test.go:132: 2024-01-08T17:08:45Z
    script_test.go:134: $WORK=/Users/swarming/.swarming/w/ir/x/t/cmd-go-test-2324303667/tmpdir1305803261/cgo_path_space2972876599
    script_test.go:156: 
        PATH=/Users/swarming/.swarming/w/ir/x/t/cmd-go-test-2324303667/tmpdir1305803261/testbin:/Users/swarming/.swarming/w/ir/x/w/goroot/bin:/Users/swarming/.swarming/w/ir/x/w/goroot/bin:/Users/swarming/.swarming/w/ir/x/w/goroot/bin:/Users/swarming/.swarming/w/ir/cache/tools/bin:/Users/swarming/.swarming/w/ir/bbagent_utility_packages:/Users/swarming/.swarming/w/ir/bbagent_utility_packages/bin:/Users/swarming/.swarming/w/ir/cipd_bin_packages:/Users/swarming/.swarming/w/ir/cipd_bin_packages/bin:/Users/swarming/.swarming/w/ir/cipd_bin_packages/cpython3:/Users/swarming/.swarming/w/ir/cipd_bin_packages/cpython3/bin:/Users/swarming/.swarming/w/ir/cache/cipd_client:/Users/swarming/.swarming/w/ir/cache/cipd_client/bin:/Users/swarming/.swarming/cipd_cache/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/sbin:/usr/sbin:/sbin
        HOME=/no-home
        CCACHE_DISABLE=1
        GOARCH=amd64
...
        r14    0xd2010000d300
        r15    0x8400
        rip    0x7ff813a840de
        rflags 0x247
        cs     0x7
        fs     0x0
        gs     0x0
        [exit status 2]
    script_test.go:156: FAIL: testdata/script/cgo_path_space.txt:23: context deadline exceeded
--- FAIL: TestScript/cgo_path_space (10.40s)

2024-01-09 15:29 gotip-darwin-amd64_13 go@aba18d5b cmd/fix.TestRewrite (log)

=== RUN   TestRewrite/jni.MapValue
panic: test timed out after 9m0s
running tests:
	TestRewrite (9m0s)
	TestRewrite/jni.MapValue (20s)

goroutine 94 gp=0xc000006c40 m=5 mp=0xc000100908 [running]:
panic({0xc4a8460?, 0xc0004dc200?})
	/Users/swarming/.swarming/w/ir/x/w/goroot/src/runtime/panic.go:779 +0x158 fp=0xc0004f8f10 sp=0xc0004f8e60 pc=0xc31d338
testing.(*M).startAlarm.func1()
...
cmd/fix.TestRewrite.func3(0xc0001d04e0)
	/Users/swarming/.swarming/w/ir/x/w/goroot/src/cmd/fix/main_test.go:145 +0x2e8 fp=0xc000169f70 sp=0xc000169eb0 pc=0xc452dc8
testing.tRunner(0xc0001d04e0, 0xc000026260)
	/Users/swarming/.swarming/w/ir/x/w/goroot/src/testing/testing.go:1689 +0xfb fp=0xc000169fc0 sp=0xc000169f70 pc=0xc3ba61b
testing.(*T).Run.gowrap1()
	/Users/swarming/.swarming/w/ir/x/w/goroot/src/testing/testing.go:1742 +0x25 fp=0xc000169fe0 sp=0xc000169fc0 pc=0xc3bb645
runtime.goexit({})
	/Users/swarming/.swarming/w/ir/x/w/goroot/src/runtime/asm_amd64.s:1695 +0x1 fp=0xc000169fe8 sp=0xc000169fe0 pc=0xc356d41
created by testing.(*T).Run in goroutine 34
	/Users/swarming/.swarming/w/ir/x/w/goroot/src/testing/testing.go:1742 +0x390

2024-01-09 15:29 gotip-darwin-amd64_13 go@aba18d5b cmd/go.TestScript (log)

=== RUN   TestScript/build_pgo_auto_multi
=== PAUSE TestScript/build_pgo_auto_multi
=== CONT  TestScript/build_pgo_auto_multi
    script_test.go:132: 2024-01-09T16:21:55Z
    script_test.go:134: $WORK=/Users/swarming/.swarming/w/ir/x/t/cmd-go-test-2333596952/tmpdir3949127613/build_pgo_auto_multi2572497361
    script_test.go:156: 
        PATH=/Users/swarming/.swarming/w/ir/x/t/cmd-go-test-2333596952/tmpdir3949127613/testbin:/Users/swarming/.swarming/w/ir/x/w/goroot/bin:/Users/swarming/.swarming/w/ir/x/w/goroot/bin:/Users/swarming/.swarming/w/ir/x/w/goroot/bin:/Users/swarming/.swarming/w/ir/cache/tools/bin:/Users/swarming/.swarming/w/ir/bbagent_utility_packages:/Users/swarming/.swarming/w/ir/bbagent_utility_packages/bin:/Users/swarming/.swarming/w/ir/cipd_bin_packages:/Users/swarming/.swarming/w/ir/cipd_bin_packages/bin:/Users/swarming/.swarming/w/ir/cipd_bin_packages/cpython3:/Users/swarming/.swarming/w/ir/cipd_bin_packages/cpython3/bin:/Users/swarming/.swarming/w/ir/cache/cipd_client:/Users/swarming/.swarming/w/ir/cache/cipd_client/bin:/Users/swarming/.swarming/cipd_cache/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/sbin:/usr/sbin:/sbin
        HOME=/no-home
        CCACHE_DISABLE=1
        GOARCH=amd64
...
        > ! stderr 'compile.*-pgoprofile=.*nopgo(/|\\\\)nopgo_test\.go'
        # test-only dependencies also have profiles attached (2.137s)
        > stderr 'compile.*-pgoprofile=.*a(/|\\\\)default\.pgo.*testdep(/|\\\\)testdep\.go'
        matched: /Users/swarming/.swarming/w/ir/x/w/goroot/pkg/tool/darwin_amd64/compile -o $WORK/b091/_pkg_.a -trimpath "$WORK/b091=>" -p test/testdep -lang=go1.20 -complete -buildid 5e_-LXiIG4WlgUhcawtb/5e_-LXiIG4WlgUhcawtb -pgoprofile=/Users/swarming/.swarming/w/ir/x/t/cmd-go-test-2333596952/tmpdir3949127613/build_pgo_auto_multi2572497361/gopath/src/a/default.pgo -c=4 -shared -nolocalimports -importcfg $WORK/b091/importcfg -pack ./testdep/testdep.go
        > stderr 'compile.*-pgoprofile=.*b(/|\\\\)default\.pgo.*testdep(/|\\\\)testdep\.go'
        matched: /Users/swarming/.swarming/w/ir/x/w/goroot/pkg/tool/darwin_amd64/compile -o $WORK/b244/_pkg_.a -trimpath "$WORK/b244=>" -p test/testdep -lang=go1.20 -complete -buildid 5e_-LXiIG4WlgUhcawtb/5e_-LXiIG4WlgUhcawtb -pgoprofile=/Users/swarming/.swarming/w/ir/x/t/cmd-go-test-2333596952/tmpdir3949127613/build_pgo_auto_multi2572497361/gopath/src/b/default.pgo -c=4 -shared -nolocalimports -importcfg $WORK/b244/importcfg -pack ./testdep/testdep.go
        > stderr 'compile.*-pgoprofile=.*a(/|\\\\)default\.pgo.*testdep2(/|\\\\)testdep2\.go'
        matched: /Users/swarming/.swarming/w/ir/x/w/goroot/pkg/tool/darwin_amd64/compile -o $WORK/b092/_pkg_.a -trimpath "$WORK/b092=>" -p test/testdep2 -lang=go1.20 -complete -buildid 2nksUir2tqGHKBXsGUmy/2nksUir2tqGHKBXsGUmy -pgoprofile=/Users/swarming/.swarming/w/ir/x/t/cmd-go-test-2333596952/tmpdir3949127613/build_pgo_auto_multi2572497361/gopath/src/a/default.pgo -c=4 -shared -nolocalimports -importcfg $WORK/b092/importcfg -pack ./testdep2/testdep2.go
    script_test.go:156: FAIL: testdata/script/build_pgo_auto_multi.txt:51: context deadline exceeded
--- FAIL: TestScript/build_pgo_auto_multi (21.81s)

2024-01-10 17:35 gotip-darwin-amd64_11 go@e9b3ff15 cmd/cgo/internal/testplugin.TestIssue22175 (log)

=== RUN   TestIssue22175
( GOPATH=$TMPDIR PWD=$TMPDIR/src/testplugin LD_LIBRARY_PATH=$TMPDIR/src/testplugin /opt/s/w/ir/x/w/goroot/bin/go build -gcflags '' -buildmode=plugin -o issue22175_plugin1.so ./issue22175/plugin1.go )
( GOPATH=$TMPDIR PWD=$TMPDIR/src/testplugin LD_LIBRARY_PATH=$TMPDIR/src/testplugin /opt/s/w/ir/x/w/goroot/bin/go build -gcflags '' -buildmode=plugin -o issue22175_plugin2.so ./issue22175/plugin2.go )
( GOPATH=$TMPDIR PWD=$TMPDIR/src/testplugin LD_LIBRARY_PATH=$TMPDIR/src/testplugin /opt/s/w/ir/x/w/goroot/bin/go build -gcflags '' -o issue22175.exe ./issue22175/main.go )
SIGQUIT: quit
PC=0x7fff20618cbe m=0 sigcode=0

goroutine 0 gp=0x4b05720 m=0 mp=0x4b05f20 [idle]:
runtime.pthread_cond_wait(0x4b06568, 0x4b06528)
	/opt/s/w/ir/x/w/goroot/src/runtime/sys_darwin.go:507 +0x2e fp=0x7ffeec371bc0 sp=0x7ffeec371b98 pc=0x48e68ee
...
r12    0x4b06528
r13    0x16
r14    0x3b0100003c00
r15    0x3b00
rip    0x7fff20618cbe
rflags 0x247
cs     0x7
fs     0x0
gs     0x0
*** Test killed with quit: ran too long (10m0s).

2024-01-10 17:35 gotip-darwin-amd64_11 go@e9b3ff15 cmd/compile/internal/loopvar.TestLoopVarHashes (log)

=== RUN   TestLoopVarHashes
    exec.go:193: test timed out while running command: /opt/s/w/ir/x/w/goroot/bin/go run -trimpath cmd/compile/internal/loopvar/testdata/inlines
    loopvar_test.go:203: SIGQUIT: quit
        PC=0x7fff20618cbe m=0 sigcode=0
        
        goroutine 0 gp=0x3680740 m=0 mp=0x3682440 [idle]:
        runtime.pthread_cond_wait(0x3682a88, 0x3682a48)
        	runtime/sys_darwin.go:507 +0x2e fp=0x7ffeee0b7a20 sp=0x7ffeee0b79f8 pc=0x2ba50ae
        runtime.semasleep(0xffffffffffffffff)
        	runtime/os_darwin.go:71 +0xaf fp=0x7ffeee0b7a78 sp=0x7ffeee0b7a20 pc=0x2b806ef
...
panic: test timed out after 9m0s
running tests:
	TestLoopVarHashes (4m56s)

goroutine 89 gp=0xc000007880 m=4 mp=0xc000080008 [running]:
panic({0x8abd8e0?, 0xc000214040?})
	/opt/s/w/ir/x/w/goroot/src/runtime/panic.go:779 +0x158 fp=0xc000105f10 sp=0xc000105e60 pc=0x8865b38
testing.(*M).startAlarm.func1()
	/opt/s/w/ir/x/w/goroot/src/testing/testing.go:2366 +0x385 fp=0xc000105fe0 sp=0xc000105f10 pc=0x8945a25
runtime.goexit({})
...

goroutine 116 gp=0xc000185500 m=nil [GC worker (idle)]:
runtime.gopark(0x0?, 0x8b1bcf0?, 0xc0?, 0x9e?, 0x8b1ae18?)
	/opt/s/w/ir/x/w/goroot/src/runtime/proc.go:402 +0xce fp=0xc0001f0f50 sp=0xc0001f0f30 pc=0x88694ae
runtime.gcBgMarkWorker()
	/opt/s/w/ir/x/w/goroot/src/runtime/mgc.go:1310 +0xe5 fp=0xc0001f0fe0 sp=0xc0001f0f50 pc=0x884a3c5
runtime.goexit({})
	/opt/s/w/ir/x/w/goroot/src/runtime/asm_amd64.s:1695 +0x1 fp=0xc0001f0fe8 sp=0xc0001f0fe0 pc=0x88a0e21
created by runtime.gcBgMarkStartWorkers in goroutine 77
	/opt/s/w/ir/x/w/goroot/src/runtime/mgc.go:1234 +0x1c

2024-01-10 17:35 gotip-darwin-amd64_11 go@e9b3ff15 cmd/compile/internal/ssa.TestFmaHash (log)

=== RUN   TestFmaHash
    fmahash_test.go:40: /opt/s/w/ir/x/w/goroot/bin/go build -o /opt/s/w/ir/x/t/TestFmaHash2806456817/001/fma.exe testdata/fma.go
    fmahash_test.go:41: [GOCOMPILEDEBUG=fmahash=1/0 GOOS=linux GOARCH=arm64 HOME=/opt/s/w/ir/x/t/TestFmaHash2806456817/001]
    exec.go:193: test timed out while running command: /opt/s/w/ir/x/w/goroot/bin/go build -o /opt/s/w/ir/x/t/TestFmaHash2806456817/001/fma.exe testdata/fma.go
    fmahash_test.go:44: exit status 2
    fmahash_test.go:50: Expected to match 'fmahash(0?) triggered .*fma.go:29:..;.*fma.go:18:..' with 
        -----
        # math
        ../../../../math/expm1.go:212:43 [bisect-match 0x3453d6efcaf1e845]
        fmahash triggered ../../../../math/expm1.go:212:43 111100011110100001000101
...
        r13    0x16
        r14    0xa1010000a200
        r15    0xa100
        rip    0x7fff20618cbe
        rflags 0x247
        cs     0x7
        fs     0x0
        gs     0x0
        -----
--- FAIL: TestFmaHash (56.50s)

2024-01-17 19:47 gotip-darwin-amd64_13 go@92d7169a cmd/fix.TestRewrite (log)

=== RUN   TestRewrite/jni.StructField
panic: test timed out after 9m0s
running tests:
	TestRewrite (9m0s)
	TestRewrite/jni.StructField (0s)

goroutine 87 gp=0xc000007340 m=2 mp=0xc00004a908 [running]:
panic({0xee3f460?, 0xc0003b8e40?})
	/Users/swarming/.swarming/w/ir/x/w/goroot/src/runtime/panic.go:779 +0x158 fp=0xc00009bf10 sp=0xc00009be60 pc=0xecb4338
testing.(*M).startAlarm.func1()
...

goroutine 78 gp=0xc0001848c0 m=nil [GC worker (idle)]:
runtime.gopark(0x267e358508cd?, 0x0?, 0x0?, 0x0?, 0x0?)
	/Users/swarming/.swarming/w/ir/x/w/goroot/src/runtime/proc.go:402 +0xce fp=0xc0001caf50 sp=0xc0001caf30 pc=0xecb7cae
runtime.gcBgMarkWorker()
	/Users/swarming/.swarming/w/ir/x/w/goroot/src/runtime/mgc.go:1310 +0xe5 fp=0xc0001cafe0 sp=0xc0001caf50 pc=0xec992e5
runtime.goexit({})
	/Users/swarming/.swarming/w/ir/x/w/goroot/src/runtime/asm_amd64.s:1695 +0x1 fp=0xc0001cafe8 sp=0xc0001cafe0 pc=0xecedd21
created by runtime.gcBgMarkStartWorkers in goroutine 76
	/Users/swarming/.swarming/w/ir/x/w/goroot/src/runtime/mgc.go:1234 +0x1c

2024-01-17 19:47 gotip-darwin-amd64_13 go@92d7169a cmd/go.TestScript (log)

=== RUN   TestScript/build_pgo_auto_multi
=== PAUSE TestScript/build_pgo_auto_multi
=== CONT  TestScript/build_pgo_auto_multi
    script_test.go:132: 2024-01-17T20:34:31Z
    script_test.go:134: $WORK=/Users/swarming/.swarming/w/ir/x/t/cmd-go-test-1329034139/tmpdir260820126/build_pgo_auto_multi2549261420
    script_test.go:156: 
        PATH=/Users/swarming/.swarming/w/ir/x/t/cmd-go-test-1329034139/tmpdir260820126/testbin:/Users/swarming/.swarming/w/ir/x/w/goroot/bin:/Users/swarming/.swarming/w/ir/x/w/goroot/bin:/Users/swarming/.swarming/w/ir/x/w/goroot/bin:/Users/swarming/.swarming/w/ir/cache/tools/bin:/Users/swarming/.swarming/w/ir/bbagent_utility_packages:/Users/swarming/.swarming/w/ir/bbagent_utility_packages/bin:/Users/swarming/.swarming/w/ir/cipd_bin_packages:/Users/swarming/.swarming/w/ir/cipd_bin_packages/bin:/Users/swarming/.swarming/w/ir/cipd_bin_packages/cpython3:/Users/swarming/.swarming/w/ir/cipd_bin_packages/cpython3/bin:/Users/swarming/.swarming/w/ir/cache/cipd_client:/Users/swarming/.swarming/w/ir/cache/cipd_client/bin:/Users/swarming/.swarming/cipd_cache/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/sbin:/usr/sbin:/sbin
        HOME=/no-home
        CCACHE_DISABLE=1
        GOARCH=amd64
...
        matched: /Users/swarming/.swarming/w/ir/x/w/goroot/pkg/tool/darwin_amd64/compile -o $WORK/b090/_pkg_.a -trimpath "$WORK/b090=>" -p test/a -lang=go1.20 -complete -buildid Rqm7T22QDK7dX9KCHtRw/Rqm7T22QDK7dX9KCHtRw -pgoprofile=/Users/swarming/.swarming/w/ir/x/t/cmd-go-test-1329034139/tmpdir260820126/build_pgo_auto_multi2549261420/gopath/src/a/default.pgo -c=4 -shared -nolocalimports -importcfg $WORK/b090/importcfg -pack ./a/a.go ./a/a_test.go
        > stderr 'compile.*-pgoprofile=.*a(/|\\\\)default\.pgo.*dep(/|\\\\)dep\.go'
        matched: /Users/swarming/.swarming/w/ir/x/w/goroot/pkg/tool/darwin_amd64/compile -o $WORK/b093/_pkg_.a -trimpath "$WORK/b093=>" -p test/dep -lang=go1.20 -complete -buildid vGdknpAWUcCWkpjpt7GB/vGdknpAWUcCWkpjpt7GB -pgoprofile=/Users/swarming/.swarming/w/ir/x/t/cmd-go-test-1329034139/tmpdir260820126/build_pgo_auto_multi2549261420/gopath/src/a/default.pgo -c=4 -shared -nolocalimports -importcfg $WORK/b093/importcfg -pack ./dep/dep.go
        > stderr 'compile.*-pgoprofile=.*b(/|\\\\)default\.pgo.*b(/|\\\\)b_test\.go'
        matched: /Users/swarming/.swarming/w/ir/x/w/goroot/pkg/tool/darwin_amd64/compile -o $WORK/b243/_pkg_.a -trimpath "$WORK/b243=>" -p test/b -lang=go1.20 -complete -buildid Pb4FQswzaH9tKZXkjg-a/Pb4FQswzaH9tKZXkjg-a -pgoprofile=/Users/swarming/.swarming/w/ir/x/t/cmd-go-test-1329034139/tmpdir260820126/build_pgo_auto_multi2549261420/gopath/src/b/default.pgo -c=4 -shared -nolocalimports -importcfg $WORK/b243/importcfg -pack ./b/b.go ./b/b_test.go
        > stderr 'compile.*-pgoprofile=.*b(/|\\\\)default\.pgo.*dep(/|\\\\)dep\.go'
        matched: /Users/swarming/.swarming/w/ir/x/w/goroot/pkg/tool/darwin_amd64/compile -o $WORK/b246/_pkg_.a -trimpath "$WORK/b246=>" -p test/dep -lang=go1.20 -complete -buildid vGdknpAWUcCWkpjpt7GB/vGdknpAWUcCWkpjpt7GB -pgoprofile=/Users/swarming/.swarming/w/ir/x/t/cmd-go-test-1329034139/tmpdir260820126/build_pgo_auto_multi2549261420/gopath/src/b/default.pgo -c=4 -shared -nolocalimports -importcfg $WORK/b246/importcfg -pack ./dep/dep.go
        > ! stderr 'compile.*-pgoprofile=.*nopgo(/|\\\\)nopgo_test\.go'
    script_test.go:156: FAIL: testdata/script/build_pgo_auto_multi.txt:46: context deadline exceeded
--- FAIL: TestScript/build_pgo_auto_multi (17.17s)

— watchflakes

[cherrymui]

There seem to be timeouts on other LUCI darwin builders (other than 13). I put them all here for now. Feel free to split if this is really specific to 13. Thanks.

[gopherbot]

Found new dashboard test flakes for:

#!watchflakes
post <- builder ~ `gotip-darwin-amd64` && (`test timed out` || `SIGQUIT` || `context deadline exceeded` || status == "ABORT")

2024-01-22 21:47 gotip-darwin-amd64_13 go@b7ae16e0 cmd/fix.TestRewrite (log)

=== RUN   TestRewrite/jni.ArrayElement
panic: test timed out after 9m0s
running tests:
	TestRewrite (9m0s)
	TestRewrite/jni.ArrayElement (18s)

goroutine 97 gp=0xc000084a80 m=3 mp=0xc00004b208 [running]:
panic({0xa010460?, 0xc000026060?})
	/Users/swarming/.swarming/w/ir/x/w/goroot/src/runtime/panic.go:768 +0x158 fp=0xc000074f10 sp=0xc000074e60 pc=0x9e85318
testing.(*M).startAlarm.func1()
...

goroutine 89 gp=0xc0004041c0 m=nil [GC worker (idle)]:
runtime.gopark(0xe7858117334?, 0x0?, 0x0?, 0x0?, 0x0?)
	/Users/swarming/.swarming/w/ir/x/w/goroot/src/runtime/proc.go:402 +0xce fp=0xc0001e2f50 sp=0xc0001e2f30 pc=0x9e88c2e
runtime.gcBgMarkWorker()
	/Users/swarming/.swarming/w/ir/x/w/goroot/src/runtime/mgc.go:1310 +0xe5 fp=0xc0001e2fe0 sp=0xc0001e2f50 pc=0x9e6a2e5
runtime.goexit({})
	/Users/swarming/.swarming/w/ir/x/w/goroot/src/runtime/asm_amd64.s:1695 +0x1 fp=0xc0001e2fe8 sp=0xc0001e2fe0 pc=0x9ebeda1
created by runtime.gcBgMarkStartWorkers in goroutine 71
	/Users/swarming/.swarming/w/ir/x/w/goroot/src/runtime/mgc.go:1234 +0x1c

2024-01-22 21:47 gotip-darwin-amd64_13 go@b7ae16e0 cmd/go.TestScript (log)

=== RUN   TestScript/modfile_flag
=== PAUSE TestScript/modfile_flag
=== CONT  TestScript/modfile_flag
    script_test.go:132: 2024-01-22T22:53:51Z
    script_test.go:134: $WORK=/Users/swarming/.swarming/w/ir/x/t/cmd-go-test-1665181012/tmpdir2501751610/modfile_flag3035229305
    script_test.go:156: 
        PATH=/Users/swarming/.swarming/w/ir/x/t/cmd-go-test-1665181012/tmpdir2501751610/testbin:/Users/swarming/.swarming/w/ir/x/w/goroot/bin:/Users/swarming/.swarming/w/ir/x/w/goroot/bin:/Users/swarming/.swarming/w/ir/x/w/goroot/bin:/Users/swarming/.swarming/w/ir/cache/tools/bin:/Users/swarming/.swarming/w/ir/bbagent_utility_packages:/Users/swarming/.swarming/w/ir/bbagent_utility_packages/bin:/Users/swarming/.swarming/w/ir/cipd_bin_packages:/Users/swarming/.swarming/w/ir/cipd_bin_packages/bin:/Users/swarming/.swarming/w/ir/cipd_bin_packages/cpython3:/Users/swarming/.swarming/w/ir/cipd_bin_packages/cpython3/bin:/Users/swarming/.swarming/w/ir/cache/cipd_client:/Users/swarming/.swarming/w/ir/cache/cipd_client/bin:/Users/swarming/.swarming/cipd_cache/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/sbin:/usr/sbin:/sbin
        HOME=/no-home
        CCACHE_DISABLE=1
        GOARCH=amd64
...
        r13    0xf4b08523
        r14    0xb6486dfe
        r15    0xe4a02e24
        rip    0x4e77c7d
        rflags 0xa13
        cs     0x2b
        fs     0x0
        gs     0x0
    script_test.go:156: FAIL: testdata/script/modfile_flag.txt:36: go mod tidy: exit status 2
--- FAIL: TestScript/modfile_flag (6.60s)

— watchflakes