openbsd-386-72 at 5e91059f8b5cc078b4b0bfa38290a98414e441e2 :: Running /tmp/workdir/go/src/make.bash with args ["/tmp/workdir/go/src/make.bash" "-force"] and env ["HOME=/" "INRC=1" "_=/bin/sh" "WORKDIR=/tmp/workdir" "GO_BUILDER_NAME=openbsd-386-72" "GOBIN=" "GOROOT_BOOTSTRAP=" "TMPDIR=/tmp/workdir/tmp" "GOCACHE=/tmp/workdir/gocache" "GOPLSCACHE=/tmp/workdir/goplscache" "PATH=/tmp/workdir/go1.4/go/bin:/sbin:/bin:/usr/sbin:/usr/bin:/usr/local/bin" "PWD=/tmp/workdir/go/src"] in dir /tmp/workdir/go/src WARNING: //go1.4/bin/go does not exist, found /tmp/workdir/go1.4/go/bin/go from env WARNING: set /tmp/workdir/go1.4/go as GOROOT_BOOTSTRAP Building Go cmd/dist using /tmp/workdir/go1.4/go. (go1.22.6 openbsd/386) Building Go toolchain1 using /tmp/workdir/go1.4/go. Building Go bootstrap cmd/go (go_bootstrap) using Go toolchain1. Building Go toolchain2 using go_bootstrap and Go toolchain1. Building Go toolchain3 using go_bootstrap and Go toolchain2. Building packages and commands for openbsd/386. --- Installed Go for openbsd/386 in /tmp/workdir/go Installed commands in /tmp/workdir/go/bin *** You need to add /tmp/workdir/go/bin to your PATH. ##### Test execution environment. # GOARCH: 386 # CPU: Intel(R) Xeon(R) CPU @ 2.80GHz # GOOS: openbsd # OS Version: OpenBSD 7.2 OpenBSD 7.2 (GENERIC) #5: Tue Jul 25 16:20:24 CEST 2023 root@syspatch-72-i386.openbsd.org:/usr/src/sys/arch/i386/compile/GENERIC i386 ##### Testing packages. ok archive/tar 0.210s ok archive/zip 0.481s ok bufio 0.086s ok bytes 0.472s ok cmp 0.016s ok compress/bzip2 0.094s ok compress/flate 0.871s ok compress/gzip 1.778s ok compress/lzw 0.105s ok compress/zlib 0.598s ok container/heap 0.018s ok container/list 0.016s ok container/ring 0.017s ok context 0.296s ok crypto 1.376s ok crypto/aes 0.042s ok crypto/cipher 2.506s ok crypto/des 0.033s ok crypto/dsa 0.019s ok crypto/ecdh 0.306s ok crypto/ecdsa 0.207s ok crypto/ed25519 0.336s ok crypto/elliptic 0.067s ok crypto/hmac 0.033s ok crypto/internal/alias 0.016s ok crypto/internal/bigmod 0.068s ok crypto/internal/boring 0.016s ok crypto/internal/boring/bcache 0.195s ok crypto/internal/edwards25519 0.535s ok crypto/internal/edwards25519/field 0.083s ok crypto/internal/fips 0.215s ok crypto/internal/fips/check 0.015s ok crypto/internal/fips/sha3 4.346s ok crypto/internal/fips/subtle 0.125s ok crypto/internal/hpke 0.021s ok crypto/internal/mlkem768 0.321s ok crypto/internal/nistec 1.094s ok crypto/internal/nistec/fiat 0.015s [no tests to run] ok crypto/md5 0.020s ok crypto/rand 0.796s ok crypto/rc4 0.067s ok crypto/rsa 1.120s ok crypto/sha1 0.020s ok crypto/sha256 0.020s ok crypto/sha512 0.024s ok crypto/subtle 0.018s ok crypto/tls 2.340s ok crypto/x509 2.478s ok database/sql 0.792s ok database/sql/driver 0.016s ok debug/buildinfo 0.092s ok debug/dwarf 0.062s ok debug/elf 0.211s ok debug/gosym 0.060s ok debug/macho 0.028s ok debug/pe 0.070s ok debug/plan9obj 0.018s ok embed 0.017s [no tests to run] ok embed/internal/embedtest 0.018s ok encoding/ascii85 0.018s ok encoding/asn1 0.020s ok encoding/base32 0.040s ok encoding/base64 0.019s ok encoding/binary 0.027s ok encoding/csv 0.028s ok encoding/gob 4.526s ok encoding/hex 0.019s ok encoding/json 0.465s ok encoding/pem 1.100s ok encoding/xml 0.103s ok errors 0.020s ok expvar 0.020s ok flag 0.073s ok fmt 0.106s ok go/ast 0.022s ok go/ast/internal/tests 0.017s ok go/build 5.293s ok go/build/constraint 0.079s ok go/constant 0.020s ok go/doc 0.110s ok go/doc/comment 1.903s ok go/format 0.022s ok go/importer 0.650s ok go/internal/gccgoimporter 0.037s ok go/internal/gcimporter 4.300s ok go/internal/srcimporter 17.443s ok go/parser 0.504s ok go/printer 0.212s ok go/scanner 0.018s ok go/token 0.031s ok go/types 27.009s ok go/version 0.016s ok hash 0.018s ok hash/adler32 0.023s ok hash/crc32 0.021s ok hash/crc64 0.017s ok hash/fnv 0.016s ok hash/maphash 2.293s ok html 0.018s ok html/template 0.100s ok image 0.090s ok image/color 0.030s ok image/draw 0.099s ok image/gif 0.224s ok image/jpeg 0.225s ok image/png 0.337s ok index/suffixarray 0.218s ok internal/abi 0.170s ok internal/buildcfg 0.016s ok internal/chacha8rand 0.016s ok internal/concurrent 0.090s ok internal/coverage/cfile 1.735s ok internal/coverage/cformat 0.016s ok internal/coverage/cmerge 0.016s ok internal/coverage/pods 0.021s ok internal/coverage/slicereader 0.016s ok internal/coverage/slicewriter 0.015s ok internal/coverage/test 0.029s ok internal/cpu 0.037s ok internal/dag 0.017s ok internal/diff 0.024s ok internal/fmtsort 0.017s ok internal/fuzz 0.024s ok internal/godebug 1.208s ok internal/godebugs 8.973s ok internal/gover 0.016s ok internal/itoa 0.016s ok internal/pkgbits 0.016s ok internal/platform 1.812s ok internal/poll 0.075s ok internal/profile 0.016s ok internal/reflectlite 0.019s ok internal/runtime/atomic 0.054s ok internal/runtime/maps 0.024s ok internal/runtime/math 0.016s ok internal/runtime/sys 0.016s ok internal/saferio 0.111s ok internal/singleflight 0.088s ok internal/sysinfo 0.016s ok internal/testenv 0.457s --- FAIL: TestTraceStress (130.54s) --- FAIL: TestTraceStress/Default (130.54s) exec.go:213: test timed out while running command: /tmp/workdir/go/bin/go run testdata/testprog/stress.go trace_test.go:610: signal: killed panic: test timed out after 3m0s running tests: TestTraceStressStartStop (7s) TestTraceStressStartStop/Default (7s) goroutine 126 gp=0x6d59ea28 m=0 mp=0x840b3c0 [running]: panic({0x8246dc0, 0x6d6022b8}) /tmp/workdir/go/src/runtime/panic.go:806 +0x138 fp=0x6d036f84 sp=0x6d036f30 pc=0x80b3428 testing.(*M).startAlarm.func1() /tmp/workdir/go/src/testing/testing.go:2456 +0x37f fp=0x6d036ff0 sp=0x6d036f84 pc=0x814629f runtime.goexit({}) /tmp/workdir/go/src/runtime/asm_386.s:1393 +0x1 fp=0x6d036ff4 sp=0x6d036ff0 pc=0x80b8f31 created by time.goFunc /tmp/workdir/go/src/time/sleep.go:215 +0x29 goroutine 1 gp=0x6d006128 m=nil [chan receive]: runtime.gopark(0x82919f4, 0x6d01e4f4, 0xe, 0x7, 0x2) /tmp/workdir/go/src/runtime/proc.go:435 +0xfa fp=0x6d066c3c sp=0x6d066c28 pc=0x80b383a runtime.chanrecv(0x6d01e4c0, 0x6d066caf, 0x1) /tmp/workdir/go/src/runtime/chan.go:640 +0x3bd fp=0x6d066c78 sp=0x6d066c3c pc=0x804d9ed runtime.chanrecv1(0x6d01e4c0, 0x6d066caf) /tmp/workdir/go/src/runtime/chan.go:490 +0x1c fp=0x6d066c8c sp=0x6d066c78 pc=0x804d5fc testing.(*T).Run(0x6d006d88, {0x82830f0, 0x18}, 0x8291854) /tmp/workdir/go/src/testing/testing.go:1831 +0x466 fp=0x6d066d10 sp=0x6d066c8c pc=0x8142d36 testing.runTests.func1(0x6d006d88) /tmp/workdir/go/src/testing/testing.go:2251 +0x3f fp=0x6d066d30 sp=0x6d066d10 pc=0x8144eaf testing.tRunner(0x6d006d88, 0x6d066df4) /tmp/workdir/go/src/testing/testing.go:1764 +0x113 fp=0x6d066d90 sp=0x6d066d30 pc=0x8141df3 testing.runTests(0x6d010050, {0x8402e80, 0x1a, 0x1a}, {0xc1c557546bba185e, 0x29e8fcd829, 0x840ab80}) /tmp/workdir/go/src/testing/testing.go:2249 +0x3de fp=0x6d066e08 sp=0x6d066d90 pc=0x8144dce testing.(*M).Run(0x6d058050) /tmp/workdir/go/src/testing/testing.go:2114 +0x632 fp=0x6d066f54 sp=0x6d066e08 pc=0x81437b2 main.main() _testmain.go:99 +0xdf fp=0x6d066fac sp=0x6d066f54 pc=0x8228dcf runtime.main() /tmp/workdir/go/src/runtime/proc.go:283 +0x288 fp=0x6d066ff0 sp=0x6d066fac pc=0x807ff38 runtime.goexit({}) /tmp/workdir/go/src/runtime/asm_386.s:1393 +0x1 fp=0x6d066ff4 sp=0x6d066ff0 pc=0x80b8f31 goroutine 2 gp=0x6d006488 m=nil [force gc (idle), 3 minutes]: runtime.gopark(0x8291b60, 0x840a830, 0x11, 0xa, 0x1) /tmp/workdir/go/src/runtime/proc.go:435 +0xfa fp=0x6d038fdc sp=0x6d038fc8 pc=0x80b383a runtime.goparkunlock(...) /tmp/workdir/go/src/runtime/proc.go:441 runtime.forcegchelper() /tmp/workdir/go/src/runtime/proc.go:348 +0xc7 fp=0x6d038ff0 sp=0x6d038fdc pc=0x8080297 runtime.goexit({}) /tmp/workdir/go/src/runtime/asm_386.s:1393 +0x1 fp=0x6d038ff4 sp=0x6d038ff0 pc=0x80b8f31 created by runtime.init.6 in goroutine 1 /tmp/workdir/go/src/runtime/proc.go:336 +0x1d goroutine 3 gp=0x6d0065a8 m=nil [GC sweep wait]: runtime.gopark(0x8291b60, 0x840a9d0, 0xc, 0x9, 0x1) /tmp/workdir/go/src/runtime/proc.go:435 +0xfa fp=0x6d0397cc sp=0x6d0397b8 pc=0x80b383a runtime.goparkunlock(...) /tmp/workdir/go/src/runtime/proc.go:441 runtime.bgsweep(0x6d01e040) /tmp/workdir/go/src/runtime/mgcsweep.go:317 +0xec fp=0x6d0397e8 sp=0x6d0397cc pc=0x8069e8c runtime.gcenable.gowrap1() /tmp/workdir/go/src/runtime/mgc.go:203 +0x21 fp=0x6d0397f0 sp=0x6d0397e8 pc=0x805b941 runtime.goexit({}) /tmp/workdir/go/src/runtime/asm_386.s:1393 +0x1 fp=0x6d0397f4 sp=0x6d0397f0 pc=0x80b8f31 created by runtime.gcenable in goroutine 1 /tmp/workdir/go/src/runtime/mgc.go:203 +0x71 goroutine 4 gp=0x6d0066c8 m=nil [GC scavenge wait]: runtime.gopark(0x8291b60, 0x840ad00, 0xd, 0xa, 0x2) /tmp/workdir/go/src/runtime/proc.go:435 +0xfa fp=0x6d039fb8 sp=0x6d039fa4 pc=0x80b383a runtime.goparkunlock(...) /tmp/workdir/go/src/runtime/proc.go:441 runtime.(*scavengerState).park(0x840ad00) /tmp/workdir/go/src/runtime/mgcscavenge.go:425 +0x54 fp=0x6d039fcc sp=0x6d039fb8 pc=0x80674d4 runtime.bgscavenge(0x6d01e040) /tmp/workdir/go/src/runtime/mgcscavenge.go:658 +0x69 fp=0x6d039fe8 sp=0x6d039fcc pc=0x8067b29 runtime.gcenable.gowrap2() /tmp/workdir/go/src/runtime/mgc.go:204 +0x21 fp=0x6d039ff0 sp=0x6d039fe8 pc=0x805b901 runtime.goexit({}) /tmp/workdir/go/src/runtime/asm_386.s:1393 +0x1 fp=0x6d039ff4 sp=0x6d039ff0 pc=0x80b8f31 created by runtime.gcenable in goroutine 1 /tmp/workdir/go/src/runtime/mgc.go:204 +0xb1 goroutine 5 gp=0x6d006c68 m=nil [finalizer wait, 2 minutes]: runtime.gopark(0x8291a14, 0x8416e34, 0x10, 0xa, 0x1) /tmp/workdir/go/src/runtime/proc.go:435 +0xfa fp=0x6d03a798 sp=0x6d03a784 pc=0x80b383a runtime.runfinq() /tmp/workdir/go/src/runtime/mfinal.go:193 +0xf0 fp=0x6d03a7f0 sp=0x6d03a798 pc=0x805aaa0 runtime.goexit({}) /tmp/workdir/go/src/runtime/asm_386.s:1393 +0x1 fp=0x6d03a7f4 sp=0x6d03a7f0 pc=0x80b8f31 created by runtime.createfing in goroutine 1 /tmp/workdir/go/src/runtime/mfinal.go:163 +0x5a goroutine 12 gp=0x6d006fc8 m=nil [chan receive, 3 minutes]: runtime.gopark(0x82919f4, 0x6d01e2f4, 0xe, 0x7, 0x2) /tmp/workdir/go/src/runtime/proc.go:435 +0xfa fp=0x6d065d3c sp=0x6d065d28 pc=0x80b383a runtime.chanrecv(0x6d01e2c0, 0x0, 0x1) /tmp/workdir/go/src/runtime/chan.go:640 +0x3bd fp=0x6d065d78 sp=0x6d065d3c pc=0x804d9ed runtime.chanrecv1(0x6d01e2c0, 0x0) /tmp/workdir/go/src/runtime/chan.go:490 +0x1c fp=0x6d065d8c sp=0x6d065d78 pc=0x804d5fc testing.(*T).Parallel(0x6d0070e8) /tmp/workdir/go/src/testing/testing.go:1549 +0x244 fp=0x6d065e08 sp=0x6d065d8c pc=0x8141ad4 internal/trace_test.TestMMU(0x6d0070e8) /tmp/workdir/go/src/internal/trace/gc_test.go:28 +0x2c fp=0x6d065f84 sp=0x6d065e08 pc=0x821b28c testing.tRunner(0x6d0070e8, 0x8291808) /tmp/workdir/go/src/testing/testing.go:1764 +0x113 fp=0x6d065fe4 sp=0x6d065f84 pc=0x8141df3 testing.(*T).Run.gowrap1() /tmp/workdir/go/src/testing/testing.go:1823 +0x28 fp=0x6d065ff0 sp=0x6d065fe4 pc=0x8142e78 runtime.goexit({}) /tmp/workdir/go/src/runtime/asm_386.s:1393 +0x1 fp=0x6d065ff4 sp=0x6d065ff0 pc=0x80b8f31 created by testing.(*T).Run in goroutine 1 /tmp/workdir/go/src/testing/testing.go:1823 +0x447 goroutine 10 gp=0x6d007688 m=nil [GC worker (idle), 1 minutes]: runtime.gopark(0x8291a24, 0x6d018c48, 0x1a, 0xa, 0x0) /tmp/workdir/go/src/runtime/proc.go:435 +0xfa fp=0x6d03878c sp=0x6d038778 pc=0x80b383a runtime.gcBgMarkWorker(0x6d01fe00) /tmp/workdir/go/src/runtime/mgc.go:1363 +0xeb fp=0x6d0387e8 sp=0x6d03878c pc=0x805e26b runtime.gcBgMarkStartWorkers.gowrap1() /tmp/workdir/go/src/runtime/mgc.go:1279 +0x21 fp=0x6d0387f0 sp=0x6d0387e8 pc=0x805e161 runtime.goexit({}) /tmp/workdir/go/src/runtime/asm_386.s:1393 +0x1 fp=0x6d0387f4 sp=0x6d0387f0 pc=0x80b8f31 created by runtime.gcBgMarkStartWorkers in goroutine 9 /tmp/workdir/go/src/runtime/mgc.go:1279 +0x114 goroutine 120 gp=0x6d007328 m=nil [chan receive]: runtime.gopark(0x82919f4, 0x6d01e574, 0xe, 0x7, 0x2) /tmp/workdir/go/src/runtime/proc.go:435 +0xfa fp=0x6d034e60 sp=0x6d034e4c pc=0x80b383a runtime.chanrecv(0x6d01e540, 0x6d034ed3, 0x1) /tmp/workdir/go/src/runtime/chan.go:640 +0x3bd fp=0x6d034e9c sp=0x6d034e60 pc=0x804d9ed runtime.chanrecv1(0x6d01e540, 0x6d034ed3) /tmp/workdir/go/src/runtime/chan.go:490 +0x1c fp=0x6d034eb0 sp=0x6d034e9c pc=0x804d5fc testing.(*T).Run(0x6d1ec248, {0x827c1f1, 0x7}, 0x6d6021b8) /tmp/workdir/go/src/testing/testing.go:1831 +0x466 fp=0x6d034f34 sp=0x6d034eb0 pc=0x8142d36 internal/trace_test.testTraceProg(0x6d1ec248, {0x82812a4, 0x14}, 0x0) /tmp/workdir/go/src/internal/trace/trace_test.go:645 +0x22b fp=0x6d034f70 sp=0x6d034f34 pc=0x82230ab internal/trace_test.TestTraceStressStartStop(0x6d1ec248) /tmp/workdir/go/src/internal/trace/trace_test.go:512 +0x35 fp=0x6d034f84 sp=0x6d034f70 pc=0x82227a5 testing.tRunner(0x6d1ec248, 0x8291854) /tmp/workdir/go/src/testing/testing.go:1764 +0x113 fp=0x6d034fe4 sp=0x6d034f84 pc=0x8141df3 testing.(*T).Run.gowrap1() /tmp/workdir/go/src/testing/testing.go:1823 +0x28 fp=0x6d034ff0 sp=0x6d034fe4 pc=0x8142e78 runtime.goexit({}) /tmp/workdir/go/src/runtime/asm_386.s:1393 +0x1 fp=0x6d034ff4 sp=0x6d034ff0 pc=0x80b8f31 created by testing.(*T).Run in goroutine 1 /tmp/workdir/go/src/testing/testing.go:1823 +0x447 goroutine 121 gp=0x6d0078c8 m=2 mp=0x6d03c508 [syscall]: syscall.syscall6(0x80ce120, 0xc9e3, 0x6d063e54, 0x0, 0x6d814230, 0x0, 0x0) /tmp/workdir/go/src/runtime/sys_openbsd3.go:54 +0x20 fp=0x6d063e00 sp=0x6d063df0 pc=0x80b6790 syscall.wait4(0xc9e3, 0x6d063e54, 0x0, 0x6d814230) /tmp/workdir/go/src/syscall/zsyscall_openbsd_386.go:43 +0x61 fp=0x6d063e38 sp=0x6d063e00 pc=0x80cc5f1 syscall.Wait4(0xc9e3, 0x6d063e78, 0x0, 0x6d814230) /tmp/workdir/go/src/syscall/syscall_bsd.go:144 +0x3b fp=0x6d063e5c sp=0x6d063e38 pc=0x80cbe3b os.(*Process).pidWait(0x6d0f2210) /tmp/workdir/go/src/os/exec_unix.go:70 +0xb4 fp=0x6d063e94 sp=0x6d063e5c pc=0x80eaa84 os.(*Process).wait(0x6d0f2210) /tmp/workdir/go/src/os/exec_unix.go:30 +0x23 fp=0x6d063ea8 sp=0x6d063e94 pc=0x80ea973 os.(*Process).Wait(...) /tmp/workdir/go/src/os/exec.go:358 os/exec.(*Cmd).Wait(0x6d08a1a8) /tmp/workdir/go/src/os/exec/exec.go:922 +0x36 fp=0x6d063ee0 sp=0x6d063ea8 pc=0x8173cb6 os/exec.(*Cmd).Run(0x6d08a1a8) /tmp/workdir/go/src/os/exec/exec.go:626 +0x3f fp=0x6d063ef0 sp=0x6d063ee0 pc=0x8172aaf internal/trace_test.testTraceProg.func1(0x6d1ec368, 0x0, {0x0, 0x0}) /tmp/workdir/go/src/internal/trace/trace_test.go:606 +0x3b4 fp=0x6d063f70 sp=0x6d063ef0 pc=0x8223724 internal/trace_test.testTraceProg.func2(0x6d1ec368) /tmp/workdir/go/src/internal/trace/trace_test.go:646 +0x32 fp=0x6d063f84 sp=0x6d063f70 pc=0x8223362 testing.tRunner(0x6d1ec368, 0x6d6021b8) /tmp/workdir/go/src/testing/testing.go:1764 +0x113 fp=0x6d063fe4 sp=0x6d063f84 pc=0x8141df3 testing.(*T).Run.gowrap1() /tmp/workdir/go/src/testing/testing.go:1823 +0x28 fp=0x6d063ff0 sp=0x6d063fe4 pc=0x8142e78 runtime.goexit({}) /tmp/workdir/go/src/runtime/asm_386.s:1393 +0x1 fp=0x6d063ff4 sp=0x6d063ff0 pc=0x80b8f31 created by testing.(*T).Run in goroutine 120 /tmp/workdir/go/src/testing/testing.go:1823 +0x447 goroutine 124 gp=0x6d59e6c8 m=nil [chan send]: runtime.gopark(0x82919f4, 0x6d01e5f4, 0xf, 0x6, 0x2) /tmp/workdir/go/src/runtime/proc.go:435 +0xfa fp=0x6d064ee8 sp=0x6d064ed4 pc=0x80b383a runtime.chansend(0x6d01e5c0, 0x6d064fd4, 0x1, 0x8173ba7) /tmp/workdir/go/src/runtime/chan.go:271 +0x299 fp=0x6d064f20 sp=0x6d064ee8 pc=0x804cd89 runtime.chansend1(0x6d01e5c0, 0x6d064fd4) /tmp/workdir/go/src/runtime/chan.go:157 +0x24 fp=0x6d064f38 sp=0x6d064f20 pc=0x804cae4 os/exec.(*Cmd).watchCtx(0x6d08a1a8, 0x6d01e5c0) /tmp/workdir/go/src/os/exec/exec.go:873 +0x497 fp=0x6d064fe4 sp=0x6d064f38 pc=0x8173ba7 os/exec.(*Cmd).Start.gowrap2() /tmp/workdir/go/src/os/exec/exec.go:775 +0x28 fp=0x6d064ff0 sp=0x6d064fe4 pc=0x81734c8 runtime.goexit({}) /tmp/workdir/go/src/runtime/asm_386.s:1393 +0x1 fp=0x6d064ff4 sp=0x6d064ff0 pc=0x80b8f31 created by os/exec.(*Cmd).Start in goroutine 121 /tmp/workdir/go/src/os/exec/exec.go:775 +0x87b FAIL internal/trace 180.981s FAIL go tool dist: Failed: exit status 1