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.

Sign up for GitHub

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

Jump to bottom

runtime/trace: test failed(timeout/hang) in low end machine, CgoCallbackGC use up all CPU power #14770

Closed
wheelcomplex opened this issue Mar 11, 2016 · 4 comments
Closed

runtime/trace: test failed(timeout/hang) in low end machine, CgoCallbackGC use up all CPU power #14770

wheelcomplex opened this issue Mar 11, 2016 · 4 comments
Labels
FrozenDueToAge

Comments

@wheelcomplex
Copy link
Contributor

Please answer these questions before submitting your issue. Thanks!

  1. What version of Go are you using (go version)?

    $ go version
go version devel +b354f91 Fri Mar 11 06:43:01 2016 +0000 freebsd/amd64

  2. What operating system and processor architecture are you using (go env)?

    $ uname -a
FreeBSD freebsd-i5-box.localdomain 10.2-STABLE FreeBSD 10.2-STABLE #0 r292855: Tue Dec 29 06:17:50 UTC 2015     root@releng1.nyi.freebsd.org:/usr/obj/usr/src/sys/GENERIC  amd64

    $ cpuflags clang
Unknown machine - please send cpuflags details to abs@absd.org
OS      : 'FreeBSD'
hw.model    : 'Genuine Intel CPU           U7300  @ 1.30GHz'
hw.machine  : 'amd64'
hw.machine_arch : 'amd64'
cpu details :
CPU: Genuine Intel(R) CPU           U7300  @ 1.30GHz (1339.03-MHz K8-class CPU)
Origin="GenuineIntel"  Id=0x1067a  Family=0x6  Model=0x17  Stepping=10
Features=0xbfebfbff
Features2=0xc08e3bd
AMD Features=0x20100800
AMD Features2=0x1
VT-x: HLT,PAUSE
TSC: P-state invariant, performance statistics
-msse3 -mfpmath=sse

    $ go env
GOARCH="amd64"
GOBIN="/home/rhinofly/home/ds/sandspace/go/bin.freebsd-amd64"
GOEXE=""
GOHOSTARCH="amd64"
GOHOSTOS="freebsd"
GOOS="freebsd"
GOPATH="/home/rhinofly/home/ds/sandspace/external/:/home/rhinofly/home/ds/sandspace/golibs/"
GORACE=""
GOROOT="/home/rhinofly/home/ds/sandspace/go"
GOTOOLDIR="/home/rhinofly/home/ds/sandspace/go/pkg/tool/freebsd_amd64"
CC="clang"
GOGCCFLAGS="-fPIC -m64 -pthread -fno-caret-diagnostics -Qunused-arguments -fmessage-length=0 -gno-record-gcc-switches"
CXX="clang++"
CGO_ENABLED="1"

  3. 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.

git clone https://github.com/golang/go.git tips-go && cd tips-go/src && ./all.bash
  1. What did you expect to see?

all test pass

  1. What did you see instead?
ok      reflect 0.234s
ok      regexp  0.483s
ok      regexp/syntax   1.091s

SIGQUIT: quit
PC=0x456597 m=0

goroutine 0 [idle]:
runtime.nanotime(0x754088, 0x0, 0x186a0, 0x4380e1bacf7, 0x754220, 0x40e4dd, 0x754088, 0x186a0, 0xc82001f200, 0x42d5ec, ...)
    /usr/home/rhinofly/ds/sandspace/tips-go/src/runtime/sys_freebsd_amd64.s:166 +0x17 fp=0x7fffffffe1d0 sp=0x7fffffffe1a8
runtime.notetsleep_internal(0x754088, 0x186a0, 0xc82001f200)
    /usr/home/rhinofly/ds/sandspace/tips-go/src/runtime/lock_futex.go:179 +0x10b fp=0x7fffffffe200 sp=0x7fffffffe1d0
runtime.notetsleep(0x754088, 0x186a0, 0xc820416e00)
    /usr/home/rhinofly/ds/sandspace/tips-go/src/runtime/lock_futex.go:194 +0x4d fp=0x7fffffffe220 sp=0x7fffffffe200
runtime.forEachP(0x66caf8)
    /usr/home/rhinofly/ds/sandspace/tips-go/src/runtime/proc.go:1161 +0x2fc fp=0x7fffffffe288 sp=0x7fffffffe220
runtime.gcMarkDone.func1()
    /usr/home/rhinofly/ds/sandspace/tips-go/src/runtime/mgc.go:1090 +0x23 fp=0x7fffffffe298 sp=0x7fffffffe288
runtime.systemstack(0x754200)
    /usr/home/rhinofly/ds/sandspace/tips-go/src/runtime/asm_amd64.s:291 +0x79 fp=0x7fffffffe2a0 sp=0x7fffffffe298
runtime.mstart()
    /usr/home/rhinofly/ds/sandspace/tips-go/src/runtime/proc.go:1030 fp=0x7fffffffe2a8 sp=0x7fffffffe2a0

goroutine 151 [running]:
runtime.systemstack_switch()
    /usr/home/rhinofly/ds/sandspace/tips-go/src/runtime/asm_amd64.s:245 fp=0xc820027728 sp=0xc820027720
runtime.gcMarkDone()
    /usr/home/rhinofly/ds/sandspace/tips-go/src/runtime/mgc.go:1091 +0x139 fp=0xc820027748 sp=0xc820027728
runtime.gcBgMarkWorker(0xc82001e000)
    /usr/home/rhinofly/ds/sandspace/tips-go/src/runtime/mgc.go:1474 +0x293 fp=0xc8200277b8 sp=0xc820027748
runtime.goexit()
    /usr/home/rhinofly/ds/sandspace/tips-go/src/runtime/asm_amd64.s:2006 +0x1 fp=0xc8200277c0 sp=0xc8200277b8
created by runtime.gcBgMarkStartWorkers
    /usr/home/rhinofly/ds/sandspace/tips-go/src/runtime/mgc.go:1324 +0x8a

goroutine 1 [chan receive, 3 minutes]:
runtime.gopark(0x66ccb0, 0xc82042c478, 0x631229, 0xc, 0xc820090317, 0x3)
    /usr/home/rhinofly/ds/sandspace/tips-go/src/runtime/proc.go:262 +0x131 fp=0xc820429bf8 sp=0xc820429bd0
runtime.goparkunlock(0xc82042c478, 0x631229, 0xc, 0x17, 0x3)
    /usr/home/rhinofly/ds/sandspace/tips-go/src/runtime/proc.go:268 +0x54 fp=0xc820429c30 sp=0xc820429bf8
runtime.chanrecv(0x593b20, 0xc82042c420, 0xc820429df8, 0xc820429c01, 0x4668fb)
    /usr/home/rhinofly/ds/sandspace/tips-go/src/runtime/chan.go:474 +0x2ac fp=0xc820429cb0 sp=0xc820429c30
runtime.chanrecv1(0x593b20, 0xc82042c420, 0xc820429df8)
    /usr/home/rhinofly/ds/sandspace/tips-go/src/runtime/chan.go:357 +0x2b fp=0xc820429ce0 sp=0xc820429cb0
testing.RunTests(0x66c6a0, 0x750540, 0xb1, 0xb1, 0x5b)
    /usr/home/rhinofly/ds/sandspace/tips-go/src/testing/testing.go:582 +0x351 fp=0xc820429e20 sp=0xc820429ce0
testing.(*M).Run(0xc820429ef8, 0x40df13)
    /usr/home/rhinofly/ds/sandspace/tips-go/src/testing/testing.go:515 +0x79 fp=0xc820429ea0 sp=0xc820429e20
runtime_test.TestMain(0xc820429ef8)
    /usr/home/rhinofly/ds/sandspace/tips-go/src/runtime/crash_test.go:24 +0x25 fp=0xc820429ee8 sp=0xc820429ea0
main.main()
    runtime/_test/_testmain.go:954 +0xb4 fp=0xc820429f50 sp=0xc820429ee8
runtime.main()
    /usr/home/rhinofly/ds/sandspace/tips-go/src/runtime/proc.go:188 +0x20a fp=0xc820429fa0 sp=0xc820429f50
runtime.goexit()
    /usr/home/rhinofly/ds/sandspace/tips-go/src/runtime/asm_amd64.s:2006 +0x1 fp=0xc820429fa8 sp=0xc820429fa0

goroutine 17 [syscall, 4 minutes, locked to thread]:
runtime.goexit()
    /usr/home/rhinofly/ds/sandspace/tips-go/src/runtime/asm_amd64.s:2006 +0x1 fp=0xc820038fb8 sp=0xc820038fb0

goroutine 2 [force gc (idle), 3 minutes]:
runtime.gopark(0x66ccb0, 0x753950, 0x633ada, 0xf, 0x100000000000014, 0x1)
    /usr/home/rhinofly/ds/sandspace/tips-go/src/runtime/proc.go:262 +0x131 fp=0xc820026758 sp=0xc820026730
runtime.goparkunlock(0x753950, 0x633ada, 0xf, 0xc820000114, 0x1)
    /usr/home/rhinofly/ds/sandspace/tips-go/src/runtime/proc.go:268 +0x54 fp=0xc820026790 sp=0xc820026758
runtime.forcegchelper()
    /usr/home/rhinofly/ds/sandspace/tips-go/src/runtime/proc.go:229 +0x9f fp=0xc8200267c0 sp=0xc820026790
runtime.goexit()
    /usr/home/rhinofly/ds/sandspace/tips-go/src/runtime/asm_amd64.s:2006 +0x1 fp=0xc8200267c8 sp=0xc8200267c0
created by runtime.init.4
    /usr/home/rhinofly/ds/sandspace/tips-go/src/runtime/proc.go:218 +0x2b

goroutine 3 [GC sweep wait, 3 minutes]:
runtime.gopark(0x66ccb0, 0x753b80, 0x631cab, 0xd, 0x44c714, 0x1)
    /usr/home/rhinofly/ds/sandspace/tips-go/src/runtime/proc.go:262 +0x131 fp=0xc820026f48 sp=0xc820026f20
runtime.goparkunlock(0x753b80, 0x631cab, 0xd, 0x14, 0x1)
    /usr/home/rhinofly/ds/sandspace/tips-go/src/runtime/proc.go:268 +0x54 fp=0xc820026f80 sp=0xc820026f48
runtime.bgsweep(0xc82001a070)
    /usr/home/rhinofly/ds/sandspace/tips-go/src/runtime/mgcsweep.go:79 +0x125 fp=0xc820026fb8 sp=0xc820026f80
runtime.goexit()
    /usr/home/rhinofly/ds/sandspace/tips-go/src/runtime/asm_amd64.s:2006 +0x1 fp=0xc820026fc0 sp=0xc820026fb8
created by runtime.gcenable
    /usr/home/rhinofly/ds/sandspace/tips-go/src/runtime/mgc.go:191 +0x53

goroutine 18 [finalizer wait, 4 minutes]:
runtime.gopark(0x66ccb0, 0x76ef30, 0x632cbe, 0xe, 0x14, 0x1)
    /usr/home/rhinofly/ds/sandspace/tips-go/src/runtime/proc.go:262 +0x131 fp=0xc820022710 sp=0xc8200226e8
runtime.goparkunlock(0x76ef30, 0x632cbe, 0xe, 0x14, 0x1)
    /usr/home/rhinofly/ds/sandspace/tips-go/src/runtime/proc.go:268 +0x54 fp=0xc820022748 sp=0xc820022710
runtime.runfinq()
    /usr/home/rhinofly/ds/sandspace/tips-go/src/runtime/mfinal.go:158 +0xa5 fp=0xc8200227c0 sp=0xc820022748
runtime.goexit()
    /usr/home/rhinofly/ds/sandspace/tips-go/src/runtime/asm_amd64.s:2006 +0x1 fp=0xc8200227c8 sp=0xc8200227c0
created by runtime.createfing
    /usr/home/rhinofly/ds/sandspace/tips-go/src/runtime/mfinal.go:139 +0x66

goroutine 19 [syscall, 3 minutes]:
runtime.notetsleepg(0x753c98, 0x29845e9534, 0x0)
    /usr/home/rhinofly/ds/sandspace/tips-go/src/runtime/lock_futex.go:205 +0x34 fp=0xc820022f48 sp=0xc820022f20
runtime.timerproc()
    /usr/home/rhinofly/ds/sandspace/tips-go/src/runtime/time.go:209 +0x363 fp=0xc820022fc0 sp=0xc820022f48
runtime.goexit()
    /usr/home/rhinofly/ds/sandspace/tips-go/src/runtime/asm_amd64.s:2006 +0x1 fp=0xc820022fc8 sp=0xc820022fc0
created by runtime.addtimerLocked
    /usr/home/rhinofly/ds/sandspace/tips-go/src/runtime/time.go:116 +0x115

goroutine 22443 [syscall, 3 minutes]:
syscall.Syscall6(0x7, 0x5dc1, 0xc820036ce4, 0x0, 0xc820090480, 0x0, 0x0, 0x5d1fa0, 0xc800000000, 0xc820010700)
    /usr/home/rhinofly/ds/sandspace/tips-go/src/syscall/asm_freebsd_amd64.s:44 +0x5 fp=0xc820036c38 sp=0xc820036c30
syscall.wait4(0x5dc1, 0xc820036ce4, 0x0, 0xc820090480, 0x90, 0x617760, 0x1)
    /usr/home/rhinofly/ds/sandspace/tips-go/src/syscall/zsyscall_freebsd_amd64.go:34 +0x78 fp=0xc820036ca8 sp=0xc820036c38
syscall.Wait4(0x5dc1, 0xc820036d2c, 0x0, 0xc820090480, 0x66c848, 0xc82042e3c0, 0xc82044a7c0)
    /usr/home/rhinofly/ds/sandspace/tips-go/src/syscall/syscall_bsd.go:129 +0x47 fp=0xc820036cf0 sp=0xc820036ca8
os.(*Process).wait(0xc82044ac40, 0xc820080380, 0xc8200840d0, 0xc82044a7e0)
    /usr/home/rhinofly/ds/sandspace/tips-go/src/os/exec_unix.go:22 +0xf4 fp=0xc820036d70 sp=0xc820036cf0
os.(*Process).Wait(0xc82044ac40, 0xc820036dd0, 0x0, 0x0)
    /usr/home/rhinofly/ds/sandspace/tips-go/src/os/doc.go:49 +0x21 fp=0xc820036d98 sp=0xc820036d70
os/exec.(*Cmd).Wait(0xc82042e3c0, 0x0, 0x0)
    /usr/home/rhinofly/ds/sandspace/tips-go/src/os/exec/exec.go:396 +0x58 fp=0xc820036e20 sp=0xc820036d98
os/exec.(*Cmd).Run(0xc82042e3c0, 0xc820080380, 0xc820435c00)
    /usr/home/rhinofly/ds/sandspace/tips-go/src/os/exec/exec.go:262 +0x3e fp=0xc820036e40 sp=0xc820036e20
os/exec.(*Cmd).CombinedOutput(0xc82042e3c0, 0xc82042e3c0, 0xc8200c46d8, 0x1, 0x1, 0xc82042e3c0)
    /usr/home/rhinofly/ds/sandspace/tips-go/src/os/exec/exec.go:453 +0x174 fp=0xc820036e80 sp=0xc820036e40
runtime_test.runTestProg(0xc8200903f0, 0x630885, 0xb, 0x631bdb, 0xd, 0x593b20, 0x427659)
    /usr/home/rhinofly/ds/sandspace/tips-go/src/runtime/crash_test.go:68 +0xf9 fp=0xc820036ef0 sp=0xc820036e80
runtime_test.TestCgoCallbackGC(0xc8200903f0)
    /usr/home/rhinofly/ds/sandspace/tips-go/src/runtime/crash_cgo_test.go:54 +0x63 fp=0xc820036f80 sp=0xc820036ef0
testing.tRunner(0xc8200903f0, 0x750720)
    /usr/home/rhinofly/ds/sandspace/tips-go/src/testing/testing.go:473 +0x7e fp=0xc820036fa0 sp=0xc820036f80
runtime.goexit()
    /usr/home/rhinofly/ds/sandspace/tips-go/src/runtime/asm_amd64.s:2006 +0x1 fp=0xc820036fa8 sp=0xc820036fa0
created by testing.RunTests
    /usr/home/rhinofly/ds/sandspace/tips-go/src/testing/testing.go:581 +0x30b

goroutine 152 [GC worker (idle), 3 minutes]:
runtime.gopark(0xc820010190, 0xc820023fa0, 0x6345fe, 0x10, 0xc820023f14, 0x0)
    /usr/home/rhinofly/ds/sandspace/tips-go/src/runtime/proc.go:262 +0x131 fp=0xc820023f48 sp=0xc820023f20
runtime.gcBgMarkWorker(0xc82001f500)
    /usr/home/rhinofly/ds/sandspace/tips-go/src/runtime/mgc.go:1397 +0xc1 fp=0xc820023fb8 sp=0xc820023f48
runtime.goexit()
    /usr/home/rhinofly/ds/sandspace/tips-go/src/runtime/asm_amd64.s:2006 +0x1 fp=0xc820023fc0 sp=0xc820023fb8
created by runtime.gcBgMarkStartWorkers
    /usr/home/rhinofly/ds/sandspace/tips-go/src/runtime/mgc.go:1324 +0x8a

goroutine 22444 [syscall, 3 minutes]:
syscall.Syscall(0x3, 0x4, 0xc820438c00, 0x200, 0x0, 0x5fd, 0x0)
    /usr/home/rhinofly/ds/sandspace/tips-go/src/syscall/asm_freebsd_amd64.s:21 +0x5 fp=0xc820029ca8 sp=0xc820029ca0
syscall.read(0x4, 0xc820438c00, 0x200, 0x200, 0xc820438c00, 0x0, 0x100000000)
    /usr/home/rhinofly/ds/sandspace/tips-go/src/syscall/zsyscall_freebsd_amd64.go:892 +0x48 fp=0xc820029cf0 sp=0xc820029ca8
syscall.Read(0x4, 0xc820438c00, 0x200, 0x200, 0x0, 0xc82000d400, 0xc8200ccc00)
    /usr/home/rhinofly/ds/sandspace/tips-go/src/syscall/syscall_unix.go:161 +0x3f fp=0xc820029d30 sp=0xc820029cf0
os.(*File).read(0xc8200840b8, 0xc820438c00, 0x200, 0x200, 0x4c8921, 0x593580, 0x200)
    /usr/home/rhinofly/ds/sandspace/tips-go/src/os/file_unix.go:228 +0x68 fp=0xc820029d70 sp=0xc820029d30
os.(*File).Read(0xc8200840b8, 0xc820438c00, 0x200, 0x200, 0x1, 0x42c675, 0xc8200cccb8)
    /usr/home/rhinofly/ds/sandspace/tips-go/src/os/file.go:95 +0x4c fp=0xc820029dd0 sp=0xc820029d70
bytes.(*Buffer).ReadFrom(0xc820080380, 0x8007d5068, 0xc8200840b8, 0xc820029ea8, 0x40e001, 0x42acb1)
    /usr/home/rhinofly/ds/sandspace/tips-go/src/bytes/buffer.go:176 +0x15f fp=0xc820029e38 sp=0xc820029dd0
io.copyBuffer(0x800810690, 0xc820080380, 0x8007d5068, 0xc8200840b8, 0x0, 0x0, 0x0, 0xc82042c418, 0x0, 0x0)
    /usr/home/rhinofly/ds/sandspace/tips-go/src/io/io.go:374 +0x319 fp=0xc820029ed0 sp=0xc820029e38
io.Copy(0x800810690, 0xc820080380, 0x8007d5068, 0xc8200840b8, 0x593a60, 0xc82042c3c0, 0xc820029f98)
    /usr/home/rhinofly/ds/sandspace/tips-go/src/io/io.go:350 +0x5a fp=0xc820029f28 sp=0xc820029ed0
os/exec.(*Cmd).writerDescriptor.func1(0x593a60, 0xc82042c3c0)
    /usr/home/rhinofly/ds/sandspace/tips-go/src/os/exec/exec.go:236 +0x56 fp=0xc820029f80 sp=0xc820029f28
os/exec.(*Cmd).Start.func1(0xc82042e3c0, 0xc82044a7c0)
    /usr/home/rhinofly/ds/sandspace/tips-go/src/os/exec/exec.go:344 +0x20 fp=0xc820029fb0 sp=0xc820029f80
runtime.goexit()
    /usr/home/rhinofly/ds/sandspace/tips-go/src/runtime/asm_amd64.s:2006 +0x1 fp=0xc820029fb8 sp=0xc820029fb0
created by os/exec.(*Cmd).Start
    /usr/home/rhinofly/ds/sandspace/tips-go/src/os/exec/exec.go:345 +0x521

rax    0x0
rbx    0x7fffffffe168
rcx    0x7fffffff
rdx    0x754088
rdi    0x4
rsi    0x7fffffffe1b0
rbp    0x3b9aca00
rsp    0x7fffffffe1a8
r8     0x7fffffffe160
r9     0x0
r10    0x7fffffff
r11    0x202
r12    0x0
r13    0x7fffffffe200
r14    0x44c670
r15    0x0
rip    0x456597
rflags 0x202
cs     0x43
fs     0x13
gs     0x1b
*** Test killed: ran too long (4m0s).
FAIL    runtime 647.781s
ok      runtime/debug   0.020s
ok      runtime/internal/atomic 0.226s
ok      runtime/pprof   2.686s

panic: test timed out after 3m0s

goroutine 38 [running]:
panic(0x550220, 0xc8234f4040)
    /usr/home/rhinofly/ds/sandspace/tips-go/src/runtime/panic.go:500 +0x189
testing.startAlarm.func1()
    /usr/home/rhinofly/ds/sandspace/tips-go/src/testing/testing.go:724 +0x10f
created by time.goFunc
    /usr/home/rhinofly/ds/sandspace/tips-go/src/time/sleep.go:129 +0x3a

goroutine 1 [chan receive, 2 minutes]:
testing.RunTests(0x5cfab8, 0x673200, 0x7, 0x7, 0x1)
    /usr/home/rhinofly/ds/sandspace/tips-go/src/testing/testing.go:582 +0x351
testing.(*M).Run(0xc820034f08, 0x404b89)
    /usr/home/rhinofly/ds/sandspace/tips-go/src/testing/testing.go:515 +0x79
main.main()
    runtime/trace/_test/_testmain.go:68 +0xb4

goroutine 17 [syscall, 2 minutes, locked to thread]:
runtime.goexit()
    /usr/home/rhinofly/ds/sandspace/tips-go/src/runtime/asm_amd64.s:2006 +0x1

goroutine 8 [running]:
    goroutine running on other thread; stack unavailable
created by testing.RunTests
    /usr/home/rhinofly/ds/sandspace/tips-go/src/testing/testing.go:581 +0x30b

goroutine 22 [select (no cases), 2 minutes]:
runtime/trace_test.TestTraceSymbolize.func1()
    /usr/home/rhinofly/ds/sandspace/tips-go/src/runtime/trace/trace_stack_test.go:38 +0x14
created by runtime/trace_test.TestTraceSymbolize
    /usr/home/rhinofly/ds/sandspace/tips-go/src/runtime/trace/trace_stack_test.go:39 +0xc9

goroutine 23 [chan send (nil chan), 2 minutes]:
runtime/trace_test.TestTraceSymbolize.func2()
    /usr/home/rhinofly/ds/sandspace/tips-go/src/runtime/trace/trace_stack_test.go:42 +0x3f
created by runtime/trace_test.TestTraceSymbolize
    /usr/home/rhinofly/ds/sandspace/tips-go/src/runtime/trace/trace_stack_test.go:43 +0xe1

goroutine 24 [chan receive (nil chan), 2 minutes]:
runtime/trace_test.TestTraceSymbolize.func3()
    /usr/home/rhinofly/ds/sandspace/tips-go/src/runtime/trace/trace_stack_test.go:46 +0x35
created by runtime/trace_test.TestTraceSymbolize
    /usr/home/rhinofly/ds/sandspace/tips-go/src/runtime/trace/trace_stack_test.go:47 +0xf9

goroutine 84 [select (no cases), 2 minutes]:
runtime/trace_test.TestTraceStress.func9()
    /usr/home/rhinofly/ds/sandspace/tips-go/src/runtime/trace/trace_test.go:200 +0x19
created by runtime/trace_test.TestTraceStress
    /usr/home/rhinofly/ds/sandspace/tips-go/src/runtime/trace/trace_test.go:201 +0x539
*** Test killed: ran too long (4m0s).
FAIL    runtime/trace   944.500s
ok      sort    0.138s
ok      strconv 1.259s
ok      strings 0.706s
ok      sync    0.171s

$ top -IaS

last pid: 24204;  load averages: 92.07, 46.36, 21.11                                                                                                                  up 0+01:16:39  16:07:03
120 processes: 4 running, 115 sleeping, 1 waiting
CPU: 19.0% user,  0.0% nice, 81.0% system,  0.0% interrupt,  0.0% idle
Mem: 575M Active, 503M Inact, 4076M Wired, 1468K Cache, 2740M Free
ARC: 1954M Total, 658M MFU, 975M MRU, 162K Anon, 29M Header, 292M Other
Swap: 

  PID USERNAME    THR PRI NICE   SIZE    RES STATE   C   TIME    WCPU COMMAND
24001 rhinofly    204  20    0   117M 48424K uwait   1   6:05 156.30% /tmp/go-build734138444/testprogcgo.exe CgoCallbackGC
 1325 rhinofly      1  20    0   180M 38560K select  1   1:15   0.78% X :0 (Xorg)
   22 root          1  24    -     0K    16K geli:w  0   1:26   0.39% [g_eli[0] ada0p4]
 1219 root          1  20    0 16736K  2236K select  1   0:06   0.20% /usr/sbin/moused -p /dev/ums0 -t auto -I /var/run/moused.ums0.pid
 1512 rhinofly      4  52    0   219M 27364K select  1   0:17   0.10% /usr/local/bin/xfce4-terminal

$ pstree -p 24001
-+= 00001 root /sbin/init --
 \-+- 01512 rhinofly /usr/local/bin/xfce4-terminal
   \-+= 03094 rhinofly bash
     \-+= 21931 rhinofly bash ./all.bash
       \-+- 22842 rhinofly go tool dist test -rebuild --no-rebuild
         \-+- 22857 rhinofly /usr/home/rhinofly/ds/sandspace/tips-go/pkg/tool/freebsd_amd64/dist test -rebuild --no-rebuild
           \-+- 22870 rhinofly go test -short -tags= -timeout=3m0s -gcflags= archive/tar archive/zip bufio bytes compress/bzip2 compress/flate compress/gzip compress/lzw compress/zlib conta
             \-+- 23893 rhinofly /tmp/go-build431565516/runtime/_test/runtime.test -test.short=true -test.timeout=3m0s
               \--- 24001 rhinofly /tmp/go-build734138444/testprogcgo.exe CgoCallbackGC

more info:

Excepted kill timeout is test.timeout=3m0s, but in most case the test run more then 3min(4m0s in this case), looks like the parent(PID 23893) has no CPU tick to issue "kill -SIGQUIT" to CgoCallbackGC (PID 24001).

Is that too many goroutine created from https://github.com/golang/go/blob/master/src/runtime/testdata/testprogcgo/callback.go#L66?

 65 func CgoCallbackGC() {
 66         const P = 100
 67         done := make(chan bool)
 68         // allocate a bunch of stack frames and spray them with pointers

After reduce const P = 100 to const P = 20 everything is OK(ok runtime/trace 41.667s). Maybe a auto-detect P base on runtime.NumCPU() is better?
@davecheney
Copy link
Contributor

You can use GO_TEST_TIMEOUT_SCALE=10 (or any scale value you like) to increase the test timeouts.

@wheelcomplex
Copy link
Contributor Author

I mean 3min timeout is quite long, so should we reduce const P to make the test pass? Is that less P will make this test useless?
Thanks.

@davecheney
Copy link
Contributor

The tests are sized for reasonably powerful machines. If you want to run
the tests in smaller machines you can change the test timeout scale, this
is what I do for my arm machines.

On Fri, 11 Mar 2016, 20:28 Wheelcomplex Yin, notifications@github.com
wrote:

I mean 3min timeout is quite long, so should we reduce const P to make the
test pass? Is that less P will make this test usless?
Thanks.

—
Reply to this email directly or view it on GitHub
#14770 (comment).

@wheelcomplex
Copy link
Contributor Author

Thanks for your explanations.

@wheelcomplex wheelcomplex changed the title runtime/trace: test failed(timeout) in low end machine, CgoCallbackGC use up all CPU power runtime/trace: test failed(timeout/hang) in low end machine, CgoCallbackGC use up all CPU power Mar 14, 2016
@golang golang locked and limited conversation to collaborators Mar 14, 2017
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees
No one assigned
Labels
FrozenDueToAge
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
3 participants
@davecheney @wheelcomplex @gopherbot