Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

runtime/pprof: TestStackBarrierProfiling hangs #15477

Closed
alexbrainman opened this issue Apr 28, 2016 · 11 comments
Closed

runtime/pprof: TestStackBarrierProfiling hangs #15477

alexbrainman opened this issue Apr 28, 2016 · 11 comments
Milestone

Comments

@alexbrainman
Copy link
Member

Please answer these questions before submitting your issue. Thanks!

  1. What version of Go are you using (go version)?
go version devel +80e9a7f Thu Apr 28 05:26:36 2016 +0000 linux/386
  1. What operating system and processor architecture are you using (go env)?
GOARCH="386"
GOBIN=""
GOEXE=""
GOHOSTARCH="386"
GOHOSTOS="linux"
GOOS="linux"
GOPATH="/root"
GORACE=""
GOROOT="/root/go"
GOTOOLDIR="/root/go/pkg/tool/linux_386"
CC="gcc"
GOGCCFLAGS="-fPIC -m32 -pthread -fmessage-length=0 -fdebug-prefix-map=/tmp/go-build695579586=/tmp/go-build"
CXX="g++"
CGO_ENABLED="1"
  1. What did you do?
    If possible, provide a recipe for reproducing the error.
    A complete runnable program is good.
    A link on play.golang.org is best.

I run:

go test runtime/pprof -v -short -run=TestStackBarrierProfiling -timeout=1m
  1. What did you expect to see?

I expect test pass.

  1. What did you see instead?
=== RUN   TestStackBarrierProfiling
panic: test timed out after 1m0s

goroutine 8 [running]:
panic(0x813de00, 0x184262d0)
        /root/go/src/runtime/panic.go:500 +0x331
testing.startAlarm.func1()
        /root/go/src/testing/testing.go:855 +0xf5
created by time.goFunc
        /root/go/src/time/sleep.go:129 +0x36

goroutine 1 [chan receive]:
testing.(*T).Run(0x18418280, 0x8160c86, 0x19, 0x816f7b0, 0x1)
        /root/go/src/testing/testing.go:584 +0x2c4
testing.RunTests.func1(0x18418200)
        /root/go/src/testing/testing.go:730 +0x98
testing.tRunner(0x18418200, 0x18439ed8)
        /root/go/src/testing/testing.go:547 +0x8c
testing.RunTests(0x816f50c, 0x81d9da0, 0x9, 0x9, 0x18462001)
        /root/go/src/testing/testing.go:736 +0x332
testing.(*M).Run(0x18439f7c, 0x0)
        /root/go/src/testing/testing.go:680 +0x79
main.main()
        runtime/pprof/_test/_testmain.go:72 +0x100

goroutine 6 [syscall]:
syscall.Syscall6(0x72, 0x76c1, 0x184245cc, 0x0, 0x18478000, 0x0, 0x0, 0x80772bf, 0xb76df000, 0x0)
        /root/go/src/syscall/asm_linux_386.s:45 +0x5
syscall.wait4(0x76c1, 0x184245cc, 0x0, 0x18478000, 0x50, 0x0, 0x0)
        /root/go/src/syscall/zsyscall_linux_386.go:172 +0x71
syscall.Wait4(0x76c1, 0x184245f0, 0x0, 0x18478000, 0x184262b0, 0x0, 0x0)
        /root/go/src/syscall/syscall_linux.go:256 +0x4d
os.(*Process).wait(0x184103a0, 0x1f, 0x0, 0x0)
        /root/go/src/os/exec_unix.go:22 +0xae
os.(*Process).Wait(0x184103a0, 0x0, 0x0, 0x0)
        /root/go/src/os/doc.go:49 +0x2b
os/exec.(*Cmd).Wait(0x1840e140, 0x0, 0x0)
        /root/go/src/os/exec/exec.go:396 +0x11c
os/exec.(*Cmd).Run(0x1840e140, 0x0, 0x0)
        /root/go/src/os/exec/exec.go:262 +0x58
os/exec.(*Cmd).CombinedOutput(0x1840e140, 0x0, 0x0, 0x0, 0x0, 0x0)
        /root/go/src/os/exec/exec.go:453 +0x1a7
runtime/pprof_test.TestStackBarrierProfiling(0x18418280)
        /root/go/src/runtime/pprof/pprof_test.go:392 +0x2b6
testing.tRunner(0x18418280, 0x816f7b0)
        /root/go/src/testing/testing.go:547 +0x8c
created by testing.(*T).Run
        /root/go/src/testing/testing.go:583 +0x2a5

goroutine 7 [syscall]:
syscall.Syscall(0x3, 0x4, 0x1847a000, 0x200, 0xb76df000, 0x0, 0x1)
        /root/go/src/syscall/asm_linux_386.s:20 +0x5
syscall.read(0x4, 0x1847a000, 0x200, 0x200, 0x816f4fc, 0x0, 0x0)
        /root/go/src/syscall/zsyscall_linux_386.go:783 +0x5b
syscall.Read(0x4, 0x1847a000, 0x200, 0x200, 0x0, 0x0, 0x0)
        /root/go/src/syscall/syscall_unix.go:161 +0x45
os.(*File).read(0x184262a8, 0x1847a000, 0x200, 0x200, 0x1847a000, 0x0, 0x0)
        /root/go/src/os/file_unix.go:228 +0x4a
os.(*File).Read(0x184262a8, 0x1847a000, 0x200, 0x200, 0x11de5298, 0x0, 0x0)
        /root/go/src/os/file.go:97 +0x6f
bytes.(*Buffer).ReadFrom(0x18462180, 0x81c9770, 0x184262a8, 0x0, 0x0, 0x0, 0x0)
        /root/go/src/bytes/buffer.go:176 +0x1c5
io.copyBuffer(0x81c96f0, 0x18462180, 0x81c9770, 0x184262a8, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, ...)
        /root/go/src/io/io.go:392 +0x129
io.Copy(0x81c96f0, 0x18462180, 0x81c9770, 0x184262a8, 0x0, 0x0, 0x0, 0x0)
        /root/go/src/io/io.go:368 +0x53
os/exec.(*Cmd).writerDescriptor.func1(0x0, 0x0)
        /root/go/src/os/exec/exec.go:236 +0x57
os/exec.(*Cmd).Start.func1(0x1840e140, 0x18410260)
        /root/go/src/os/exec/exec.go:344 +0x1d
created by os/exec.(*Cmd).Start
        /root/go/src/os/exec/exec.go:345 +0x698
exit status 2
FAIL    runtime/pprof   60.005s

The test fails on my windows-amd64 too.

Alex

@ianlancetaylor ianlancetaylor added this to the Go1.7 milestone Apr 28, 2016
@ianlancetaylor
Copy link
Contributor

CC @aclements

@aclements
Copy link
Member

@alexbrainman, can you re-run with GOTRACEBACK=crash?

@alexbrainman
Copy link
Member Author

re-run with GOTRACEBACK=crash?

=== RUN   TestStackBarrierProfiling
panic: test timed out after 1m0s

goroutine 8 [running]:
panic(0x813de00, 0x184262d0)
    /root/go/src/runtime/panic.go:500 +0x331 fp=0x184257a0 sp=0x1842575c
testing.startAlarm.func1()
    /root/go/src/testing/testing.go:855 +0xf5 fp=0x184257e0 sp=0x184257a0
runtime.goexit()
    /root/go/src/runtime/asm_386.s:1601 +0x1 fp=0x184257e4 sp=0x184257e0
created by time.goFunc
    /root/go/src/time/sleep.go:129 +0x36

goroutine 1 [chan receive]:
runtime.gopark(0x816f6d8, 0x184422b0, 0x815e3ca, 0xc, 0x81d7d17, 0x3)
    /root/go/src/runtime/proc.go:264 +0x130 fp=0x18439d08 sp=0x18439cf4
runtime.goparkunlock(0x184422b0, 0x815e3ca, 0xc, 0x809cf17, 0x3)
    /root/go/src/runtime/proc.go:270 +0x4b fp=0x18439d24 sp=0x18439d08
runtime.chanrecv(0x813cc80, 0x18442280, 0x0, 0x18439d01, 0x80a0000)
    /root/go/src/runtime/chan.go:496 +0x3e8 fp=0x18439d6c sp=0x18439d24
runtime.chanrecv1(0x813cc80, 0x18442280, 0x0)
    /root/go/src/runtime/chan.go:378 +0x24 fp=0x18439d84 sp=0x18439d6c
testing.(*T).Run(0x18418280, 0x8160c86, 0x19, 0x816f7b0, 0x1)
    /root/go/src/testing/testing.go:584 +0x2c4 fp=0x18439dec sp=0x18439d84
testing.RunTests.func1(0x18418200)
    /root/go/src/testing/testing.go:730 +0x98 fp=0x18439e34 sp=0x18439dec
testing.tRunner(0x18418200, 0x18439ed8)
    /root/go/src/testing/testing.go:547 +0x8c fp=0x18439e58 sp=0x18439e34
testing.RunTests(0x816f50c, 0x81d9da0, 0x9, 0x9, 0x18462001)
    /root/go/src/testing/testing.go:736 +0x332 fp=0x18439eec sp=0x18439e58
testing.(*M).Run(0x18439f7c, 0x0)
    /root/go/src/testing/testing.go:680 +0x79 fp=0x18439f2c sp=0x18439eec
main.main()
    runtime/pprof/_test/_testmain.go:72 +0x100 fp=0x18439fa8 sp=0x18439f2c
runtime.main()
    /root/go/src/runtime/proc.go:188 +0x276 fp=0x18439fd0 sp=0x18439fa8
runtime.goexit()
    /root/go/src/runtime/asm_386.s:1601 +0x1 fp=0x18439fd4 sp=0x18439fd0

goroutine 2 [force gc (idle)]:
runtime.gopark(0x816f6d8, 0x81dae88, 0x815ebae, 0xf, 0x14adb14, 0x1)
    /root/go/src/runtime/proc.go:264 +0x130 fp=0x184227ac sp=0x18422798
runtime.goparkunlock(0x81dae88, 0x815ebae, 0xf, 0x18400014, 0x1)
    /root/go/src/runtime/proc.go:270 +0x4b fp=0x184227c8 sp=0x184227ac
runtime.forcegchelper()
    /root/go/src/runtime/proc.go:229 +0xaa fp=0x184227e0 sp=0x184227c8
runtime.goexit()
    /root/go/src/runtime/asm_386.s:1601 +0x1 fp=0x184227e4 sp=0x184227e0
created by runtime.init.4
    /root/go/src/runtime/proc.go:218 +0x2a

goroutine 3 [GC sweep wait]:
runtime.gopark(0x816f6d8, 0x81daf60, 0x815e607, 0xd, 0x8062f14, 0x1)
    /root/go/src/runtime/proc.go:264 +0x130 fp=0x18422fa0 sp=0x18422f8c
runtime.goparkunlock(0x81daf60, 0x815e607, 0xd, 0x14, 0x1)
    /root/go/src/runtime/proc.go:270 +0x4b fp=0x18422fbc sp=0x18422fa0
runtime.bgsweep(0x18442000)
    /root/go/src/runtime/mgcsweep.go:63 +0xa0 fp=0x18422fd8 sp=0x18422fbc
runtime.goexit()
    /root/go/src/runtime/asm_386.s:1601 +0x1 fp=0x18422fdc sp=0x18422fd8
created by runtime.gcenable
    /root/go/src/runtime/mgc.go:195 +0x52

goroutine 4 [finalizer wait]:
runtime.gopark(0x816f6d8, 0x81eb258, 0x815e8df, 0xe, 0x14, 0x1)
    /root/go/src/runtime/proc.go:264 +0x130 fp=0x1842378c sp=0x18423778
runtime.goparkunlock(0x81eb258, 0x815e8df, 0xe, 0x14, 0x1)
    /root/go/src/runtime/proc.go:270 +0x4b fp=0x184237a8 sp=0x1842378c
runtime.runfinq()
    /root/go/src/runtime/mfinal.go:158 +0x9e fp=0x184237e0 sp=0x184237a8
runtime.goexit()
    /root/go/src/runtime/asm_386.s:1601 +0x1 fp=0x184237e4 sp=0x184237e0
created by runtime.createfing
    /root/go/src/runtime/mfinal.go:139 +0x5c

goroutine 5 [timer goroutine (idle)]:
runtime.gopark(0x816f6d8, 0x81db000, 0x81605ad, 0x16, 0x816f814, 0x1)
    /root/go/src/runtime/proc.go:264 +0x130 fp=0x18423f70 sp=0x18423f5c
runtime.goparkunlock(0x81db000, 0x81605ad, 0x16, 0x14, 0x1)
    /root/go/src/runtime/proc.go:270 +0x4b fp=0x18423f8c sp=0x18423f70
runtime.timerproc()
    /root/go/src/runtime/time.go:202 +0x123 fp=0x18423fe0 sp=0x18423f8c
runtime.goexit()
    /root/go/src/runtime/asm_386.s:1601 +0x1 fp=0x18423fe4 sp=0x18423fe0
created by runtime.addtimerLocked
    /root/go/src/runtime/time.go:116 +0x112

goroutine 6 [syscall]:
syscall.Syscall6(0x72, 0x1217, 0x184245cc, 0x0, 0x18478000, 0x0, 0x0, 0x80772bf, 0xb76fd000, 0x0)
    /root/go/src/syscall/asm_linux_386.s:45 +0x5 fp=0x18424570 sp=0x1842456c
syscall.wait4(0x1217, 0x184245cc, 0x0, 0x18478000, 0x50, 0x0, 0x0)
    /root/go/src/syscall/zsyscall_linux_386.go:172 +0x71 fp=0x184245b0 sp=0x18424570
syscall.Wait4(0x1217, 0x184245f0, 0x0, 0x18478000, 0x184262b0, 0x0, 0x0)
    /root/go/src/syscall/syscall_linux.go:256 +0x4d fp=0x184245d4 sp=0x184245b0
os.(*Process).wait(0x184103a0, 0x20, 0x0, 0x0)
    /root/go/src/os/exec_unix.go:22 +0xae fp=0x1842462c sp=0x184245d4
os.(*Process).Wait(0x184103a0, 0x0, 0x0, 0x0)
    /root/go/src/os/doc.go:49 +0x2b fp=0x18424640 sp=0x1842462c
os/exec.(*Cmd).Wait(0x1840e140, 0x0, 0x0)
    /root/go/src/os/exec/exec.go:396 +0x11c fp=0x184246a8 sp=0x18424640
os/exec.(*Cmd).Run(0x1840e140, 0x0, 0x0)
    /root/go/src/os/exec/exec.go:262 +0x58 fp=0x184246c0 sp=0x184246a8
os/exec.(*Cmd).CombinedOutput(0x1840e140, 0x0, 0x0, 0x0, 0x0, 0x0)
    /root/go/src/os/exec/exec.go:453 +0x1a7 fp=0x18424708 sp=0x184246c0
runtime/pprof_test.TestStackBarrierProfiling(0x18418280)
    /root/go/src/runtime/pprof/pprof_test.go:392 +0x2b6 fp=0x184247b4 sp=0x18424708
testing.tRunner(0x18418280, 0x816f7b0)
    /root/go/src/testing/testing.go:547 +0x8c fp=0x184247d8 sp=0x184247b4
runtime.goexit()
    /root/go/src/runtime/asm_386.s:1601 +0x1 fp=0x184247dc sp=0x184247d8
created by testing.(*T).Run
    /root/go/src/testing/testing.go:583 +0x2a5

goroutine 7 [syscall]:
syscall.Syscall(0x3, 0x4, 0x1847a000, 0x200, 0xb76fd000, 0x0, 0x1)
    /root/go/src/syscall/asm_linux_386.s:20 +0x5 fp=0x18424dfc sp=0x18424df8
syscall.read(0x4, 0x1847a000, 0x200, 0x200, 0x816f4fc, 0x0, 0x0)
    /root/go/src/syscall/zsyscall_linux_386.go:783 +0x5b fp=0x18424e28 sp=0x18424dfc
syscall.Read(0x4, 0x1847a000, 0x200, 0x200, 0x0, 0x0, 0x0)
    /root/go/src/syscall/syscall_unix.go:161 +0x45 fp=0x18424e48 sp=0x18424e28
os.(*File).read(0x184262a8, 0x1847a000, 0x200, 0x200, 0x1847a000, 0x0, 0x0)
    /root/go/src/os/file_unix.go:228 +0x4a fp=0x18424e68 sp=0x18424e48
os.(*File).Read(0x184262a8, 0x1847a000, 0x200, 0x200, 0x11de5298, 0x0, 0x0)
    /root/go/src/os/file.go:97 +0x6f fp=0x18424e94 sp=0x18424e68
bytes.(*Buffer).ReadFrom(0x18462180, 0x81c9770, 0x184262a8, 0x0, 0x0, 0x0, 0x0)
    /root/go/src/bytes/buffer.go:176 +0x1c5 fp=0x18424eec sp=0x18424e94
io.copyBuffer(0x81c96f0, 0x18462180, 0x81c9770, 0x184262a8, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, ...)
    /root/go/src/io/io.go:392 +0x129 fp=0x18424f50 sp=0x18424eec
io.Copy(0x81c96f0, 0x18462180, 0x81c9770, 0x184262a8, 0x0, 0x0, 0x0, 0x0)
    /root/go/src/io/io.go:368 +0x53 fp=0x18424f80 sp=0x18424f50
os/exec.(*Cmd).writerDescriptor.func1(0x0, 0x0)
    /root/go/src/os/exec/exec.go:236 +0x57 fp=0x18424fc0 sp=0x18424f80
os/exec.(*Cmd).Start.func1(0x1840e140, 0x18410260)
    /root/go/src/os/exec/exec.go:344 +0x1d fp=0x18424fd8 sp=0x18424fc0
runtime.goexit()
    /root/go/src/runtime/asm_386.s:1601 +0x1 fp=0x18424fdc sp=0x18424fd8
created by os/exec.(*Cmd).Start
    /root/go/src/os/exec/exec.go:345 +0x698
signal: aborted
FAIL    runtime/pprof   60.007s

Alex

@aclements
Copy link
Member

@alexbrainman, are you (or were you) able to reproduce this reliably? How many CPUs does the host have?

I haven't been able to reproduce this on a linux/amd64 host with GOARCH=386, or on the linux-386 gomote. If you can still reproduce this easily, could you run GODEBUG=gcstackbarrierall=1 GOGC=1 ./pprof.test -test.v -test.short -test.run=TestStackBarrierProfiling -test.timeout=1m?

@aclements
Copy link
Member

Actually, GODEBUG=gcstackbarrierall=1 GOGC=1 GOTRACEBACK=crash ./pprof.test -test.v -test.short -test.run=TestStackBarrierProfiling -test.timeout=1m

@gopherbot
Copy link

CL https://golang.org/cl/23134 mentions this issue.

gopherbot pushed a commit that referenced this issue May 16, 2016
This should help with debugging failures.

For #15138 and #15477.

Change-Id: I77db2b6375d8b4403d3edf5527899d076291e02c
Reviewed-on: https://go-review.googlesource.com/23134
Run-TryBot: Austin Clements <austin@google.com>
Reviewed-by: Brad Fitzpatrick <bradfitz@golang.org>
TryBot-Result: Gobot Gobot <gobot@golang.org>
Reviewed-by: Rick Hudson <rlh@golang.org>
@alexbrainman
Copy link
Member Author

are you (or were you) able to reproduce this reliably?

Yes. It fails nearly every time.

How many CPUs does the host have?

processor   : 0
vendor_id   : GenuineIntel
cpu family  : 6
model       : 26
model name  : Intel(R) Xeon(R) CPU           E5530  @ 2.40GHz
stepping    : 5
microcode   : 0x10
cpu MHz     : 2400.085
cache size  : 8192 KB
fdiv_bug    : no
hlt_bug     : no
f00f_bug    : no
coma_bug    : no
fpu     : yes
fpu_exception   : yes
cpuid level : 11
wp      : yes
flags       : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush dts acpi mmx fxsr sse sse2 ss nx rdtscp lm constant_tsc up arch_perfmon pebs bts xtopology tsc_reliable nonstop_tsc aperfmperf pni ssse3 cx16 sse4_1 sse4_2 popcnt hypervisor lahf_lm ida dts
bogomips    : 4800.17
clflush size    : 64
cache_alignment : 64
address sizes   : 40 bits physical, 48 bits virtual
power management:

Actually, GODEBUG=gcstackbarrierall=1 GOGC=1 GOTRACEBACK=crash ./pprof.test -test.v -test.short -test.run=TestStackBarrierProfiling -test.timeout=1m

If I use GODEBUG=gcstackbarrierall=1, the problem goes away. So running:

# go test -c && GOGC=1 GOTRACEBACK=crash ./pprof.test -test.v -test.short -test.run=TestStackBarrierProfiling -test.timeout=1m
panic: test timed out after 1m0s

goroutine 9 [running]:
panic(0x8142240, 0x185261d8)
    /root/go/src/runtime/panic.go:500 +0x331 fp=0x1851f7a0 sp=0x1851f75c
testing.startAlarm.func1()
    /root/go/src/testing/testing.go:855 +0xf5 fp=0x1851f7e0 sp=0x1851f7a0
runtime.goexit()
    /root/go/src/runtime/asm_386.s:1605 +0x1 fp=0x1851f7e4 sp=0x1851f7e0
created by time.goFunc
    /root/go/src/time/sleep.go:129 +0x36

goroutine 1 [chan receive, 1 minutes]:
runtime.gopark(0x8174460, 0x185421b0, 0x8162da0, 0xc, 0x18512017, 0x3)
    /root/go/src/runtime/proc.go:265 +0x130 fp=0x1853ed10 sp=0x1853ecfc
runtime.goparkunlock(0x185421b0, 0x8162da0, 0xc, 0x809f617, 0x3)
    /root/go/src/runtime/proc.go:271 +0x4b fp=0x1853ed2c sp=0x1853ed10
runtime.chanrecv(0x8141080, 0x18542180, 0x0, 0x1853ed01, 0x80a0000)
    /root/go/src/runtime/chan.go:496 +0x3e8 fp=0x1853ed74 sp=0x1853ed2c
runtime.chanrecv1(0x8141080, 0x18542180, 0x0)
    /root/go/src/runtime/chan.go:378 +0x24 fp=0x1853ed8c sp=0x1853ed74
testing.(*T).Run(0x18518200, 0x8165738, 0x19, 0x8174538, 0x8056401)
    /root/go/src/testing/testing.go:584 +0x2c4 fp=0x1853edf4 sp=0x1853ed8c
testing.RunTests.func1(0x18518100)
    /root/go/src/testing/testing.go:730 +0x98 fp=0x1853ee3c sp=0x1853edf4
testing.tRunner(0x18518100, 0x1853eee0)
    /root/go/src/testing/testing.go:547 +0x8c fp=0x1853ee60 sp=0x1853ee3c
testing.RunTests(0x817428c, 0x81dfee0, 0x9, 0x9, 0x1856c001)
    /root/go/src/testing/testing.go:736 +0x332 fp=0x1853eef4 sp=0x1853ee60
testing.(*M).Run(0x1853ef84, 0x0)
    /root/go/src/testing/testing.go:680 +0x79 fp=0x1853ef34 sp=0x1853eef4
main.main()
    runtime/pprof/_test/_testmain.go:72 +0x100 fp=0x1853efb0 sp=0x1853ef34
runtime.main()
    /root/go/src/runtime/proc.go:189 +0x276 fp=0x1853efd8 sp=0x1853efb0
runtime.goexit()
    /root/go/src/runtime/asm_386.s:1605 +0x1 fp=0x1853efdc sp=0x1853efd8

goroutine 2 [force gc (idle), 1 minutes]:
runtime.gopark(0x8174460, 0x81e0fe8, 0x816359b, 0xf, 0x1508814, 0x1)
    /root/go/src/runtime/proc.go:265 +0x130 fp=0x185227ac sp=0x18522798
runtime.goparkunlock(0x81e0fe8, 0x816359b, 0xf, 0x18500014, 0x1)
    /root/go/src/runtime/proc.go:271 +0x4b fp=0x185227c8 sp=0x185227ac
runtime.forcegchelper()
    /root/go/src/runtime/proc.go:230 +0xaa fp=0x185227e0 sp=0x185227c8
runtime.goexit()
    /root/go/src/runtime/asm_386.s:1605 +0x1 fp=0x185227e4 sp=0x185227e0
created by runtime.init.4
    /root/go/src/runtime/proc.go:219 +0x2a

goroutine 3 [GC sweep wait]:
runtime.gopark(0x8174460, 0x81e10e0, 0x8162ff6, 0xd, 0x8096514, 0x1)
    /root/go/src/runtime/proc.go:265 +0x130 fp=0x18522fa0 sp=0x18522f8c
runtime.goparkunlock(0x81e10e0, 0x8162ff6, 0xd, 0x14, 0x1)
    /root/go/src/runtime/proc.go:271 +0x4b fp=0x18522fbc sp=0x18522fa0
runtime.bgsweep(0x18542000)
    /root/go/src/runtime/mgcsweep.go:79 +0x125 fp=0x18522fd8 sp=0x18522fbc
runtime.goexit()
    /root/go/src/runtime/asm_386.s:1605 +0x1 fp=0x18522fdc sp=0x18522fd8
created by runtime.gcenable
    /root/go/src/runtime/mgc.go:195 +0x52

goroutine 4 [GC worker (idle)]:
runtime.gopark(0x81743b0, 0x18510110, 0x8163797, 0x10, 0x14, 0x0)
    /root/go/src/runtime/proc.go:265 +0x130 fp=0x1852379c sp=0x18523788
runtime.gcBgMarkWorker(0x1851c000)
    /root/go/src/runtime/mgc.go:1421 +0xd6 fp=0x185237d8 sp=0x1852379c
runtime.goexit()
    /root/go/src/runtime/asm_386.s:1605 +0x1 fp=0x185237dc sp=0x185237d8
created by runtime.gcBgMarkStartWorkers
    /root/go/src/runtime/mgc.go:1342 +0x79

goroutine 5 [finalizer wait, 1 minutes]:
runtime.gopark(0x8174460, 0x81f13fc, 0x81632e9, 0xe, 0x14, 0x1)
    /root/go/src/runtime/proc.go:265 +0x130 fp=0x18523f8c sp=0x18523f78
runtime.goparkunlock(0x81f13fc, 0x81632e9, 0xe, 0x14, 0x1)
    /root/go/src/runtime/proc.go:271 +0x4b fp=0x18523fa8 sp=0x18523f8c
runtime.runfinq()
    /root/go/src/runtime/mfinal.go:158 +0x9e fp=0x18523fe0 sp=0x18523fa8
runtime.goexit()
    /root/go/src/runtime/asm_386.s:1605 +0x1 fp=0x18523fe4 sp=0x18523fe0
created by runtime.createfing
    /root/go/src/runtime/mfinal.go:139 +0x5c

goroutine 6 [timer goroutine (idle)]:
runtime.gopark(0x8174460, 0x81e1180, 0x816505e, 0x16, 0x8174514, 0x1)
    /root/go/src/runtime/proc.go:265 +0x130 fp=0x18524770 sp=0x1852475c
runtime.goparkunlock(0x81e1180, 0x816505e, 0x16, 0x14, 0x1)
    /root/go/src/runtime/proc.go:271 +0x4b fp=0x1852478c sp=0x18524770
runtime.timerproc()
    /root/go/src/runtime/time.go:202 +0x123 fp=0x185247e0 sp=0x1852478c
runtime.goexit()
    /root/go/src/runtime/asm_386.s:1605 +0x1 fp=0x185247e4 sp=0x185247e0
created by runtime.addtimerLocked
    /root/go/src/runtime/time.go:116 +0x112

goroutine 7 [syscall]:
syscall.Syscall6(0x72, 0x7ed0, 0x1853dda0, 0x0, 0x1855c000, 0x0, 0x0, 0xb76ec000, 0x0, 0x16caa3ff)
    /root/go/src/syscall/asm_linux_386.s:45 +0x5 fp=0x1853dd44 sp=0x1853dd40
syscall.wait4(0x7ed0, 0x1853dda0, 0x0, 0x1855c000, 0x50, 0x0, 0x0)
    /root/go/src/syscall/zsyscall_linux_386.go:172 +0x71 fp=0x1853dd84 sp=0x1853dd44
syscall.Wait4(0x7ed0, 0x1853ddc4, 0x0, 0x1855c000, 0x18510240, 0x0, 0x0)
    /root/go/src/syscall/syscall_linux.go:256 +0x4d fp=0x1853dda8 sp=0x1853dd84
os.(*Process).wait(0x185103a0, 0x0, 0x0, 0x0)
    /root/go/src/os/exec_unix.go:22 +0xae fp=0x1853de00 sp=0x1853dda8
os.(*Process).Wait(0x185103a0, 0x1850e700, 0x0, 0x0)
    /root/go/src/os/doc.go:49 +0x2b fp=0x1853de14 sp=0x1853de00
os/exec.(*Cmd).WaitContext(0x185120a0, 0x0, 0x0, 0x0, 0x0)
    /root/go/src/os/exec/exec.go:424 +0x198 fp=0x1853de88 sp=0x1853de14
os/exec.(*Cmd).Wait(0x185120a0, 0x0, 0x0)
    /root/go/src/os/exec/exec.go:399 +0x35 fp=0x1853dea0 sp=0x1853de88
os/exec.(*Cmd).Run(0x185120a0, 0x0, 0x0)
    /root/go/src/os/exec/exec.go:263 +0x58 fp=0x1853deb8 sp=0x1853dea0
os/exec.(*Cmd).CombinedOutput(0x185120a0, 0x0, 0x0, 0x0, 0x0, 0x0)
    /root/go/src/os/exec/exec.go:484 +0x1a7 fp=0x1853df00 sp=0x1853deb8
runtime/pprof_test.TestStackBarrierProfiling(0x18518200)
    /root/go/src/runtime/pprof/pprof_test.go:392 +0x2c8 fp=0x1853dfac sp=0x1853df00
testing.tRunner(0x18518200, 0x8174538)
    /root/go/src/testing/testing.go:547 +0x8c fp=0x1853dfd0 sp=0x1853dfac
runtime.goexit()
    /root/go/src/runtime/asm_386.s:1605 +0x1 fp=0x1853dfd4 sp=0x1853dfd0
created by testing.(*T).Run
    /root/go/src/testing/testing.go:583 +0x2a5

goroutine 8 [syscall]:
syscall.Syscall(0x3, 0x4, 0x1856e000, 0x200, 0x8095550, 0x18528500, 0x0)
    /root/go/src/syscall/asm_linux_386.s:20 +0x5 fp=0x185205fc sp=0x185205f8
syscall.read(0x4, 0x1856e000, 0x200, 0x200, 0x817427c, 0x0, 0x0)
    /root/go/src/syscall/zsyscall_linux_386.go:783 +0x5b fp=0x18520628 sp=0x185205fc
syscall.Read(0x4, 0x1856e000, 0x200, 0x200, 0x0, 0x0, 0x0)
    /root/go/src/syscall/syscall_unix.go:161 +0x45 fp=0x18520648 sp=0x18520628
os.(*File).read(0x18526188, 0x1856e000, 0x200, 0x200, 0x80564fe, 0x0, 0x0)
    /root/go/src/os/file_unix.go:228 +0x4a fp=0x18520668 sp=0x18520648
os.(*File).Read(0x18526188, 0x1856e000, 0x200, 0x200, 0x185206ac, 0x0, 0x0)
    /root/go/src/os/file.go:97 +0x6f fp=0x18520694 sp=0x18520668
bytes.(*Buffer).ReadFrom(0x1856c060, 0x81cf770, 0x18526188, 0x0, 0x0, 0x0, 0x0)
    /root/go/src/bytes/buffer.go:176 +0x1c5 fp=0x185206ec sp=0x18520694
io.copyBuffer(0x81cf6f0, 0x1856c060, 0x81cf770, 0x18526188, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, ...)
    /root/go/src/io/io.go:392 +0x129 fp=0x18520750 sp=0x185206ec
io.Copy(0x81cf6f0, 0x1856c060, 0x81cf770, 0x18526188, 0x0, 0x0, 0x0, 0x0)
    /root/go/src/io/io.go:368 +0x53 fp=0x18520780 sp=0x18520750
os/exec.(*Cmd).writerDescriptor.func1(0x0, 0x0)
    /root/go/src/os/exec/exec.go:237 +0x57 fp=0x185207c0 sp=0x18520780
os/exec.(*Cmd).Start.func1(0x185120a0, 0x18510240)
    /root/go/src/os/exec/exec.go:354 +0x1d fp=0x185207d8 sp=0x185207c0
runtime.goexit()
    /root/go/src/runtime/asm_386.s:1605 +0x1 fp=0x185207dc sp=0x185207d8
created by os/exec.(*Cmd).Start
    /root/go/src/os/exec/exec.go:355 +0x698

This is all on current tip:

go version devel +495e3c6 Tue May 17 04:02:11 2016 +0000 linux/386

I hope you have everything you need, Dr Austin.

Alex

@aclements
Copy link
Member

Oh, is this a single core? If it is, this is probably the same as #15706.

@aclements
Copy link
Member

@alexbrainman, could you give https://golang.org/cl/23172 a try?

@alexbrainman
Copy link
Member Author

Oh, is this a single core?

It is.

... this is probably the same as #15706.

It is. The issue #15706 is about the same TestStackBarrierProfiling hangs. I am closing my issue as duplicate.

... could you give https://golang.org/cl/23172 a try?

CL 23172 fixes my problem. I can run all.bash without fear now. Thank you.

Alex

@aclements
Copy link
Member

Great! Thanks for testing.

@golang golang locked and limited conversation to collaborators May 18, 2017
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Projects
None yet
Development

No branches or pull requests

4 participants