openbsd-386-72 at a8487dadeb6057418ee29b3ec8d2f1af0c91a42e :: 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.470s ok bufio 0.086s ok bytes 0.460s ok cmp 0.016s ok compress/bzip2 0.095s ok compress/flate 0.827s ok compress/gzip 1.861s ok compress/lzw 0.110s ok compress/zlib 0.580s ok container/heap 0.018s ok container/list 0.016s ok container/ring 0.017s ok context 0.296s ok crypto 1.282s ok crypto/aes 0.021s ok crypto/cipher 8.974s ok crypto/des 0.032s ok crypto/dsa 0.019s ok crypto/ecdh 0.331s ok crypto/ecdsa 0.192s ok crypto/ed25519 0.347s ok crypto/elliptic 0.058s ? crypto/fips140 [no test files] ok crypto/hkdf 0.016s ok crypto/hmac 0.032s ok crypto/internal/boring 0.015s ? crypto/internal/boring/bbig [no test files] ok crypto/internal/boring/bcache 0.190s ? crypto/internal/boring/sig [no test files] ? crypto/internal/cryptotest [no test files] ? crypto/internal/entropy [no test files] ? crypto/internal/fips140 [no test files] ok crypto/internal/fips140/aes 0.037s ok crypto/internal/fips140/aes/gcm 0.015s [no tests to run] ? crypto/internal/fips140/alias [no test files] ok crypto/internal/fips140/bigmod 0.081s ? crypto/internal/fips140/check [no test files] ? crypto/internal/fips140/check/checktest [no test files] ok crypto/internal/fips140/drbg 0.015s [no tests to run] ok crypto/internal/fips140/ecdh 0.015s ok crypto/internal/fips140/ecdsa 0.169s ? crypto/internal/fips140/ed25519 [no test files] ok crypto/internal/fips140/edwards25519 0.535s ok crypto/internal/fips140/edwards25519/field 0.083s ? crypto/internal/fips140/hkdf [no test files] ? crypto/internal/fips140/hmac [no test files] ok crypto/internal/fips140/mlkem 0.232s ok crypto/internal/fips140/nistec 0.153s ok crypto/internal/fips140/nistec/fiat 0.015s [no tests to run] ? crypto/internal/fips140/pbkdf2 [no test files] ok crypto/internal/fips140/rsa 0.345s ? crypto/internal/fips140/sha256 [no test files] ? crypto/internal/fips140/sha3 [no test files] ? crypto/internal/fips140/sha512 [no test files] ? crypto/internal/fips140/ssh [no test files] ? crypto/internal/fips140/subtle [no test files] ? crypto/internal/fips140/tls12 [no test files] ? crypto/internal/fips140/tls13 [no test files] ok crypto/internal/fips140deps 0.230s ? crypto/internal/fips140deps/byteorder [no test files] ? crypto/internal/fips140deps/cpu [no test files] ? crypto/internal/fips140deps/godebug [no test files] ? crypto/internal/fips140hash [no test files] ? crypto/internal/fips140only [no test files] ok crypto/internal/fips140test 3.224s ok crypto/internal/hpke 0.024s ? crypto/internal/impl [no test files] ? crypto/internal/randutil [no test files] ok crypto/internal/sysrand 0.392s ? crypto/internal/sysrand/internal/seccomp [no test files] ok crypto/md5 0.020s ok crypto/mlkem 0.109s ok crypto/pbkdf2 0.036s ok crypto/rand 0.794s ok crypto/rc4 0.063s ok crypto/rsa 1.271s ok crypto/sha1 0.019s ok crypto/sha256 0.020s ok crypto/sha3 4.358s ok crypto/sha512 0.024s ok crypto/subtle 0.200s ok crypto/tls 26.291s ? crypto/tls/internal/fips140tls [no test files] ok crypto/x509 2.672s ? crypto/x509/pkix [no test files] ok database/sql 0.776s ok database/sql/driver 0.015s ok debug/buildinfo 0.090s ok debug/dwarf 0.059s ok debug/elf 0.206s ok debug/gosym 0.061s ok debug/macho 0.028s ok debug/pe 0.068s ok debug/plan9obj 0.018s ok embed 0.017s [no tests to run] ok embed/internal/embedtest 0.018s ? encoding [no test files] ok encoding/ascii85 0.017s ok encoding/asn1 0.019s ok encoding/base32 0.041s ok encoding/base64 0.020s ok encoding/binary 0.026s ok encoding/csv 0.028s ok encoding/gob 4.617s ok encoding/hex 0.019s ok encoding/json 0.525s ok encoding/pem 1.097s ok encoding/xml 0.094s ok errors 0.019s ok expvar 0.020s ok flag 0.071s ok fmt 0.108s ok go/ast 0.022s ok go/ast/internal/tests 0.016s ok go/build 6.158s ok go/build/constraint 0.080s ok go/constant 0.020s ok go/doc 0.110s ok go/doc/comment 1.616s ok go/format 0.021s ok go/importer 0.658s ok go/internal/gccgoimporter 0.036s ok go/internal/gcimporter 4.775s ok go/internal/srcimporter 17.924s ok go/parser 0.491s ok go/printer 0.203s ok go/scanner 0.018s ok go/token 0.030s ok go/types 27.346s ok go/version 0.015s ok hash 0.017s ok hash/adler32 0.022s ok hash/crc32 0.021s ok hash/crc64 0.022s ok hash/fnv 0.016s ok hash/maphash 2.292s ok html 0.018s ok html/template 0.097s ok image 0.089s ok image/color 0.029s ? image/color/palette [no test files] ok image/draw 0.101s ok image/gif 0.212s ? image/internal/imageutil [no test files] ok image/jpeg 0.223s ok image/png 0.336s ok index/suffixarray 0.219s ok internal/abi 0.168s ? internal/asan [no test files] ? internal/bisect [no test files] ok internal/buildcfg 0.015s ? internal/bytealg [no test files] ? internal/byteorder [no test files] ? internal/cfg [no test files] ok internal/chacha8rand 0.016s ok internal/copyright 0.351s ? internal/coverage [no test files] ? internal/coverage/calloc [no test files] ok internal/coverage/cfile 1.784s ok internal/coverage/cformat 0.016s ok internal/coverage/cmerge 0.015s ? internal/coverage/decodecounter [no test files] ? internal/coverage/decodemeta [no test files] ? internal/coverage/encodecounter [no test files] ? internal/coverage/encodemeta [no test files] ok internal/coverage/pods 0.018s ? internal/coverage/rtcov [no test files] ok internal/coverage/slicereader 0.015s ok internal/coverage/slicewriter 0.015s ? internal/coverage/stringtab [no test files] ok internal/coverage/test 0.024s ? internal/coverage/uleb128 [no test files] ok internal/cpu 0.038s ok internal/dag 0.016s ok internal/diff 0.022s ? internal/exportdata [no test files] ? internal/filepathlite [no test files] ok internal/fmtsort 0.017s ok internal/fuzz 0.023s ? internal/goarch [no test files] ok internal/godebug 1.195s ok internal/godebugs 8.862s ? internal/goexperiment [no test files] ? internal/goos [no test files] ? internal/goroot [no test files] ok internal/gover 0.016s ? internal/goversion [no test files] ok internal/itoa 0.015s ? internal/lazyregexp [no test files] ? internal/lazytemplate [no test files] ? internal/msan [no test files] ? internal/nettrace [no test files] ? internal/obscuretestdata [no test files] ? internal/oserror [no test files] ok internal/pkgbits 0.015s ok internal/platform 1.909s ok internal/poll 0.069s ok internal/profile 0.015s ? internal/profilerecord [no test files] ? internal/race [no test files] ok internal/reflectlite 0.018s ok internal/routebsd 0.017s ok internal/runtime/atomic 0.053s ? internal/runtime/exithook [no test files] ok internal/runtime/maps 0.023s ok internal/runtime/math 0.015s ok internal/runtime/sys 0.016s ok internal/saferio 0.111s ok internal/singleflight 0.126s ? internal/stringslite [no test files] ok internal/sync 1.185s ok internal/synctest 1.392s ? internal/syscall/execenv [no test files] ? internal/syscall/unix [no test files] ok internal/sysinfo 0.015s ? internal/syslist [no test files] ok internal/testenv 0.469s ? internal/testlog [no test files] ? internal/testpty [no test files] --- FAIL: TestTraceStress (122.08s) --- FAIL: TestTraceStress/Default (122.08s) exec.go:213: test timed out while running command: /tmp/workdir/go/bin/go run testdata/testprog/stress.go trace_test.go:615: context deadline exceeded --- FAIL: TestTraceStressStartStop (12.77s) --- FAIL: TestTraceStressStartStop/Default (12.77s) exec.go:213: test timed out while running command: /tmp/workdir/go/bin/go run testdata/testprog/stress-start-stop.go trace_test.go:615: signal: killed --- FAIL: TestTraceManyStartStop (0.52s) --- FAIL: TestTraceManyStartStop/Default (0.52s) exec.go:213: test timed out while running command: /tmp/workdir/go/bin/go run testdata/testprog/many-start-stop.go trace_test.go:613: stderr: SIGQUIT: quit PC=0x2966dc2f m=3 sigcode=0 goroutine 0 gp=0x54c08b48 m=3 mp=0x54c43008 [idle]: runtime.kevent(0x40, 0x0, 0x0, 0x180d03e0, 0x40, 0x180d03b8) runtime/sys_openbsd2.go:219 +0x21 fp=0x180d0390 sp=0x180d0380 pc=0x80a8bb1 runtime.netpoll(0x334cfafa) runtime/netpoll_kqueue.go:110 +0xe3 fp=0x180d09e8 sp=0x180d0390 pc=0x8085623 runtime.findRunnable() runtime/proc.go:3602 +0xa04 fp=0x180d0ab4 sp=0x180d09e8 pc=0x8090ba4 runtime.schedule() runtime/proc.go:4017 +0xb1 fp=0x180d0ad0 sp=0x180d0ab4 pc=0x80922f1 runtime.park_m(0x54ed3b08) runtime/proc.go:4141 +0x227 fp=0x180d0afc sp=0x180d0ad0 pc=0x8092767 runtime.mcall(0x40000) runtime/asm_386.s:329 +0x40 fp=0x180d0b04 sp=0x180d0afc pc=0x80c4590 goroutine 1 gp=0x54c08128 m=nil [sync.WaitGroup.Wait]: runtime.gopark(0x87bb364, 0x8c39c00, 0x18, 0x5, 0x4) runtime/proc.go:435 +0xfa fp=0x54cd1ae0 sp=0x54cd1acc pc=0x80bfada runtime.goparkunlock(...) runtime/proc.go:441 runtime.semacquire1(0x54e36a68, 0x0, 0x1, 0x0, 0x18) runtime/sema.go:188 +0x27b fp=0x54cd1b10 sp=0x54cd1ae0 pc=0x809e20b sync.runtime_SemacquireWaitGroup(0x54e36a68) runtime/sema.go:110 +0x35 fp=0x54cd1b28 sp=0x54cd1b10 pc=0x80c1115 sync.(*WaitGroup).Wait(0x54e36a60) sync/waitgroup.go:118 +0x5f fp=0x54cd1b44 sp=0x54cd1b28 pc=0x80cfebf cmd/go/internal/work.(*Builder).Do(0x54c744b0, {0x88821e0, 0x8c3e380}, 0x54f091e8) cmd/go/internal/work/exec.go:234 +0x419 fp=0x54cd1bdc sp=0x54cd1b44 pc=0x8538799 cmd/go/internal/run.runRun({0x88821e0, 0x8c3e380}, 0x8c286c0, {0x54c1c118, 0x1, 0x1}) cmd/go/internal/run/run.go:172 +0x806 fp=0x54cd1c90 sp=0x54cd1bdc pc=0x858d106 main.invoke(0x8c286c0, {0x54c1c110, 0x2, 0x2}) cmd/go/main.go:341 +0x8ba fp=0x54cd1e64 sp=0x54cd1c90 pc=0x85dad0a main.main() cmd/go/main.go:220 +0x1031 fp=0x54cd1fac sp=0x54cd1e64 pc=0x85d9d71 runtime.main() runtime/proc.go:283 +0x288 fp=0x54cd1ff0 sp=0x54cd1fac pc=0x808acd8 runtime.goexit({}) runtime/asm_386.s:1393 +0x1 fp=0x54cd1ff4 sp=0x54cd1ff0 pc=0x80c5921 goroutine 2 gp=0x54c08488 m=nil [force gc (idle)]: runtime.gopark(0x87bb364, 0x8c2f7d0, 0x11, 0xa, 0x1) runtime/proc.go:435 +0xfa fp=0x54c3e7dc sp=0x54c3e7c8 pc=0x80bfada runtime.goparkunlock(...) runtime/proc.go:441 runtime.forcegchelper() runtime/proc.go:348 +0xc7 fp=0x54c3e7f0 sp=0x54c3e7dc pc=0x808b037 runtime.goexit({}) runtime/asm_386.s:1393 +0x1 fp=0x54c3e7f4 sp=0x54c3e7f0 pc=0x80c5921 created by runtime.init.6 in goroutine 1 runtime/proc.go:336 +0x1d goroutine 3 gp=0x54c085a8 m=nil [GC sweep wait]: runtime.gopark(0x87bb364, 0x8c2fba0, 0xc, 0x9, 0x1) runtime/proc.go:435 +0xfa fp=0x54f3cfcc sp=0x54f3cfb8 pc=0x80bfada runtime.goparkunlock(...) runtime/proc.go:441 runtime.bgsweep(0x54c24040) runtime/mgcsweep.go:316 +0xec fp=0x54f3cfe8 sp=0x54f3cfcc pc=0x8076dec runtime.gcenable.gowrap1() runtime/mgc.go:204 +0x21 fp=0x54f3cff0 sp=0x54f3cfe8 pc=0x80685e1 runtime.goexit({}) runtime/asm_386.s:1393 +0x1 fp=0x54f3cff4 sp=0x54f3cff0 pc=0x80c5921 created by runtime.gcenable in goroutine 1 runtime/mgc.go:204 +0x71 goroutine 4 gp=0x54c086c8 m=nil [sleep]: runtime.gopark(0x87bb364, 0x8c30900, 0x13, 0xe, 0x2) runtime/proc.go:435 +0xfa fp=0x54f3bf68 sp=0x54f3bf54 pc=0x80bfada runtime.goparkunlock(...) runtime/proc.go:441 runtime.(*scavengerState).sleep(0x8c30900, 0x40f873e000000000) runtime/mgcscavenge.go:504 +0x149 fp=0x54f3bfcc sp=0x54f3bf68 pc=0x8074649 runtime.bgscavenge(0x54c24040) runtime/mgcscavenge.go:662 +0xa0 fp=0x54f3bfe8 sp=0x54f3bfcc pc=0x8074ad0 runtime.gcenable.gowrap2() runtime/mgc.go:205 +0x21 fp=0x54f3bff0 sp=0x54f3bfe8 pc=0x80685a1 runtime.goexit({}) runtime/asm_386.s:1393 +0x1 fp=0x54f3bff4 sp=0x54f3bff0 pc=0x80c5921 created by runtime.gcenable in goroutine 1 runtime/mgc.go:205 +0xb1 goroutine 5 gp=0x54c08c68 m=nil [finalizer wait]: runtime.gopark(0x87bb214, 0x8c3e470, 0x10, 0xa, 0x1) runtime/proc.go:435 +0xfa fp=0x54c3ff98 sp=0x54c3ff84 pc=0x80bfada runtime.runfinq() runtime/mfinal.go:196 +0xed fp=0x54c3fff0 sp=0x54c3ff98 pc=0x806768d runtime.goexit({}) runtime/asm_386.s:1393 +0x1 fp=0x54c3fff4 sp=0x54c3fff0 pc=0x80c5921 created by runtime.createfing in goroutine 1 runtime/mfinal.go:166 +0x5a goroutine 6 gp=0x54c08fc8 m=nil [chan receive]: runtime.gopark(0x87bb1f4, 0x54c24274, 0xe, 0x7, 0x2) runtime/proc.go:435 +0xfa fp=0x54f38f8c sp=0x54f38f78 pc=0x80bfada runtime.chanrecv(0x54c24240, 0x0, 0x1) runtime/chan.go:664 +0x41a fp=0x54f38fcc sp=0x54f38f8c pc=0x8059fea runtime.chanrecv1(0x54c24240, 0x0) runtime/chan.go:506 +0x1c fp=0x54f38fe0 sp=0x54f38fcc pc=0x8059b9c runtime.unique_runtime_registerUniqueMapCleanup.func2(...) runtime/mgc.go:1805 runtime.unique_runtime_registerUniqueMapCleanup.gowrap1() runtime/mgc.go:1808 +0x34 fp=0x54f38ff0 sp=0x54f38fe0 pc=0x806bed4 runtime.goexit({}) runtime/asm_386.s:1393 +0x1 fp=0x54f38ff4 sp=0x54f38ff0 pc=0x80c5921 created by unique.runtime_registerUniqueMapCleanup in goroutine 1 runtime/mgc.go:1803 +0x66 goroutine 8 gp=0x54c09208 m=0 mp=0x8c32400 [syscall]: syscall.syscall6(0x80dff40, 0x165dc, 0x54ccfa7c, 0x0, 0x54c90370, 0x0, 0x0) runtime/sys_openbsd3.go:54 +0x20 fp=0x54ccfa28 sp=0x54ccfa18 pc=0x80c2f50 syscall.wait4(0x165dc, 0x54ccfa7c, 0x0, 0x54c90370) syscall/zsyscall_openbsd_386.go:43 +0x5d fp=0x54ccfa60 sp=0x54ccfa28 pc=0x80dcc4d syscall.Wait4(0x165dc, 0x54ccfaa0, 0x0, 0x54c90370) syscall/syscall_bsd.go:144 +0x3b fp=0x54ccfa84 sp=0x54ccfa60 pc=0x80da32b os.(*Process).pidWait.func1(...) os/exec_unix.go:64 os.ignoringEINTR2[...](...) os/file_posix.go:261 os.(*Process).pidWait(0x54efb500) os/exec_unix.go:63 +0x9e fp=0x54ccfab8 sp=0x54ccfa84 pc=0x814284e os.(*Process).wait(0x54efb500) os/exec_unix.go:28 +0x22 fp=0x54ccfacc sp=0x54ccfab8 pc=0x8142772 os.(*Process).Wait(...) os/exec.go:340 os/exec.(*Cmd).Wait(0x54f09458) os/exec/exec.go:922 +0x36 fp=0x54ccfb04 sp=0x54ccfacc pc=0x817bfc6 os/exec.(*Cmd).Run(0x54f09458) os/exec/exec.go:626 +0x3f fp=0x54ccfb14 sp=0x54ccfb04 pc=0x817adbf cmd/go/internal/work.(*Shell).runOut(0x55048600, {0x887b36c, 0x1}, {0x55048ab0, 0x1, 0x1}, {0x54ccfd6c, 0x8, 0x8}) cmd/go/internal/work/shell.go:650 +0x703 fp=0x54ccfc20 sp=0x54ccfb14 pc=0x856e5f3 cmd/go/internal/work.(*Shell).run(0x55048600, {0x887b36c, 0x1}, {0x876bb4d, 0x16}, {0x55048ab0, 0x1, 0x1}, {0x54ccfd6c, 0x8, ...}) cmd/go/internal/work/shell.go:577 +0x62 fp=0x54ccfc78 sp=0x54ccfc20 pc=0x856dd62 cmd/go/internal/work.gcToolchain.ld({}, 0x54c744b0, 0x54ca9e18, {0x54e46600, 0x3c}, {0x550c2540, 0x37}, {0x54d7fd70, 0x30}) cmd/go/internal/work/gc.go:683 +0x125f fp=0x54ccfdcc sp=0x54ccfc78 pc=0x855f0ff cmd/go/internal/work.(*gcToolchain).ld(0x8c3e380, 0x54c744b0, 0x54ca9e18, {0x54e46600, 0x3c}, {0x550c2540, 0x37}, {0x54d7fd70, 0x30}) :1 +0x62 fp=0x54ccfdf8 sp=0x54ccfdcc pc=0x8570b02 cmd/go/internal/work.(*Builder).link(0x54c744b0, {0x88821e0, 0x8c3e380}, 0x54ca9e18) cmd/go/internal/work/exec.go:1469 +0x353 fp=0x54ccfe7c sp=0x54ccfdf8 pc=0x8545fe3 cmd/go/internal/work.ActorFunc.Act(0x87bb0b0, 0x54c744b0, {0x88821e0, 0x8c3e380}, 0x54ca9e18) cmd/go/internal/work/action.go:76 +0x36 fp=0x54ccfe98 sp=0x54ccfe7c pc=0x85289a6 cmd/go/internal/work.(*Builder).Do.func3({0x88821e0, 0x8c3e380}, 0x54ca9e18) cmd/go/internal/work/exec.go:153 +0x909 fp=0x54ccff84 sp=0x54ccfe98 pc=0x85393e9 cmd/go/internal/work.(*Builder).Do.func4() cmd/go/internal/work/exec.go:225 +0xaf fp=0x54ccfff0 sp=0x54ccff84 pc=0x853897f runtime.goexit({}) runtime/asm_386.s:1393 +0x1 fp=0x54ccfff4 sp=0x54ccfff0 pc=0x80c5921 created by cmd/go/internal/work.(*Builder).Do in goroutine 1 cmd/go/internal/work/exec.go:211 +0x37a goroutine 13 gp=0x54ed39e8 m=nil [GC worker (idle)]: runtime.gopark(0x87bb220, 0x54f7a228, 0x1b, 0xa, 0x0) runtime/proc.go:435 +0xfa fp=0x54f3af8c sp=0x54f3af78 pc=0x80bfada runtime.gcBgMarkWorker(0x54e47040) runtime/mgc.go:1432 +0xeb fp=0x54f3afe8 sp=0x54f3af8c pc=0x806b06b runtime.gcBgMarkStartWorkers.gowrap1() runtime/mgc.go:1348 +0x21 fp=0x54f3aff0 sp=0x54f3afe8 pc=0x806af61 runtime.goexit({}) runtime/asm_386.s:1393 +0x1 fp=0x54f3aff4 sp=0x54f3aff0 pc=0x80c5921 created by runtime.gcBgMarkStartWorkers in goroutine 8 runtime/mgc.go:1348 +0x114 goroutine 17 gp=0x54ed3b08 m=nil [IO wait]: runtime.gopark(0x87bb358, 0x317fd0c0, 0x2, 0x2, 0x5) runtime/proc.go:435 +0xfa fp=0x54f39da8 sp=0x54f39d94 pc=0x80bfada runtime.netpollblock(0x317fd0b0, 0x72, 0x0) runtime/netpoll.go:575 +0xe4 fp=0x54f39dc0 sp=0x54f39da8 pc=0x8084de4 internal/poll.runtime_pollWait(0x317fd0b0, 0x72) runtime/netpoll.go:351 +0x4c fp=0x54f39dd4 sp=0x54f39dc0 pc=0x80bedfc internal/poll.(*pollDesc).wait(0x54da8568, 0x72, 0x1) internal/poll/fd_poll_runtime.go:84 +0x31 fp=0x54f39de8 sp=0x54f39dd4 pc=0x8139c61 internal/poll.(*pollDesc).waitRead(...) internal/poll/fd_poll_runtime.go:89 internal/poll.(*FD).Read(0x54da8550, {0x54cac200, 0x200, 0x200}) internal/poll/fd_unix.go:165 +0x1f6 fp=0x54f39e30 sp=0x54f39de8 pc=0x813aae6 os.(*File).read(...) os/file_posix.go:29 os.(*File).Read(0x550494e8, {0x54cac200, 0x200, 0x200}) os/file.go:124 +0x6a fp=0x54f39e54 sp=0x54f39e30 pc=0x814343a bytes.(*Buffer).ReadFrom(0x54ef49f0, {0x887f020, 0x55049530}) bytes/buffer.go:211 +0x8f fp=0x54f39e90 sp=0x54f39e54 pc=0x8175b0f io.copyBuffer({0x887f130, 0x54ef49f0}, {0x887f020, 0x55049530}, {0x0, 0x0, 0x0}) io/io.go:415 +0x146 fp=0x54f39edc sp=0x54f39e90 pc=0x8132626 io.Copy(...) io/io.go:388 os.genericWriteTo(0x550494e8, {0x887f130, 0x54ef49f0}) os/file.go:275 +0x6f fp=0x54f39f10 sp=0x54f39edc pc=0x8143cdf os.(*File).WriteTo(0x550494e8, {0x887f130, 0x54ef49f0}) os/file.go:253 +0x61 fp=0x54f39f30 sp=0x54f39f10 pc=0x8143c11 io.copyBuffer({0x887f130, 0x54ef49f0}, {0x887efa0, 0x550494e8}, {0x0, 0x0, 0x0}) io/io.go:411 +0x186 fp=0x54f39f7c sp=0x54f39f30 pc=0x8132666 io.Copy(...) io/io.go:388 os/exec.(*Cmd).writerDescriptor.func1() os/exec/exec.go:596 +0x4f fp=0x54f39fb8 sp=0x54f39f7c pc=0x817ad3f os/exec.(*Cmd).Start.func2(0x54f0c3d0) os/exec/exec.go:749 +0x2b fp=0x54f39fe8 sp=0x54f39fb8 pc=0x817b85b os/exec.(*Cmd).Start.gowrap1() os/exec/exec.go:761 +0x23 fp=0x54f39ff0 sp=0x54f39fe8 pc=0x817b813 runtime.goexit({}) runtime/asm_386.s:1393 +0x1 fp=0x54f39ff4 sp=0x54f39ff0 pc=0x80c5921 created by os/exec.(*Cmd).Start in goroutine 8 os/exec/exec.go:748 +0x8b6 eax 0x4 ebx 0x40 ecx 0x180d03b8 edx 0x180d0390 edi 0x79c esi 0x54c08b48 ebp 0x180d0338 esp 0x180d031c eip 0x2966dc2f eflags 0x203 cs 0x2b fs 0x5b gs 0x63 trace_test.go:615: exit status 2 --- FAIL: TestTraceWaitOnPipe (0.00s) --- FAIL: TestTraceWaitOnPipe/Default (0.00s) trace_test.go:615: context deadline exceeded --- FAIL: TestTraceIterPull (0.00s) --- FAIL: TestTraceIterPull/Default (0.00s) trace_test.go:615: context deadline exceeded panic: test timed out after 3m0s running tests: TestTraceV1 (0s) TestTraceV1/stress_1_11_good (0s) goroutine 136 gp=0x6feee488 m=2 mp=0x6fc3c808 [running]: panic({0x824eb80, 0x6fc22278}) /tmp/workdir/go/src/runtime/panic.go:818 +0x138 fp=0x6fc4bf84 sp=0x6fc4bf30 pc=0x80bc728 testing.(*M).startAlarm.func1() /tmp/workdir/go/src/testing/testing.go:2490 +0x37c fp=0x6fc4bff0 sp=0x6fc4bf84 pc=0x81497fc runtime.goexit({}) /tmp/workdir/go/src/runtime/asm_386.s:1393 +0x1 fp=0x6fc4bff4 sp=0x6fc4bff0 pc=0x80c2471 created by time.goFunc /tmp/workdir/go/src/time/sleep.go:215 +0x29 goroutine 1 gp=0x6fc06128 m=nil [chan receive, 1 minutes]: runtime.gopark(0x829bce8, 0x6fc1eff4, 0xe, 0x7, 0x2) /tmp/workdir/go/src/runtime/proc.go:435 +0xfa fp=0x6fc4ac34 sp=0x6fc4ac20 pc=0x80bcb6a runtime.chanrecv(0x6fc1efc0, 0x6fc4acaf, 0x1) /tmp/workdir/go/src/runtime/chan.go:664 +0x41a fp=0x6fc4ac74 sp=0x6fc4ac34 pc=0x80556da runtime.chanrecv1(0x6fc1efc0, 0x6fc4acaf) /tmp/workdir/go/src/runtime/chan.go:506 +0x1c fp=0x6fc4ac88 sp=0x6fc4ac74 pc=0x805528c testing.(*T).Run(0x6fc06d88, {0x828710e, 0xb}, 0x829bb4c) /tmp/workdir/go/src/testing/testing.go:1865 +0x481 fp=0x6fc4ad10 sp=0x6fc4ac88 pc=0x8146241 testing.runTests.func1(0x6fc06d88) /tmp/workdir/go/src/testing/testing.go:2285 +0x3f fp=0x6fc4ad30 sp=0x6fc4ad10 pc=0x814840f testing.tRunner(0x6fc06d88, 0x6fc4adf4) /tmp/workdir/go/src/testing/testing.go:1798 +0x10e fp=0x6fc4ad90 sp=0x6fc4ad30 pc=0x814528e testing.runTests(0x6fc10080, {0x841a100, 0x1a, 0x1a}, {0xc1e3f82bc5386aa1, 0x29e8eec569, 0x8422040}) /tmp/workdir/go/src/testing/testing.go:2283 +0x3e4 fp=0x6fc4ae08 sp=0x6fc4ad90 pc=0x8148324 testing.(*M).Run(0x6fc64140) /tmp/workdir/go/src/testing/testing.go:2148 +0x634 fp=0x6fc4af54 sp=0x6fc4ae08 pc=0x8146cc4 main.main() _testmain.go:99 +0xdf fp=0x6fc4afac sp=0x6fc4af54 pc=0x822225f runtime.main() /tmp/workdir/go/src/runtime/proc.go:283 +0x288 fp=0x6fc4aff0 sp=0x6fc4afac pc=0x8088658 runtime.goexit({}) /tmp/workdir/go/src/runtime/asm_386.s:1393 +0x1 fp=0x6fc4aff4 sp=0x6fc4aff0 pc=0x80c2471 goroutine 2 gp=0x6fc06488 m=nil [force gc (idle), 3 minutes]: runtime.gopark(0x829be54, 0x8421cb8, 0x11, 0xa, 0x1) /tmp/workdir/go/src/runtime/proc.go:435 +0xfa fp=0x6fc387dc sp=0x6fc387c8 pc=0x80bcb6a runtime.goparkunlock(...) /tmp/workdir/go/src/runtime/proc.go:441 runtime.forcegchelper() /tmp/workdir/go/src/runtime/proc.go:348 +0xc7 fp=0x6fc387f0 sp=0x6fc387dc pc=0x80889b7 runtime.goexit({}) /tmp/workdir/go/src/runtime/asm_386.s:1393 +0x1 fp=0x6fc387f4 sp=0x6fc387f0 pc=0x80c2471 created by runtime.init.6 in goroutine 1 /tmp/workdir/go/src/runtime/proc.go:336 +0x1d goroutine 3 gp=0x6fc065a8 m=nil [runnable]: runtime.goschedIfBusy() /tmp/workdir/go/src/runtime/proc.go:387 +0x36 fp=0x6fc48fcc sp=0x6fc48fc0 pc=0x8088a66 runtime.bgsweep(0x6fc1e040) /tmp/workdir/go/src/runtime/mgcsweep.go:300 +0x141 fp=0x6fc48fe8 sp=0x6fc48fcc pc=0x8072351 runtime.gcenable.gowrap1() /tmp/workdir/go/src/runtime/mgc.go:204 +0x21 fp=0x6fc48ff0 sp=0x6fc48fe8 pc=0x8063b51 runtime.goexit({}) /tmp/workdir/go/src/runtime/asm_386.s:1393 +0x1 fp=0x6fc48ff4 sp=0x6fc48ff0 pc=0x80c2471 created by runtime.gcenable in goroutine 1 /tmp/workdir/go/src/runtime/mgc.go:204 +0x71 goroutine 4 gp=0x6fc066c8 m=nil [runnable]: runtime.gopark(0x829be54, 0x8422160, 0x13, 0xe, 0x2) /tmp/workdir/go/src/runtime/proc.go:435 +0xfa fp=0x6fc49f68 sp=0x6fc49f54 pc=0x80bcb6a runtime.goparkunlock(...) /tmp/workdir/go/src/runtime/proc.go:441 runtime.(*scavengerState).sleep(0x8422160, 0x412ea51600000000) /tmp/workdir/go/src/runtime/mgcscavenge.go:504 +0x149 fp=0x6fc49fcc sp=0x6fc49f68 pc=0x806fb59 runtime.bgscavenge(0x6fc1e040) /tmp/workdir/go/src/runtime/mgcscavenge.go:662 +0xa0 fp=0x6fc49fe8 sp=0x6fc49fcc pc=0x806ffe0 runtime.gcenable.gowrap2() /tmp/workdir/go/src/runtime/mgc.go:205 +0x21 fp=0x6fc49ff0 sp=0x6fc49fe8 pc=0x8063b11 runtime.goexit({}) /tmp/workdir/go/src/runtime/asm_386.s:1393 +0x1 fp=0x6fc49ff4 sp=0x6fc49ff0 pc=0x80c2471 created by runtime.gcenable in goroutine 1 /tmp/workdir/go/src/runtime/mgc.go:205 +0xb1 goroutine 5 gp=0x6fc06c68 m=nil [finalizer wait, 3 minutes]: runtime.gopark(0x829bd08, 0x842e5d0, 0x10, 0xa, 0x1) /tmp/workdir/go/src/runtime/proc.go:435 +0xfa fp=0x6fc39f98 sp=0x6fc39f84 pc=0x80bcb6a runtime.runfinq() /tmp/workdir/go/src/runtime/mfinal.go:196 +0xed fp=0x6fc39ff0 sp=0x6fc39f98 pc=0x8062bfd runtime.goexit({}) /tmp/workdir/go/src/runtime/asm_386.s:1393 +0x1 fp=0x6fc39ff4 sp=0x6fc39ff0 pc=0x80c2471 created by runtime.createfing in goroutine 1 /tmp/workdir/go/src/runtime/mfinal.go:166 +0x5a goroutine 12 gp=0x6fc06fc8 m=nil [chan receive, 3 minutes]: runtime.gopark(0x829bce8, 0x6fc1e1f4, 0xe, 0x7, 0x2) /tmp/workdir/go/src/runtime/proc.go:435 +0xfa fp=0x6fc46d34 sp=0x6fc46d20 pc=0x80bcb6a runtime.chanrecv(0x6fc1e1c0, 0x0, 0x1) /tmp/workdir/go/src/runtime/chan.go:664 +0x41a fp=0x6fc46d74 sp=0x6fc46d34 pc=0x80556da runtime.chanrecv1(0x6fc1e1c0, 0x0) /tmp/workdir/go/src/runtime/chan.go:506 +0x1c fp=0x6fc46d88 sp=0x6fc46d74 pc=0x805528c testing.(*T).Parallel(0x6fc070e8) /tmp/workdir/go/src/testing/testing.go:1579 +0x267 fp=0x6fc46e08 sp=0x6fc46d88 pc=0x8144f47 internal/trace_test.TestMMU(0x6fc070e8) /tmp/workdir/go/src/internal/trace/gc_test.go:28 +0x2c fp=0x6fc46f84 sp=0x6fc46e08 pc=0x821471c testing.tRunner(0x6fc070e8, 0x829bb00) /tmp/workdir/go/src/testing/testing.go:1798 +0x10e fp=0x6fc46fe4 sp=0x6fc46f84 pc=0x814528e testing.(*T).Run.gowrap1() /tmp/workdir/go/src/testing/testing.go:1857 +0x28 fp=0x6fc46ff0 sp=0x6fc46fe4 pc=0x8146388 runtime.goexit({}) /tmp/workdir/go/src/runtime/asm_386.s:1393 +0x1 fp=0x6fc46ff4 sp=0x6fc46ff0 pc=0x80c2471 created by testing.(*T).Run in goroutine 1 /tmp/workdir/go/src/testing/testing.go:1857 +0x462 goroutine 10 gp=0x6fc07688 m=nil [GC worker (idle)]: runtime.gopark(0x829bd18, 0x6fc18c48, 0x1b, 0xa, 0x0) /tmp/workdir/go/src/runtime/proc.go:435 +0xfa fp=0x6fc4df8c sp=0x6fc4df78 pc=0x80bcb6a runtime.gcBgMarkWorker(0x6fc1fd00) /tmp/workdir/go/src/runtime/mgc.go:1432 +0xeb fp=0x6fc4dfe8 sp=0x6fc4df8c pc=0x80665db runtime.gcBgMarkStartWorkers.gowrap1() /tmp/workdir/go/src/runtime/mgc.go:1348 +0x21 fp=0x6fc4dff0 sp=0x6fc4dfe8 pc=0x80664d1 runtime.goexit({}) /tmp/workdir/go/src/runtime/asm_386.s:1393 +0x1 fp=0x6fc4dff4 sp=0x6fc4dff0 pc=0x80c2471 created by runtime.gcBgMarkStartWorkers in goroutine 9 /tmp/workdir/go/src/runtime/mgc.go:1348 +0x114 goroutine 131 gp=0x6fc07328 m=nil [chan receive]: runtime.gopark(0x829bce8, 0x6fc1e5f4, 0xe, 0x7, 0x2) /tmp/workdir/go/src/runtime/proc.go:435 +0xfa fp=0x6fcb5e5c sp=0x6fcb5e48 pc=0x80bcb6a runtime.chanrecv(0x6fc1e5c0, 0x6fcb5ed7, 0x1) /tmp/workdir/go/src/runtime/chan.go:664 +0x41a fp=0x6fcb5e9c sp=0x6fcb5e5c pc=0x80556da runtime.chanrecv1(0x6fc1e5c0, 0x6fcb5ed7) /tmp/workdir/go/src/runtime/chan.go:506 +0x1c fp=0x6fcb5eb0 sp=0x6fcb5e9c pc=0x805528c testing.(*T).Run(0x6fca9688, {0x6fc1aa6a, 0x10}, 0x6fdb82d0) /tmp/workdir/go/src/testing/testing.go:1865 +0x481 fp=0x6fcb5f38 sp=0x6fcb5eb0 pc=0x8146241 internal/trace_test.TestTraceV1(0x6fca9688) /tmp/workdir/go/src/internal/trace/tracev1_test.go:28 +0xe5 fp=0x6fcb5f84 sp=0x6fcb5f38 pc=0x821c755 testing.tRunner(0x6fca9688, 0x829bb4c) /tmp/workdir/go/src/testing/testing.go:1798 +0x10e fp=0x6fcb5fe4 sp=0x6fcb5f84 pc=0x814528e testing.(*T).Run.gowrap1() /tmp/workdir/go/src/testing/testing.go:1857 +0x28 fp=0x6fcb5ff0 sp=0x6fcb5fe4 pc=0x8146388 runtime.goexit({}) /tmp/workdir/go/src/runtime/asm_386.s:1393 +0x1 fp=0x6fcb5ff4 sp=0x6fcb5ff0 pc=0x80c2471 created by testing.(*T).Run in goroutine 1 /tmp/workdir/go/src/testing/testing.go:1857 +0x462 goroutine 135 gp=0x6feef0e8 m=nil [runnable]: runtime.goschedguarded(...) /tmp/workdir/go/src/runtime/proc.go:372 runtime.memclrNoHeapPointersChunked(0x1e00000, 0x72580000) /tmp/workdir/go/src/runtime/malloc.go:1696 +0x5e fp=0x6fc91494 sp=0x6fc91480 pc=0x805cfae runtime.mallocgcLarge(0x1e00000, 0x824d100, 0x1) /tmp/workdir/go/src/runtime/malloc.go:1597 +0x20b fp=0x6fc914c8 sp=0x6fc91494 pc=0x805cc5b runtime.mallocgc(0x1e00000, 0x824d100, 0x1) /tmp/workdir/go/src/runtime/malloc.go:1060 +0x11e fp=0x6fc914e4 sp=0x6fc914c8 pc=0x80bb14e runtime.newobject(0x824d100) /tmp/workdir/go/src/runtime/malloc.go:1711 +0x26 fp=0x6fc914f8 sp=0x6fc914e4 pc=0x805d006 internal/trace/internal/tracev1.(*Events).grow(...) /tmp/workdir/go/src/internal/trace/internal/tracev1/parser.go:292 internal/trace/internal/tracev1.(*Events).append(...) /tmp/workdir/go/src/internal/trace/internal/tracev1/parser.go:301 internal/trace/internal/tracev1.(*parser).parseEventBatches(0x6fc7fc00) /tmp/workdir/go/src/internal/trace/internal/tracev1/parser.go:483 +0x50a fp=0x6fc91868 sp=0x6fc914f8 pc=0x81d356a internal/trace/internal/tracev1.(*parser).parse(0x6fc7fc00) /tmp/workdir/go/src/internal/trace/internal/tracev1/parser.go:211 +0x1d0 fp=0x6fc9190c sp=0x6fc91868 pc=0x81d2ab0 internal/trace/internal/tracev1.Parse({0x82dc260, 0x6fde0060}, 0xb) /tmp/workdir/go/src/internal/trace/internal/tracev1/parser.go:175 +0x96 fp=0x6fc91988 sp=0x6fc9190c pc=0x81d2886 internal/trace.NewReader({0x82dc220, 0x6fc224c0}) /tmp/workdir/go/src/internal/trace/reader.go:49 +0x19e fp=0x6fc91a60 sp=0x6fc91988 pc=0x81f432e internal/trace_test.TestTraceV1.func1(0x6fdf4008) /tmp/workdir/go/src/internal/trace/tracev1_test.go:35 +0x193 fp=0x6fc91f84 sp=0x6fc91a60 pc=0x821ca53 testing.tRunner(0x6fdf4008, 0x6fdb82d0) /tmp/workdir/go/src/testing/testing.go:1798 +0x10e fp=0x6fc91fe4 sp=0x6fc91f84 pc=0x814528e testing.(*T).Run.gowrap1() /tmp/workdir/go/src/testing/testing.go:1857 +0x28 fp=0x6fc91ff0 sp=0x6fc91fe4 pc=0x8146388 runtime.goexit({}) /tmp/workdir/go/src/runtime/asm_386.s:1393 +0x1 fp=0x6fc91ff4 sp=0x6fc91ff0 pc=0x80c2471 created by testing.(*T).Run in goroutine 131 /tmp/workdir/go/src/testing/testing.go:1857 +0x462 FAIL internal/trace 180.165s ? internal/trace/internal/testgen [no test files] FAIL go tool dist: Failed: exit status 1