x/build: time out on LUCI Linux/PPC64x builder

[cherrymui]

#!watchflakes
post <- builder ~ `(gotip|go1\.\d\d)-linux-ppc64` && (`test timed out` || `SIGQUIT` || `context deadline exceeded` || `running too slowly` || status == "ABORT") && test != "TestServerReadAfterWriteHeader100Continue/h1"

[gopherbot]

Found new dashboard test flakes for:

#!watchflakes
post <- builder ==  "gotip-linux-ppc64le" && (`test timed out` || `SIGQUIT` || `context deadline exceeded`)

2023-12-06 21:50 gotip-linux-ppc64le go@e914671f cmd/cgo/internal/testshared.TestIssue62277 (log)

=== RUN   TestIssue62277
panic: test timed out after 9m0s
running tests:
	TestIssue62277 (1s)

goroutine 142 gp=0xc0001d61c0 m=2 mp=0xc000044808 [running]:
panic({0x1c37c0?, 0xc0000b20c0?})
	/home/swarming/.swarming/w/ir/x/w/goroot/src/runtime/panic.go:779 +0x174 fp=0xc000182ee0 sp=0xc000182e20 pc=0x4d1e4
testing.(*M).startAlarm.func1()
	/home/swarming/.swarming/w/ir/x/w/goroot/src/testing/testing.go:2366 +0x338 fp=0xc000182fc0 sp=0xc000182ee0 pc=0x104058
...
os/exec.(*Cmd).writerDescriptor.func1()
	/home/swarming/.swarming/w/ir/x/w/goroot/src/os/exec/exec.go:577 +0x4c fp=0xc000185f20 sp=0xc000185eb0 pc=0x13390c
os/exec.(*Cmd).Start.func2(0x0?)
	/home/swarming/.swarming/w/ir/x/w/goroot/src/os/exec/exec.go:724 +0x48 fp=0xc000185f98 sp=0xc000185f20 pc=0x1344e8
os/exec.(*Cmd).Start.gowrap1()
	/home/swarming/.swarming/w/ir/x/w/goroot/src/os/exec/exec.go:736 +0x58 fp=0xc000185fc0 sp=0xc000185f98 pc=0x134488
runtime.goexit({})
	/home/swarming/.swarming/w/ir/x/w/goroot/src/runtime/asm_ppc64x.s:1018 +0x4 fp=0xc000185fc0 sp=0xc000185fc0 pc=0x8bb54
created by os/exec.(*Cmd).Start in goroutine 139
	/home/swarming/.swarming/w/ir/x/w/goroot/src/os/exec/exec.go:723 +0x8ec

2023-12-12 20:05 gotip-linux-ppc64le go@962dade4 cmd/cgo/internal/testshared.TestIssue44031 (log)

=== RUN   TestIssue44031
SIGQUIT: quit
PC=0x8d22c m=0 sigcode=0

goroutine 0 gp=0x360f40 m=0 mp=0x361bc0 [idle]:
runtime.futex(0x361d00, 0x80, 0x0, 0x0, 0x0, 0x0)
	/home/swarming/.swarming/w/ir/x/w/goroot/src/runtime/sys_linux_ppc64x.s:644 +0x1c fp=0x7fffe1a6a2c8 sp=0x7fffe1a6a2c8 pc=0x8d22c
runtime.futexsleep(0x1?, 0x55d30?, 0x361bc0?)
	/home/swarming/.swarming/w/ir/x/w/goroot/src/runtime/os_linux.go:69 +0x30 fp=0x7fffe1a6a328 sp=0x7fffe1a6a2c8 pc=0x4a5d0
runtime.notesleep(0x361d00)
...
r20  0x4	r21  0x2
r22  0x7fffe1a5aa00	r23  0x1
r24  0x0	r25  0x0
r26  0x0	r27  0xe09d261a
r28  0xd617e65a	r29  0xc00002f7a8
r30  0x360f40	r31  0x1cda0
pc   0x8d22c	ctr  0x0
link 0x4a5d0	xer  0x0
ccr  0x34420884	trap 0xc00
*** Test killed with quit: ran too long (10m0s).

2023-12-15 18:30 gotip-linux-ppc64le go@5e939b3a cmd/cgo/internal/testcarchive.TestPIE (log)

=== RUN   TestPIE
    carchive_test.go:956: [go tool cgo -objdir /home/swarming/.swarming/w/ir/x/t/carchive_test2687818152/_obj664230977 -exportheader p.h p/p.go]
panic: test timed out after 9m0s
running tests:
	TestPIE (25s)

goroutine 94 gp=0xc0002fe1c0 m=3 mp=0xc000045008 [running]:
panic({0x1803a0?, 0xc000182730?})
	/home/swarming/.swarming/w/ir/x/w/goroot/src/runtime/panic.go:779 +0x174 fp=0xc000089ee0 sp=0xc000089e20 pc=0x4ceb4
testing.(*M).startAlarm.func1()
...
os/exec.(*Cmd).writerDescriptor.func1()
	/home/swarming/.swarming/w/ir/x/w/goroot/src/os/exec/exec.go:577 +0x4c fp=0xc00028ef20 sp=0xc00028eeb0 pc=0x10814c
os/exec.(*Cmd).Start.func2(0x0?)
	/home/swarming/.swarming/w/ir/x/w/goroot/src/os/exec/exec.go:724 +0x48 fp=0xc00028ef98 sp=0xc00028ef20 pc=0x108d28
os/exec.(*Cmd).Start.gowrap1()
	/home/swarming/.swarming/w/ir/x/w/goroot/src/os/exec/exec.go:736 +0x58 fp=0xc00028efc0 sp=0xc00028ef98 pc=0x108cc8
runtime.goexit({})
	/home/swarming/.swarming/w/ir/x/w/goroot/src/runtime/asm_ppc64x.s:1018 +0x4 fp=0xc00028efc0 sp=0xc00028efc0 pc=0x8b874
created by os/exec.(*Cmd).Start in goroutine 91
	/home/swarming/.swarming/w/ir/x/w/goroot/src/os/exec/exec.go:723 +0x8ec

2023-12-15 18:30 gotip-linux-ppc64le go@5e939b3a cmd/cgo/internal/testshared.TestGlobal (log)

=== RUN   TestGlobal
SIGQUIT: quit
PC=0x8d22c m=0 sigcode=0

goroutine 0 gp=0x360f40 m=0 mp=0x361bc0 [idle]:
runtime.futex(0x361d00, 0x80, 0x0, 0x0, 0x0, 0x0)
	/home/swarming/.swarming/w/ir/x/w/goroot/src/runtime/sys_linux_ppc64x.s:644 +0x1c fp=0x7fffe0703828 sp=0x7fffe0703828 pc=0x8d22c
runtime.futexsleep(0x7d870?, 0x55d30?, 0x361bc0?)
	/home/swarming/.swarming/w/ir/x/w/goroot/src/runtime/os_linux.go:69 +0x30 fp=0x7fffe0703888 sp=0x7fffe0703828 pc=0x4a5d0
runtime.notesleep(0x361d00)
...
r20  0x4	r21  0x1
r22  0x7fffe06f3f60	r23  0x1
r24  0x0	r25  0x0
r26  0x0	r27  0xdf0a0c9
r28  0x9e3a2147	r29  0xdca58061
r30  0x360f40	r31  0x1cda0
pc   0x8d22c	ctr  0x0
link 0x4a5d0	xer  0x0
ccr  0x34420888	trap 0xc00
*** Test killed with quit: ran too long (10m0s).

2023-12-15 20:51 gotip-linux-ppc64le go@f8170cc0 cmd/go.TestScript (log)

=== RUN   TestScript/cgo_path
=== PAUSE TestScript/cgo_path
=== CONT  TestScript/cgo_path
    script_test.go:132: 2023-12-15T22:29:34Z
    script_test.go:134: $WORK=/home/swarming/.swarming/w/ir/x/t/cmd-go-test-1289633616/tmpdir1500409099/cgo_path280284189
    script_test.go:156: 
        PATH=/home/swarming/.swarming/w/ir/x/t/cmd-go-test-1289633616/tmpdir1500409099/testbin:/home/swarming/.swarming/w/ir/x/w/goroot/bin:/home/swarming/.swarming/w/ir/x/w/goroot/bin:/home/swarming/.swarming/w/ir/x/w/goroot/bin:/home/swarming/.swarming/w/ir/cache/tools/bin:/home/swarming/.swarming/w/ir/bbagent_utility_packages:/home/swarming/.swarming/w/ir/bbagent_utility_packages/bin:/home/swarming/.swarming/w/ir/cipd_bin_packages:/home/swarming/.swarming/w/ir/cipd_bin_packages/bin:/home/swarming/.swarming/w/ir/cache/cipd_client:/home/swarming/.swarming/w/ir/cache/cipd_client/bin:/home/swarming/.swarming/cipd_cache/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin
        HOME=/no-home
        CCACHE_DISABLE=1
        GOARCH=ppc64le
...
        r24  0x0	r25  0x0
        r26  0x0	r27  0x110
        r28  0x81e9bc6b	r29  0xc0000581e0
        r30  0x10cf6040	r31  0x100418f4
        pc   0x100082f4	ctr  0x0
        link 0x1000828c	xer  0x0
        ccr  0x34428888	trap 0xc00
        [exit status 2]
    script_test.go:156: FAIL: testdata/script/cgo_path.txt:14: context deadline exceeded
--- FAIL: TestScript/cgo_path (7.88s)

— watchflakes

[pmur]

I wonder if LUCI needs to set GO_TEST_TIMEOUT_SCALE=2 for ppc64{,le}? I don't think I see that set in the logs. The POWER8 builders can be particularly slow. I think the VMs are also subject to sharing CPU time with whatever else is running at OSU.

[cherrymui]

Yeah, GO_TEST_TIMEOUT_SCALE=2 doesn't seem to be set. The old ppc64le builders set GO_TEST_TIMEOUT_SCALE=2, so we probably should do that for LCUI builders as well.

cc @mknyszek

[mknyszek]

I'll send a CL for this today. Thanks.

[gopherbot]

Change https://go.dev/cl/557857 mentions this issue: main.star: add a host-based test timeout scale