runtime: SIGBUS during TestTraceStress on freebsd-386-gce101 #10212

mikioh · 2015-03-22T01:04:22Z

Not sure this is the same as #9953.

fatal error: unexpected signal during runtime execution
[signal 0xa code=0xc addr=0x28316794 pc=0x80548be]

runtime stack:
runtime.throw(0x82311a8, 0x2a)
    /tmp/buildlet-scatch766897833/go/src/runtime/panic.go:543 +0x80
runtime.sigpanic()
    /tmp/buildlet-scatch766897833/go/src/runtime/sigpanic_unix.go:12 +0x54
runtime.gcmarkwb_m(0x587a100c, 0x587a1218)
    /tmp/buildlet-scatch766897833/go/src/runtime/mbarrier.go:73 +0xae
runtime.writebarrierptr_nostore1.func1()
    /tmp/buildlet-scatch766897833/go/src/runtime/mbarrier.go:111 +0x115
runtime.systemstack(0x38409e88)
    /tmp/buildlet-scatch766897833/go/src/runtime/asm_386.s:283 +0x77
runtime.writebarrierptr_nostore1(0x587a100c, 0x587a1218)
    /tmp/buildlet-scatch766897833/go/src/runtime/mbarrier.go:112 +0x44
runtime.writebarrierptr(0x587a100c, 0x587a1218)
    /tmp/buildlet-scatch766897833/go/src/runtime/mbarrier.go:135 +0x7f
runtime.writebarrierslice(0x587a100c, 0x587a1218, 0x689d, 0xfde8)
    /tmp/buildlet-scatch766897833/go/src/runtime/mbarrier.go:211 +0x1e
runtime.traceEvent(0x383d6a0e, 0xffffffff, 0x38409f70, 0x1, 0x1)
    /tmp/buildlet-scatch766897833/go/src/runtime/trace.go:502 +0x5af
runtime.traceGoStart()
    /tmp/buildlet-scatch766897833/go/src/runtime/trace.go:770 +0x81
runtime.execute(0x383d74a0)
    /tmp/buildlet-scatch766897833/go/src/runtime/proc1.go:1214 +0xd7
runtime.schedule()
    /tmp/buildlet-scatch766897833/go/src/runtime/proc1.go:1418 +0x76
runtime.goschedImpl(0x383d74a0)
    /tmp/buildlet-scatch766897833/go/src/runtime/proc1.go:1530 +0xd1
runtime.gosched_m(0x383d74a0)
    /tmp/buildlet-scatch766897833/go/src/runtime/proc1.go:1538 +0x33
runtime.mcall(0x383fc52c)
    /tmp/buildlet-scatch766897833/go/src/runtime/asm_386.s:210 +0x43

goroutine 66 [running, locked to thread]:
runtime.Gosched()
    /tmp/buildlet-scatch766897833/go/src/runtime/proc.go:135 +0x10 fp=0x4c2497d4 sp=0x4c2497cc
runtime/pprof_test.TestTraceStressStartStop.func1.5(0x383e6140)
    /tmp/buildlet-scatch766897833/go/src/runtime/pprof/trace_test.go:269 +0x4a fp=0x4c2497e8 sp=0x4c2497d4
runtime.goexit()
    /tmp/buildlet-scatch766897833/go/src/runtime/asm_386.s:2431 +0x1 fp=0x4c2497ec sp=0x4c2497e8
created by runtime/pprof_test.TestTraceStressStartStop.func1
    /tmp/buildlet-scatch766897833/go/src/runtime/pprof/trace_test.go:272 +0x233

goroutine 1 [chan receive]:
testing.RunTests(0x82528e8, 0x82e7160, 0xe, 0xe, 0x1)
    /tmp/buildlet-scatch766897833/go/src/testing/testing.go:561 +0x864
testing.(*M).Run(0x383e8120, 0x82fdac0)
    /tmp/buildlet-scatch766897833/go/src/testing/testing.go:490 +0x65
main.main()
    /tmp/go-build720119124/runtime/pprof/_test/_testmain.go:82 +0x171

goroutine 89 [semacquire]:
runtime.StopTrace()
    /tmp/buildlet-scatch766897833/go/src/runtime/trace.go:184 +0x28
runtime/pprof.StopTrace()
    /tmp/buildlet-scatch766897833/go/src/runtime/pprof/pprof.go:642 +0x18
runtime/pprof_test.TestTraceStressStartStop(0x4c23a240)
    /tmp/buildlet-scatch766897833/go/src/runtime/pprof/trace_test.go:356 +0x1c0
testing.tRunner(0x4c23a240, 0x82e71f0)
    /tmp/buildlet-scatch766897833/go/src/testing/testing.go:452 +0xa0
created by testing.RunTests
    /tmp/buildlet-scatch766897833/go/src/testing/testing.go:560 +0x832

goroutine 40 [select (no cases)]:
runtime/pprof_test.TestTraceSymbolize.func1()
    /tmp/buildlet-scatch766897833/go/src/runtime/pprof/trace_stack_test.go:38 +0x18
created by runtime/pprof_test.TestTraceSymbolize
    /tmp/buildlet-scatch766897833/go/src/runtime/pprof/trace_stack_test.go:39 +0x179

goroutine 41 [chan send (nil chan)]:
runtime/pprof_test.TestTraceSymbolize.func2()
    /tmp/buildlet-scatch766897833/go/src/runtime/pprof/trace_stack_test.go:42 +0x38
created by runtime/pprof_test.TestTraceSymbolize
    /tmp/buildlet-scatch766897833/go/src/runtime/pprof/trace_stack_test.go:43 +0x18e

goroutine 42 [chan receive (nil chan)]:
runtime/pprof_test.TestTraceSymbolize.func3()
    /tmp/buildlet-scatch766897833/go/src/runtime/pprof/trace_stack_test.go:46 +0x30
created by runtime/pprof_test.TestTraceSymbolize
    /tmp/buildlet-scatch766897833/go/src/runtime/pprof/trace_stack_test.go:47 +0x1a3

goroutine 90 [runnable]:
runtime/pprof_test.TestTraceStressStartStop.func1(0x384690c0, 0x4c23a240)
    /tmp/buildlet-scatch766897833/go/src/runtime/pprof/trace_test.go:277 +0x271
created by runtime/pprof_test.TestTraceStressStartStop
    /tmp/buildlet-scatch766897833/go/src/runtime/pprof/trace_test.go:348 +0x99

goroutine 113 [chan receive]:
runtime/pprof_test.TestTraceStressStartStop.func1.2(0x383e6140, 0x4c23c020)
    /tmp/buildlet-scatch766897833/go/src/runtime/pprof/trace_test.go:241 +0x32
created by runtime/pprof_test.TestTraceStressStartStop.func1
    /tmp/buildlet-scatch766897833/go/src/runtime/pprof/trace_test.go:243 +0xb7

goroutine 114 [syscall]:
syscall.Syscall(0x3, 0x3ea03fcf, 0x1, 0x1, 0x0, 0x58751218, 0x3128)
    /tmp/buildlet-scatch766897833/go/src/syscall/asm_freebsd_386.s:20 +0x5
syscall.read(0x3, 0x3ea03fcf, 0x1, 0x1, 0xb23bb542, 0x0, 0x0)
    /tmp/buildlet-scatch766897833/go/src/syscall/zsyscall_freebsd_386.go:890 +0x50
syscall.Read(0x3, 0x3ea03fcf, 0x1, 0x1, 0x58751000, 0x0, 0x0)
    /tmp/buildlet-scatch766897833/go/src/syscall/syscall_unix.go:136 +0x46
os.(*File).read(0x4c23e000, 0x3ea03fcf, 0x1, 0x1, 0x9, 0x0, 0x0)
    /tmp/buildlet-scatch766897833/go/src/os/file_unix.go:203 +0x6c
os.(*File).Read(0x4c23e000, 0x3ea03fcf, 0x1, 0x1, 0xfde8, 0x0, 0x0)
    /tmp/buildlet-scatch766897833/go/src/os/file.go:95 +0x6c
runtime/pprof_test.TestTraceStressStartStop.func1.4(0x4c23e000, 0x383e6140, 0x4c23c020)
    /tmp/buildlet-scatch766897833/go/src/runtime/pprof/trace_test.go:256 +0x54
created by runtime/pprof_test.TestTraceStressStartStop.func1
    /tmp/buildlet-scatch766897833/go/src/runtime/pprof/trace_test.go:259 +0x202

goroutine 98 [select (no cases)]:
runtime/pprof_test.TestTraceStress.func9()
    /tmp/buildlet-scatch766897833/go/src/runtime/pprof/trace_test.go:205 +0x1d
created by runtime/pprof_test.TestTraceStress
    /tmp/buildlet-scatch766897833/go/src/runtime/pprof/trace_test.go:206 +0x82c

goroutine 67 [trace reader (blocked)]:
runtime.ReadTrace(0x0, 0x0, 0x0)
    /tmp/buildlet-scatch766897833/go/src/runtime/trace.go:313 +0x1d2
runtime/pprof.StartTrace.func1(0x584e8918, 0x383eb440)
    /tmp/buildlet-scatch766897833/go/src/runtime/pprof/pprof.go:629 +0x1b
created by runtime/pprof.StartTrace
    /tmp/buildlet-scatch766897833/go/src/runtime/pprof/pprof.go:635 +0x6a
FAIL    runtime/pprof   7.732s

The text was updated successfully, but these errors were encountered:

mikioh · 2015-03-22T01:04:40Z

See http://build.golang.org/log/51a465959ec7ed0f9b6d695745cfa94fa3759ad2.

% git rev-parse HEAD
25bf792

rsc · 2015-05-21T19:57:42Z

This could be caused by the write barrier consulting arena_used and then h_spans while this sequence runs in another thread:

    h.arena_used = p + n
    if p_end > h.arena_end {
        h.arena_end = p_end
    }

    XXX write barrier on other thread NOW XXX

    mHeap_MapBits(h)
    mHeap_MapSpans(h)

If there is system memory in the middle of the arena (more likely on 32-bit systems) then the advancement of arena_used may cause the range arena_start, arena_used to now include that memory. Inheap sees that the system pointer it is considering (and it is a system pointer since the barrier is in traceEvent) is in range, so it looks at the corresponding h_spans entry. But since mHeap_MapSpans has not completed yet, the corresponding h_spans entry is not present in memory and causes the fault.

The fix would be to swap the two halves of the above code, passing the expected new arena_end value into mHeap_MapBits and mHeap_MapSpans, but waiting until they return to actually update h.arena_used.

This sequence happens twice in runtime/malloc.go. The other looks like:

    p := h.arena_used
    sysMap((unsafe.Pointer)(p), n, h.arena_reserved, &memstats.heap_sys)
    h.arena_used += n
    mHeap_MapBits(h)
    mHeap_MapSpans(h)

Both need to be fixed.

@aclements @RLH

aclements · 2015-05-21T19:59:07Z

If Russ's theory is right, this is closely related to issue #9984.

gopherbot · 2015-06-08T14:00:35Z

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

aclements · 2015-06-17T16:29:14Z

This crash is still happening regularly on freebsd-386-gce101, openbsd-386-gce56, and windows-386-gce.

mikioh added this to the Go1.5 milestone Mar 23, 2015

mikioh mentioned this issue May 2, 2015

runtime: fatal error: unexpected signal during runtime execution inside gcmarkwb_m #10664

Closed

rsc mentioned this issue Jun 8, 2015

runtime/pprof: unexpected signal during runtime execution on windows-386-gce #10564

Closed

rsc closed this as completed in d57c889 Jun 11, 2015

aclements reopened this Jun 17, 2015

aclements mentioned this issue Jun 22, 2015

runtime: writebarrier inheap check is racy #11324

Closed

aclements closed this as completed in 9a3112b Jun 22, 2015

golang locked and limited conversation to collaborators Jun 25, 2016

gopherbot added the FrozenDueToAge label Jun 25, 2016

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

runtime: SIGBUS during TestTraceStress on freebsd-386-gce101 #10212

runtime: SIGBUS during TestTraceStress on freebsd-386-gce101 #10212

mikioh commented Mar 22, 2015

mikioh commented Mar 22, 2015

rsc commented May 21, 2015

aclements commented May 21, 2015

gopherbot commented Jun 8, 2015

aclements commented Jun 17, 2015

runtime: SIGBUS during TestTraceStress on freebsd-386-gce101 #10212

runtime: SIGBUS during TestTraceStress on freebsd-386-gce101 #10212

Comments

mikioh commented Mar 22, 2015

mikioh commented Mar 22, 2015

rsc commented May 21, 2015

aclements commented May 21, 2015

gopherbot commented Jun 8, 2015

aclements commented Jun 17, 2015