openbsd-386-72 at 0214749fef334f9879287d6eec3f059e803a5270 :: Running /tmp/workdir/go/src/make.bash with args ["/tmp/workdir/go/src/make.bash" "-force"] and env ["HOME=/" "PATH=/sbin:/bin:/usr/sbin:/usr/bin:/usr/local/bin" "INRC=1" "_=/bin/sh" "WORKDIR=/tmp/workdir" "GOROOT_BOOTSTRAP=/tmp/workdir/go1.4" "GO_BUILDER_NAME=openbsd-386-72" "GOBIN=" "TMPDIR=/tmp/workdir/tmp" "GOCACHE=/tmp/workdir/gocache" "GOPLSCACHE=/tmp/workdir/goplscache" "PWD=/tmp/workdir/go/src"] in dir /tmp/workdir/go/src Building Go cmd/dist using /tmp/workdir/go1.4. (go1.20.6 openbsd/386) Building Go toolchain1 using /tmp/workdir/go1.4. 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.204s ok archive/zip 0.468s ok bufio 0.085s ok bytes 0.447s ok cmp 0.015s ok compress/bzip2 0.092s ok compress/flate 0.862s ok compress/gzip 1.712s ok compress/lzw 0.111s ok compress/zlib 0.609s ok container/heap 0.017s ok container/list 0.015s ok container/ring 0.017s ok context 0.303s ok crypto 1.234s ok crypto/aes 0.036s ok crypto/cipher 0.020s ok crypto/des 0.028s ok crypto/dsa 0.018s ok crypto/ecdh 0.307s ok crypto/ecdsa 0.208s ok crypto/ed25519 0.340s ok crypto/elliptic 0.067s ok crypto/hmac 0.032s ok crypto/internal/alias 0.016s ok crypto/internal/bigmod 0.067s ok crypto/internal/boring 0.015s ok crypto/internal/boring/bcache 0.216s ok crypto/internal/edwards25519 0.532s ok crypto/internal/edwards25519/field 0.083s ok crypto/internal/hpke 0.021s ok crypto/internal/mlkem768 0.325s ok crypto/internal/nistec 1.088s ok crypto/internal/nistec/fiat 0.015s [no tests to run] ok crypto/md5 0.020s ok crypto/rand 0.128s ok crypto/rc4 0.057s ok crypto/rsa 1.091s ok crypto/sha1 0.019s ok crypto/sha256 0.019s ok crypto/sha512 0.023s ok crypto/subtle 0.286s ok crypto/tls 2.363s ok crypto/x509 2.564s ok database/sql 0.799s ok database/sql/driver 0.015s ok debug/buildinfo 0.068s ok debug/dwarf 0.060s ok debug/elf 0.218s ok debug/gosym 0.058s ok debug/macho 0.028s ok debug/pe 0.069s ok debug/plan9obj 0.017s ok embed 0.017s [no tests to run] ok embed/internal/embedtest 0.017s ok encoding/ascii85 0.017s ok encoding/asn1 0.019s ok encoding/base32 0.039s ok encoding/base64 0.019s ok encoding/binary 0.025s ok encoding/csv 0.028s ok encoding/gob 4.537s ok encoding/hex 0.021s ok encoding/json 0.470s ok encoding/pem 1.108s ok encoding/xml 0.097s ok errors 0.019s ok expvar 0.020s ok flag 0.071s ok fmt 0.106s ok go/ast 0.021s ok go/build 3.994s ok go/build/constraint 0.018s ok go/constant 0.019s ok go/doc 0.109s ok go/doc/comment 1.852s ok go/format 0.026s ok go/importer 0.623s ok go/internal/gccgoimporter 0.041s ok go/internal/gcimporter 4.046s ok go/internal/srcimporter 17.391s ok go/parser 0.499s ok go/printer 0.215s ok go/scanner 0.017s ok go/token 0.031s ok go/types 25.835s ok go/version 0.015s ok hash 0.017s ok hash/adler32 0.027s ok hash/crc32 0.020s ok hash/crc64 0.017s ok hash/fnv 0.015s ok hash/maphash 0.066s ok html 0.017s ok html/template 0.098s ok image 0.090s ok image/color 0.029s ok image/draw 0.103s ok image/gif 0.208s ok image/jpeg 0.224s ok image/png 0.345s ok index/suffixarray 0.219s ok internal/abi 0.159s ok internal/buildcfg 0.015s ok internal/chacha8rand 0.016s ok internal/concurrent 0.078s ok internal/coverage/cfile 1.690s ok internal/coverage/cformat 0.016s ok internal/coverage/cmerge 0.015s ok internal/coverage/pods 0.018s ok internal/coverage/slicereader 0.015s ok internal/coverage/slicewriter 0.020s ok internal/coverage/test 0.025s ok internal/cpu 0.037s ok internal/dag 0.016s ok internal/diff 0.022s ok internal/fmtsort 0.016s ok internal/fuzz 0.024s ok internal/godebug 1.173s ok internal/godebugs 8.803s ok internal/gover 0.015s ok internal/itoa 0.015s ok internal/platform 1.787s ok internal/poll 0.071s ok internal/profile 0.015s ok internal/reflectlite 0.018s ok internal/runtime/atomic 0.052s ok internal/runtime/math 0.017s ok internal/runtime/sys 0.015s ok internal/saferio 0.108s ok internal/singleflight 0.084s ok internal/sysinfo 0.015s ok internal/testenv 0.424s --- FAIL: TestTraceStressStartStop (93.24s) --- FAIL: TestTraceStressStartStop/Default (93.24s) exec.go:193: test timed out while running command: /tmp/workdir/go/bin/go run testdata/testprog/stress-start-stop.go trace_test.go:616: signal: killed panic: test timed out after 3m0s running tests: TestTraceWaitOnPipe (2s) TestTraceWaitOnPipe/Default (2s) goroutine 140 gp=0x4bd02488 m=3 mp=0x4b83ca08 [running]: panic({0x82380e0, 0x5af1f3d8}) /tmp/workdir/go/src/runtime/panic.go:804 +0x138 fp=0x4ba0ff84 sp=0x4ba0ff30 pc=0x80b6468 testing.(*M).startAlarm.func1() /tmp/workdir/go/src/testing/testing.go:2373 +0x37e fp=0x4ba0fff0 sp=0x4ba0ff84 pc=0x814281e runtime.goexit({}) /tmp/workdir/go/src/runtime/asm_386.s:1393 +0x1 fp=0x4ba0fff4 sp=0x4ba0fff0 pc=0x80bce91 created by time.goFunc /tmp/workdir/go/src/time/sleep.go:215 +0x29 goroutine 1 gp=0x4b806128 m=nil [chan receive]: runtime.gopark(0x827dbfc, 0x5af31d34, 0xe, 0x7, 0x2) /tmp/workdir/go/src/runtime/proc.go:424 +0xfa fp=0x4b884c54 sp=0x4b884c40 pc=0x80b681a runtime.chanrecv(0x5af31d00, 0x4b884cc7, 0x1) /tmp/workdir/go/src/runtime/chan.go:639 +0x3bd fp=0x4b884c90 sp=0x4b884c54 pc=0x804dbad runtime.chanrecv1(0x5af31d00, 0x4b884cc7) /tmp/workdir/go/src/runtime/chan.go:489 +0x1c fp=0x4b884ca4 sp=0x4b884c90 pc=0x804d7bc testing.(*T).Run(0x4b87e008, {0x826d0b0, 0x13}, 0x827da60) /tmp/workdir/go/src/testing/testing.go:1751 +0x3ea fp=0x4b884d1c sp=0x4b884ca4 pc=0x813f32a testing.runTests.func1(0x4b87e008) /tmp/workdir/go/src/testing/testing.go:2168 +0x3f fp=0x4b884d3c sp=0x4b884d1c pc=0x814142f testing.tRunner(0x4b87e008, 0x4b884df4) /tmp/workdir/go/src/testing/testing.go:1690 +0x113 fp=0x4b884d9c sp=0x4b884d3c pc=0x813e463 testing.runTests(0x4b810040, {0x83e51e0, 0x1a, 0x1a}, {0xc1a2b6111a7ce72a, 0x29e8ef0cee, 0x83ecea0}) /tmp/workdir/go/src/testing/testing.go:2166 +0x379 fp=0x4b884e08 sp=0x4b884d9c pc=0x8141349 testing.(*M).Run(0x4b858050) /tmp/workdir/go/src/testing/testing.go:2034 +0x634 fp=0x4b884f54 sp=0x4b884e08 pc=0x813fda4 main.main() _testmain.go:99 +0xdf fp=0x4b884fac sp=0x4b884f54 pc=0x821c8af runtime.main() /tmp/workdir/go/src/runtime/proc.go:272 +0x288 fp=0x4b884ff0 sp=0x4b884fac pc=0x80815c8 runtime.goexit({}) /tmp/workdir/go/src/runtime/asm_386.s:1393 +0x1 fp=0x4b884ff4 sp=0x4b884ff0 pc=0x80bce91 goroutine 2 gp=0x4b806488 m=nil [force gc (idle), 3 minutes]: runtime.gopark(0x827dd68, 0x83ecb58, 0x11, 0xa, 0x1) /tmp/workdir/go/src/runtime/proc.go:424 +0xfa fp=0x4b838fdc sp=0x4b838fc8 pc=0x80b681a runtime.goparkunlock(...) /tmp/workdir/go/src/runtime/proc.go:430 runtime.forcegchelper() /tmp/workdir/go/src/runtime/proc.go:337 +0xc7 fp=0x4b838ff0 sp=0x4b838fdc pc=0x8081927 runtime.goexit({}) /tmp/workdir/go/src/runtime/asm_386.s:1393 +0x1 fp=0x4b838ff4 sp=0x4b838ff0 pc=0x80bce91 created by runtime.init.6 in goroutine 1 /tmp/workdir/go/src/runtime/proc.go:325 +0x1d goroutine 3 gp=0x4b8065a8 m=nil [GC sweep wait]: runtime.gopark(0x827dd68, 0x83eccf0, 0xc, 0x9, 0x1) /tmp/workdir/go/src/runtime/proc.go:424 +0xfa fp=0x4b8397cc sp=0x4b8397b8 pc=0x80b681a runtime.goparkunlock(...) /tmp/workdir/go/src/runtime/proc.go:430 runtime.bgsweep(0x4b81e040) /tmp/workdir/go/src/runtime/mgcsweep.go:317 +0xec fp=0x4b8397e8 sp=0x4b8397cc pc=0x806b52c runtime.gcenable.gowrap1() /tmp/workdir/go/src/runtime/mgc.go:203 +0x21 fp=0x4b8397f0 sp=0x4b8397e8 pc=0x805cfa1 runtime.goexit({}) /tmp/workdir/go/src/runtime/asm_386.s:1393 +0x1 fp=0x4b8397f4 sp=0x4b8397f0 pc=0x80bce91 created by runtime.gcenable in goroutine 1 /tmp/workdir/go/src/runtime/mgc.go:203 +0x71 goroutine 4 gp=0x4b8066c8 m=nil [GC scavenge wait]: runtime.gopark(0x827dd68, 0x83ecfc0, 0xd, 0xa, 0x2) /tmp/workdir/go/src/runtime/proc.go:424 +0xfa fp=0x4b839fb8 sp=0x4b839fa4 pc=0x80b681a runtime.goparkunlock(...) /tmp/workdir/go/src/runtime/proc.go:430 runtime.(*scavengerState).park(0x83ecfc0) /tmp/workdir/go/src/runtime/mgcscavenge.go:425 +0x54 fp=0x4b839fcc sp=0x4b839fb8 pc=0x8068b14 runtime.bgscavenge(0x4b81e040) /tmp/workdir/go/src/runtime/mgcscavenge.go:658 +0x69 fp=0x4b839fe8 sp=0x4b839fcc pc=0x8069169 runtime.gcenable.gowrap2() /tmp/workdir/go/src/runtime/mgc.go:204 +0x21 fp=0x4b839ff0 sp=0x4b839fe8 pc=0x805cf61 runtime.goexit({}) /tmp/workdir/go/src/runtime/asm_386.s:1393 +0x1 fp=0x4b839ff4 sp=0x4b839ff0 pc=0x80bce91 created by runtime.gcenable in goroutine 1 /tmp/workdir/go/src/runtime/mgc.go:204 +0xb1 goroutine 5 gp=0x4b806c68 m=nil [finalizer wait, 2 minutes]: runtime.gopark(0x827dc1c, 0x83f90f4, 0x10, 0xa, 0x1) /tmp/workdir/go/src/runtime/proc.go:424 +0xfa fp=0x4b83a798 sp=0x4b83a784 pc=0x80b681a runtime.runfinq() /tmp/workdir/go/src/runtime/mfinal.go:193 +0xf0 fp=0x4b83a7f0 sp=0x4b83a798 pc=0x805c100 runtime.goexit({}) /tmp/workdir/go/src/runtime/asm_386.s:1393 +0x1 fp=0x4b83a7f4 sp=0x4b83a7f0 pc=0x80bce91 created by runtime.createfing in goroutine 1 /tmp/workdir/go/src/runtime/mfinal.go:163 +0x5a goroutine 12 gp=0x4b806d88 m=nil [chan receive, 3 minutes]: runtime.gopark(0x827dbfc, 0x4b81e274, 0xe, 0x7, 0x2) /tmp/workdir/go/src/runtime/proc.go:424 +0xfa fp=0x4b883d3c sp=0x4b883d28 pc=0x80b681a runtime.chanrecv(0x4b81e240, 0x0, 0x1) /tmp/workdir/go/src/runtime/chan.go:639 +0x3bd fp=0x4b883d78 sp=0x4b883d3c pc=0x804dbad runtime.chanrecv1(0x4b81e240, 0x0) /tmp/workdir/go/src/runtime/chan.go:489 +0x1c fp=0x4b883d8c sp=0x4b883d78 pc=0x804d7bc testing.(*T).Parallel(0x4b87e208) /tmp/workdir/go/src/testing/testing.go:1484 +0x244 fp=0x4b883e08 sp=0x4b883d8c pc=0x813e144 internal/trace_test.TestMMU(0x4b87e208) /tmp/workdir/go/src/internal/trace/gc_test.go:28 +0x2c fp=0x4b883f84 sp=0x4b883e08 pc=0x820f3ec testing.tRunner(0x4b87e208, 0x827da10) /tmp/workdir/go/src/testing/testing.go:1690 +0x113 fp=0x4b883fe4 sp=0x4b883f84 pc=0x813e463 testing.(*T).Run.gowrap1() /tmp/workdir/go/src/testing/testing.go:1743 +0x28 fp=0x4b883ff0 sp=0x4b883fe4 pc=0x813f468 runtime.goexit({}) /tmp/workdir/go/src/runtime/asm_386.s:1393 +0x1 fp=0x4b883ff4 sp=0x4b883ff0 pc=0x80bce91 created by testing.(*T).Run in goroutine 1 /tmp/workdir/go/src/testing/testing.go:1743 +0x3cb goroutine 10 gp=0x4b8070e8 m=nil [GC worker (idle)]: runtime.gopark(0x827dc2c, 0x4b818c48, 0x1a, 0xa, 0x0) /tmp/workdir/go/src/runtime/proc.go:424 +0xfa fp=0x4b83878c sp=0x4b838778 pc=0x80b681a runtime.gcBgMarkWorker(0x4b81fd80) /tmp/workdir/go/src/runtime/mgc.go:1363 +0xeb fp=0x4b8387e8 sp=0x4b83878c pc=0x805f8db runtime.gcBgMarkStartWorkers.gowrap1() /tmp/workdir/go/src/runtime/mgc.go:1279 +0x21 fp=0x4b8387f0 sp=0x4b8387e8 pc=0x805f7d1 runtime.goexit({}) /tmp/workdir/go/src/runtime/asm_386.s:1393 +0x1 fp=0x4b8387f4 sp=0x4b8387f0 pc=0x80bce91 created by runtime.gcBgMarkStartWorkers in goroutine 9 /tmp/workdir/go/src/runtime/mgc.go:1279 +0x114 goroutine 134 gp=0x4b806ea8 m=nil [chan receive]: runtime.gopark(0x827dbfc, 0x5af31db4, 0xe, 0x7, 0x2) /tmp/workdir/go/src/runtime/proc.go:424 +0xfa fp=0x4b835e6c sp=0x4b835e58 pc=0x80b681a runtime.chanrecv(0x5af31d80, 0x4b835edf, 0x1) /tmp/workdir/go/src/runtime/chan.go:639 +0x3bd fp=0x4b835ea8 sp=0x4b835e6c pc=0x804dbad runtime.chanrecv1(0x5af31d80, 0x4b835edf) /tmp/workdir/go/src/runtime/chan.go:489 +0x1c fp=0x4b835ebc sp=0x4b835ea8 pc=0x804d7bc testing.(*T).Run(0x4bedac08, {0x826890a, 0x7}, 0x5af1f2f8) /tmp/workdir/go/src/testing/testing.go:1751 +0x3ea fp=0x4b835f34 sp=0x4b835ebc pc=0x813f32a internal/trace_test.testTraceProg(0x4bedac08, {0x826b6c1, 0xf}, 0x0) /tmp/workdir/go/src/internal/trace/trace_test.go:651 +0x22b fp=0x4b835f70 sp=0x4b835f34 pc=0x82170db internal/trace_test.TestTraceWaitOnPipe(0x4bedac08) /tmp/workdir/go/src/internal/trace/trace_test.go:528 +0x35 fp=0x4b835f84 sp=0x4b835f70 pc=0x8216855 testing.tRunner(0x4bedac08, 0x827da60) /tmp/workdir/go/src/testing/testing.go:1690 +0x113 fp=0x4b835fe4 sp=0x4b835f84 pc=0x813e463 testing.(*T).Run.gowrap1() /tmp/workdir/go/src/testing/testing.go:1743 +0x28 fp=0x4b835ff0 sp=0x4b835fe4 pc=0x813f468 runtime.goexit({}) /tmp/workdir/go/src/runtime/asm_386.s:1393 +0x1 fp=0x4b835ff4 sp=0x4b835ff0 pc=0x80bce91 created by testing.(*T).Run in goroutine 1 /tmp/workdir/go/src/testing/testing.go:1743 +0x3cb goroutine 135 gp=0x4b806fc8 m=2 mp=0x4b83c508 [syscall]: syscall.syscall6(0x80cbc50, 0x65ac, 0x4b834650, 0x0, 0x4bd52550, 0x0, 0x0) /tmp/workdir/go/src/runtime/sys_openbsd3.go:54 +0x20 fp=0x4b8345fc sp=0x4b8345ec pc=0x80ba140 syscall.wait4(0x65ac, 0x4b834650, 0x0, 0x4bd52550) /tmp/workdir/go/src/syscall/zsyscall_openbsd_386.go:43 +0x61 fp=0x4b834634 sp=0x4b8345fc pc=0x80ca121 syscall.Wait4(0x65ac, 0x4b834674, 0x0, 0x4bd52550) /tmp/workdir/go/src/syscall/syscall_bsd.go:144 +0x3b fp=0x4b834658 sp=0x4b834634 pc=0x80c996b os.(*Process).pidWait(0x5ae95c20) /tmp/workdir/go/src/os/exec_unix.go:70 +0xb4 fp=0x4b834690 sp=0x4b834658 pc=0x80e8324 os.(*Process).wait(0x5ae95c20) /tmp/workdir/go/src/os/exec_unix.go:30 +0x23 fp=0x4b8346a4 sp=0x4b834690 pc=0x80e8213 os.(*Process).Wait(...) /tmp/workdir/go/src/os/exec.go:358 os/exec.(*Cmd).Wait(0x4b8ca418) /tmp/workdir/go/src/os/exec/exec.go:906 +0x36 fp=0x4b8346dc sp=0x4b8346a4 pc=0x8168056 os/exec.(*Cmd).Run(0x4b8ca418) /tmp/workdir/go/src/os/exec/exec.go:610 +0x3f fp=0x4b8346ec sp=0x4b8346dc pc=0x8166def internal/trace_test.testTraceProg.func1(0x4bedad08, 0x0, {0x0, 0x0}) /tmp/workdir/go/src/internal/trace/trace_test.go:612 +0x3b4 fp=0x4b834770 sp=0x4b8346ec pc=0x8217754 internal/trace_test.testTraceProg.func2(0x4bedad08) /tmp/workdir/go/src/internal/trace/trace_test.go:652 +0x32 fp=0x4b834784 sp=0x4b834770 pc=0x8217392 testing.tRunner(0x4bedad08, 0x5af1f2f8) /tmp/workdir/go/src/testing/testing.go:1690 +0x113 fp=0x4b8347e4 sp=0x4b834784 pc=0x813e463 testing.(*T).Run.gowrap1() /tmp/workdir/go/src/testing/testing.go:1743 +0x28 fp=0x4b8347f0 sp=0x4b8347e4 pc=0x813f468 runtime.goexit({}) /tmp/workdir/go/src/runtime/asm_386.s:1393 +0x1 fp=0x4b8347f4 sp=0x4b8347f0 pc=0x80bce91 created by testing.(*T).Run in goroutine 134 /tmp/workdir/go/src/testing/testing.go:1743 +0x3cb goroutine 138 gp=0x4bd025a8 m=nil [chan send]: runtime.gopark(0x827dbfc, 0x5af31e74, 0xf, 0x6, 0x2) /tmp/workdir/go/src/runtime/proc.go:424 +0xfa fp=0x4b885ee8 sp=0x4b885ed4 pc=0x80b681a runtime.chansend(0x5af31e40, 0x4b885fd4, 0x1, 0x8167f47) /tmp/workdir/go/src/runtime/chan.go:270 +0x299 fp=0x4b885f20 sp=0x4b885ee8 pc=0x804cf49 runtime.chansend1(0x5af31e40, 0x4b885fd4) /tmp/workdir/go/src/runtime/chan.go:156 +0x24 fp=0x4b885f38 sp=0x4b885f20 pc=0x804cca4 os/exec.(*Cmd).watchCtx(0x4b8ca418, 0x5af31e40) /tmp/workdir/go/src/os/exec/exec.go:857 +0x497 fp=0x4b885fe4 sp=0x4b885f38 pc=0x8167f47 os/exec.(*Cmd).Start.gowrap2() /tmp/workdir/go/src/os/exec/exec.go:759 +0x28 fp=0x4b885ff0 sp=0x4b885fe4 pc=0x8167868 runtime.goexit({}) /tmp/workdir/go/src/runtime/asm_386.s:1393 +0x1 fp=0x4b885ff4 sp=0x4b885ff0 pc=0x80bce91 created by os/exec.(*Cmd).Start in goroutine 135 /tmp/workdir/go/src/os/exec/exec.go:759 +0x8d5 FAIL internal/trace 180.338s ok internal/trace/internal/oldtrace 3.348s ok internal/types/errors 0.942s FAIL go tool dist: Failed: exit status 1