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: bad pointer in unexpected span #12138

Closed
zeebo opened this issue Aug 13, 2015 · 26 comments
Closed

runtime: bad pointer in unexpected span #12138

zeebo opened this issue Aug 13, 2015 · 26 comments
Milestone

Comments

@zeebo
Copy link
Contributor

zeebo commented Aug 13, 2015

I upgraded my system to use go1.5rc1 and let it run for a couple of days. I observed this panic:

runtime:objectstart Span weird: p=0x133a8580 k=0x99d4 s.start=0x13330000 s.limit=0x133b0000 s.state=4
fatal error: objectstart: bad pointer in unexpected span

runtime stack:
runtime.throw(0x9c2bb8, 0x2b)
    /home/jeff/go/src/runtime/panic.go:527 +0x78 fp=0xa07fec34 sp=0xa07fec28
runtime.heapBitsForObject(0x133a8580, 0x0, 0x0, 0x0, 0xa53a6f94)
    /home/jeff/go/src/runtime/mbitmap.go:214 +0x36c fp=0xa07fec58 sp=0xa07fec34
runtime.scanblock(0xb6143b90, 0x4, 0xccf990, 0xa07fecbc)
    /home/jeff/go/src/runtime/mgcmark.go:797 +0xd8 fp=0xa07fec9c sp=0xa07fec58
runtime.markroot(0x10f16000, 0x3)
    /home/jeff/go/src/runtime/mgcmark.go:102 +0x44c fp=0xa07fecec sp=0xa07fec9c
runtime.parfordo(0x10f16000)
    /home/jeff/go/src/runtime/parfor.go:95 +0x134 fp=0xa07fed40 sp=0xa07fecec
runtime.gcscan_m()
    /home/jeff/go/src/runtime/mgcmark.go:36 +0xa8 fp=0xa07fed64 sp=0xa07fed40
runtime.gc.func1()
    /home/jeff/go/src/runtime/mgc.go:996 +0x118 fp=0xa07fed84 sp=0xa07fed64
runtime.systemstack(0x11076000)
    /home/jeff/go/src/runtime/asm_arm.s:242 +0x80 fp=0xa07fed88 sp=0xa07fed84
runtime.mstart()
    /home/jeff/go/src/runtime/proc1.go:674 fp=0xa07fed88 sp=0xa07fed88

Just as last time (#11640) I'm willing to do whatever I can to help diagnose.

@ianlancetaylor ianlancetaylor added this to the Go1.5 milestone Aug 13, 2015
@ianlancetaylor
Copy link
Contributor

CC @RLH @aclements

@aclements
Copy link
Member

@zeebo, and chance you're running with -race? We fixed a memory corruption bug after rc1 was branched, but it only affects running in -race mode.

If possible, it would be great if you can run your system with GODEBUG=gccheckmark=1. It slows things down quite a bit, but enables some very useful debug code.

@RLH
Copy link
Contributor

RLH commented Aug 13, 2015

Also if you have any of the other go routine stacks that would help.

On Thursday, August 13, 2015, Austin Clements notifications@github.com
wrote:

@zeebo https://github.com/zeebo, and chance you're running with -race?
We fixed a memory corruption bug after rc1 was branched, but it only
affects running in -race mode.

If possible, it would be great if you can run your system with
GODEBUG=gccheckmark=1. It slows things down quite a bit, but enables some
very useful debug code.


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

@aclements
Copy link
Member

@zeebo, is this also with GOOS=linux GOARCH=arm GOARM=5? If so, are you actually running on an ARMv5 or something newer?

Just some quick diagnosis from the traceback: the bad pointer is the *funcval field of a "specialfinalizer" finalizer record. It looks like a pretty reasonable pointer, but points in to a span that's in state _MSpanDead. There's only one way we're supposed to be able to observe a dead span in the h_spans array: if we free a large span and coalesce it with neighboring spans, only the first and last page in the coalesced range are guaranteed to be in state "free". The pages in between may point to any span, including one in state "dead". Given how far "p" is from "s.start", this seems the most likely way we found the dead span. If this is ARM, there's also always the possibility of a missing memory barrier, since h_spans is read by the garbage collector without locking.

If we in fact freed that span, that means we either somehow created a bogus finalizer record, or we created a fine finalizer record, but failed to mark the funcval in an earlier cycle and the span got collected. One weird thing is that I would expect that funcval to be in a small object span that was only one page and hence could not leave behind "dead" spans in h_spans. This is a long shot, @zeebo, but do you have any finalizers that are closures that access particularly large variables from their enclosing frame? Or, in general, any unusual finalizers?

@zeebo
Copy link
Contributor Author

zeebo commented Aug 13, 2015

It is not in race mode. It is an ARMv5 in the sense that no binaries will run on it if I don't specify GOARM=5. Unfortunately, I'm not much of a hardware guy so I don't know what that all entails.

I don't know if we have any unusual finalizers, but it's possible. We use them mostly for freeing resources in our openssl wrapper and some debug checks if we forget to close a file handle or something. I'll do a double check of the code base to see if anything sticks out as really strange.

Here is more of the stack dump. I'm not sure if it's all of it, but this is what I have:

runtime:objectstart Span weird: p=0x133a8580 k=0x99d4 s.start=0x13330000 s.limit=0x133b0000 s.state=4
fatal error: objectstart: bad pointer in unexpected span

runtime stack:
runtime.throw(0x9c2bb8, 0x2b)
    /home/jeff/go/src/runtime/panic.go:527 +0x78 fp=0xa07fec34 sp=0xa07fec28
runtime.heapBitsForObject(0x133a8580, 0x0, 0x0, 0x0, 0xa53a6f94)
    /home/jeff/go/src/runtime/mbitmap.go:214 +0x36c fp=0xa07fec58 sp=0xa07fec34
runtime.scanblock(0xb6143b90, 0x4, 0xccf990, 0xa07fecbc)
    /home/jeff/go/src/runtime/mgcmark.go:797 +0xd8 fp=0xa07fec9c sp=0xa07fec58
runtime.markroot(0x10f16000, 0x3)
    /home/jeff/go/src/runtime/mgcmark.go:102 +0x44c fp=0xa07fecec sp=0xa07fec9c
runtime.parfordo(0x10f16000)
    /home/jeff/go/src/runtime/parfor.go:95 +0x134 fp=0xa07fed40 sp=0xa07fecec
runtime.gcscan_m()
    /home/jeff/go/src/runtime/mgcmark.go:36 +0xa8 fp=0xa07fed64 sp=0xa07fed40
runtime.gc.func1()
    /home/jeff/go/src/runtime/mgc.go:996 +0x118 fp=0xa07fed84 sp=0xa07fed64
runtime.systemstack(0x11076000)
    /home/jeff/go/src/runtime/asm_arm.s:242 +0x80 fp=0xa07fed88 sp=0xa07fed84
runtime.mstart()
    /home/jeff/go/src/runtime/proc1.go:674 fp=0xa07fed88 sp=0xa07fed88

goroutine 50 [garbage collection scan]:
runtime.systemstack_switch()
    /home/jeff/go/src/runtime/asm_arm.s:187 +0x4 fp=0x10f1b558 sp=0x10f1b554
runtime.gc(0x0)
    /home/jeff/go/src/runtime/mgc.go:1005 +0x23c fp=0x10f1b7c4 sp=0x10f1b558
runtime.backgroundgc()
    /home/jeff/go/src/runtime/mgc.go:896 +0x34 fp=0x10f1b7dc sp=0x10f1b7c4
runtime.goexit()
    /home/jeff/go/src/runtime/asm_arm.s:1031 +0x4 fp=0x10f1b7dc sp=0x10f1b7dc
created by runtime.startGC
    /home/jeff/go/src/runtime/mgc.go:869 +0x178

goroutine 1 [chan receive, 3809 minutes]:
runtime.gopark(0xa70968, 0x11cd95b0, 0x94a138, 0xc, 0x17, 0x3)
    /home/jeff/go/src/runtime/proc.go:185 +0x148 fp=0x11cf9d70 sp=0x11cf9d5c
runtime.goparkunlock(0x11cd95b0, 0x94a138, 0xc, 0x17, 0x3)
    /home/jeff/go/src/runtime/proc.go:191 +0x44 fp=0x11cf9d8c sp=0x11cf9d70
runtime.chanrecv(0x783a38, 0x11cd9580, 0x11cf9e64, 0x11df3e01, 0x11df0000)
    /home/jeff/go/src/runtime/chan.go:505 +0x960 fp=0x11cf9df8 sp=0x11cf9d8c
runtime.chanrecv1(0x783a38, 0x11cd9580, 0x11cf9e64)
    /home/jeff/go/src/runtime/chan.go:349 +0x28 fp=0x11cf9e10 sp=0x11cf9df8
sm/flud/FludProcess.RunFludProcess(0xb28f50a0, 0x110440e0, 0x0, 0x0)
    /home/jeff/katamari/go/src/sm/flud/FludProcess/process.go:90 +0x210 fp=0x11cf9e6c sp=0x11cf9e10
main.runNode(0x0, 0x0)
    /home/jeff/katamari/go/src/sm/flud/bin/fludnode/main.go:123 +0x5b0 fp=0x11cf9f48 sp=0x11cf9e6c
main.main()
    /home/jeff/katamari/go/src/sm/flud/bin/fludnode/main.go:141 +0x20c fp=0x11cf9fa4 sp=0x11cf9f48
runtime.main()
    /home/jeff/go/src/runtime/proc.go:111 +0x2b4 fp=0x11cf9fcc sp=0x11cf9fa4
runtime.goexit()
    /home/jeff/go/src/runtime/asm_arm.s:1031 +0x4 fp=0x11cf9fcc sp=0x11cf9fcc

goroutine 17 [syscall, locked to thread]:
runtime.goexit()
    /home/jeff/go/src/runtime/asm_arm.s:1031 +0x4 fp=0x10f30fd8 sp=0x10f30fd8

goroutine 2 [force gc (idle), 25 minutes]:
runtime.gopark(0xa70968, 0xce7358, 0x94b8f8, 0xf, 0x14, 0x1)
    /home/jeff/go/src/runtime/proc.go:185 +0x148 fp=0x10f1c7a8 sp=0x10f1c794
runtime.goparkunlock(0xce7358, 0x94b8f8, 0xf, 0x14, 0x1)
    /home/jeff/go/src/runtime/proc.go:191 +0x44 fp=0x10f1c7c4 sp=0x10f1c7a8
runtime.forcegchelper()
    /home/jeff/go/src/runtime/proc.go:152 +0xa8 fp=0x10f1c7dc sp=0x10f1c7c4
runtime.goexit()
    /home/jeff/go/src/runtime/asm_arm.s:1031 +0x4 fp=0x10f1c7dc sp=0x10f1c7dc
created by runtime.init.4
    /home/jeff/go/src/runtime/proc.go:141 +0x24

goroutine 3 [GC sweep wait]:
runtime.gopark(0xa70968, 0xce7648, 0x945ca8, 0xd, 0x81714, 0x1)
    /home/jeff/go/src/runtime/proc.go:185 +0x148 fp=0x10f1cf9c sp=0x10f1cf88
runtime.goparkunlock(0xce7648, 0x945ca8, 0xd, 0x14, 0x1)
    /home/jeff/go/src/runtime/proc.go:191 +0x44 fp=0x10f1cfb8 sp=0x10f1cf9c
runtime.bgsweep(0x10f12040)
    /home/jeff/go/src/runtime/mgcsweep.go:67 +0x13c fp=0x10f1cfd4 sp=0x10f1cfb8
runtime.goexit()
    /home/jeff/go/src/runtime/asm_arm.s:1031 +0x4 fp=0x10f1cfd4 sp=0x10f1cfd4
created by runtime.gcenable
    /home/jeff/go/src/runtime/mgc.go:205 +0x4c

goroutine 4 [finalizer wait]:
runtime.gopark(0xa70968, 0xcfd5b0, 0x94b6b8, 0xe, 0x14, 0x1)
    /home/jeff/go/src/runtime/proc.go:185 +0x148 fp=0x10f1d788 sp=0x10f1d774
runtime.goparkunlock(0xcfd5b0, 0x94b6b8, 0xe, 0x14, 0x1)
    /home/jeff/go/src/runtime/proc.go:191 +0x44 fp=0x10f1d7a4 sp=0x10f1d788
runtime.runfinq()
    /home/jeff/go/src/runtime/mfinal.go:154 +0xa4 fp=0x10f1d7dc sp=0x10f1d7a4
runtime.goexit()
    /home/jeff/go/src/runtime/asm_arm.s:1031 +0x4 fp=0x10f1d7dc sp=0x10f1d7dc
created by runtime.createfing
    /home/jeff/go/src/runtime/mfinal.go:135 +0x5c

goroutine 5 [syscall, 3810 minutes]:
runtime.notetsleepg(0xcfd940, 0xffffffff, 0xffffffff, 0x1)
    /home/jeff/go/src/runtime/lock_futex.go:202 +0x4c fp=0x10f1df98 sp=0x10f1df80
runtime.signal_recv(0x0)
    /home/jeff/go/src/runtime/sigqueue.go:111 +0x190 fp=0x10f1dfb8 sp=0x10f1df98
os/signal.loop()
    /home/jeff/go/src/os/signal/signal_unix.go:22 +0x14 fp=0x10f1dfdc sp=0x10f1dfb8
runtime.goexit()
    /home/jeff/go/src/runtime/asm_arm.s:1031 +0x4 fp=0x10f1dfdc sp=0x10f1dfdc
created by os/signal.init.1
    /home/jeff/go/src/os/signal/signal_unix.go:28 +0x30

goroutine 34 [select, 3810 minutes]:
runtime.gopark(0xa70984, 0x10f19700, 0x8ff6a0, 0x6, 0xcfd518, 0x2)
    /home/jeff/go/src/runtime/proc.go:185 +0x148 fp=0x10f195dc sp=0x10f195c8
runtime.selectgoImpl(0x10f19700, 0x0, 0xc)
    /home/jeff/go/src/runtime/select.go:392 +0x14d4 fp=0x10f196b8 sp=0x10f195dc
runtime.selectgo(0x10f19700)
    /home/jeff/go/src/runtime/select.go:212 +0x10 fp=0x10f196c8 sp=0x10f196b8
sm/discovery.respondUntilError(0xb28b5020, 0x1102c020, 0x11032018, 0x3039, 0xb6a41200, 0x0, 0x0)
    /home/jeff/katamari/go/src/sm/discovery/responder.go:93 +0x288 fp=0x10f19750 sp=0x10f196c8
sm/discovery.RespondBytesOnPort(0xb28b5020, 0x1102c020, 0x11032018, 0x3039)
    /home/jeff/katamari/go/src/sm/discovery/responder.go:63 +0x78 fp=0x10f19798 sp=0x10f19750
sm/discovery.RespondOnPort(0xb28b5020, 0x1102c020, 0x11032010, 0x3039)
    /home/jeff/katamari/go/src/sm/discovery/responder.go:51 +0x40 fp=0x10f197ac sp=0x10f19798
sm/flud/discovery.(*ResponderProtocol).Run.func1(0x10f0ab10, 0xb28b5020, 0x1102c020)
    /home/jeff/katamari/go/src/sm/flud/discovery/discovery.go:67 +0xe8 fp=0x10f197cc sp=0x10f197ac
runtime.goexit()
    /home/jeff/go/src/runtime/asm_arm.s:1031 +0x4 fp=0x10f197cc sp=0x10f197cc
created by sm/flud/discovery.(*ResponderProtocol).Run
    /home/jeff/katamari/go/src/sm/flud/discovery/discovery.go:72 +0x160

goroutine 11 [select, 3810 minutes]:
runtime.gopark(0xa70984, 0x10f1ef80, 0x8ff6a0, 0x6, 0x51818, 0x2)
    /home/jeff/go/src/runtime/proc.go:185 +0x148 fp=0x10f1ee70 sp=0x10f1ee5c
runtime.selectgoImpl(0x10f1ef80, 0x0, 0xc)
    /home/jeff/go/src/runtime/select.go:392 +0x14d4 fp=0x10f1ef4c sp=0x10f1ee70
runtime.selectgo(0x10f1ef80)
    /home/jeff/go/src/runtime/select.go:212 +0x10 fp=0x10f1ef5c sp=0x10f1ef4c
sm/space/utils/godump.platformListenAndDump()
    /home/jeff/katamari/go/src/sm/space/utils/godump/godump_others.go:24 +0x124 fp=0x10f1efd0 sp=0x10f1ef5c
sm/space/utils/godump.listenAndDump()
    /home/jeff/katamari/go/src/sm/space/utils/godump/godump.go:35 +0x3c fp=0x10f1efdc sp=0x10f1efd0
runtime.goexit()
    /home/jeff/go/src/runtime/asm_arm.s:1031 +0x4 fp=0x10f1efdc sp=0x10f1efdc
created by sm/space/utils/godump.init.1
    /home/jeff/katamari/go/src/sm/space/utils/godump/godump.go:25 +0x24

goroutine 12 [select, 3810 minutes, locked to thread]:
runtime.gopark(0xa70984, 0x10f1f78c, 0x8ff6a0, 0x6, 0x56318, 0x2)
    /home/jeff/go/src/runtime/proc.go:185 +0x148 fp=0x10f1f674 sp=0x10f1f660
runtime.selectgoImpl(0x10f1f78c, 0x0, 0xc)
    /home/jeff/go/src/runtime/select.go:392 +0x14d4 fp=0x10f1f750 sp=0x10f1f674
runtime.selectgo(0x10f1f78c)
    /home/jeff/go/src/runtime/select.go:212 +0x10 fp=0x10f1f760 sp=0x10f1f750
runtime.ensureSigM.func1()
    /home/jeff/go/src/runtime/signal1_unix.go:227 +0x428 fp=0x10f1f7dc sp=0x10f1f760
runtime.goexit()
    /home/jeff/go/src/runtime/asm_arm.s:1031 +0x4 fp=0x10f1f7dc sp=0x10f1f7dc
created by runtime.ensureSigM
    /home/jeff/go/src/runtime/signal1_unix.go:240 +0xe4

goroutine 14 [syscall, 3810 minutes]:
syscall.Syscall6(0x72, 0x4377, 0x10f19eb0, 0x0, 0x1104e000, 0x0, 0x0, 0x803c8, 0xb6a414b8, 0x6)
    /home/jeff/go/src/syscall/asm_linux_arm.s:48 +0x8 fp=0x10f19e64 sp=0x10f19e60
syscall.wait4(0x4377, 0x10f19eb0, 0x0, 0x1104e000, 0x50, 0x0, 0x0)
    /home/jeff/go/src/syscall/zsyscall_linux_arm.go:172 +0x64 fp=0x10f19e90 sp=0x10f19e64
syscall.Wait4(0x4377, 0x10f19ed4, 0x0, 0x1104e000, 0x0, 0x0, 0x0)
    /home/jeff/go/src/syscall/syscall_linux.go:256 +0x54 fp=0x10f19eb4 sp=0x10f19e90
os.(*Process).wait(0x11060240, 0x0, 0x0, 0x0)
    /home/jeff/go/src/os/exec_unix.go:22 +0xcc fp=0x10f19f0c sp=0x10f19eb4
os.(*Process).Wait(0x11060240, 0x0, 0x0, 0x0)
    /home/jeff/go/src/os/doc.go:45 +0x2c fp=0x10f19f20 sp=0x10f19f0c
os/exec.(*Cmd).Wait(0x10f56140, 0x0, 0x0)
    /home/jeff/go/src/os/exec/exec.go:380 +0x1b4 fp=0x10f19f88 sp=0x10f19f20
github.com/spacemonkeygo/spacelog.CaptureOutputToProcess.func1(0x10f56140)
    /home/jeff/katamari/go/src/github.com/spacemonkeygo/spacelog/capture.go:61 +0x1c fp=0x10f19fd4 sp=0x10f19f88
runtime.goexit()
    /home/jeff/go/src/runtime/asm_arm.s:1031 +0x4 fp=0x10f19fd4 sp=0x10f19fd4
created by github.com/spacemonkeygo/spacelog.CaptureOutputToProcess
    /home/jeff/katamari/go/src/github.com/spacemonkeygo/spacelog/capture.go:65 +0x204

goroutine 35 [IO wait]:
runtime.gopark(0xa7094c, 0xb6148424, 0x8f8fc8, 0x7, 0x1b, 0x5)
    /home/jeff/go/src/runtime/proc.go:185 +0x148 fp=0x10f2edd8 sp=0x10f2edc4
runtime.netpollblock(0xb6148410, 0x72, 0x0, 0x34234)
    /home/jeff/go/src/runtime/netpoll.go:338 +0x178 fp=0x10f2edfc sp=0x10f2edd8
net.runtime_pollWait(0xb6148410, 0x72, 0x10f0e060)
    /home/jeff/go/src/runtime/netpoll.go:157 +0x60 fp=0x10f2ee10 sp=0x10f2edfc
net.(*pollDesc).Wait(0x10f121b8, 0x72, 0x0, 0x0)
    /home/jeff/go/src/net/fd_poll_runtime.go:73 +0x34 fp=0x10f2ee20 sp=0x10f2ee10
net.(*pollDesc).WaitRead(0x10f121b8, 0x0, 0x0)
    /home/jeff/go/src/net/fd_poll_runtime.go:78 +0x30 fp=0x10f2ee34 sp=0x10f2ee20
net.(*netFD).readFrom(0x10f12180, 0x10f70a00, 0x80, 0x80, 0x0, 0x0, 0x0, 0xb6141030, 0x10f0e060)
    /home/jeff/go/src/net/fd_unix.go:259 +0x20c fp=0x10f2eea8 sp=0x10f2ee34
net.(*UDPConn).ReadFromUDP(0x11032020, 0x10f70a00, 0x80, 0x80, 0x0, 0x10f70a00, 0x0, 0x0)
    /home/jeff/go/src/net/udpsock_posix.go:61 +0xe4 fp=0x10f2ef18 sp=0x10f2eea8
sm/discovery.handleRequest(0xb28b5090, 0x11032020, 0x11032018, 0x0, 0x0)
    /home/jeff/katamari/go/src/sm/discovery/responder.go:117 +0x80 fp=0x10f2ef8c sp=0x10f2ef18
sm/discovery.handleRequests(0xb28b5090, 0x11032020, 0x11032018, 0x0, 0x0)
    /home/jeff/katamari/go/src/sm/discovery/responder.go:107 +0x44 fp=0x10f2efa4 sp=0x10f2ef8c
sm/discovery.respondUntilError.func1(0x10f122c0, 0xb28b5090, 0x11032020, 0x11032018)
    /home/jeff/katamari/go/src/sm/discovery/responder.go:89 +0x2c fp=0x10f2efc4 sp=0x10f2efa4
runtime.goexit()

I'll see if I can start running it with GODEBUG=gccheckmark=1. Is there anything in particular I should be observing with that flag?

@aclements
Copy link
Member

It is an ARMv5 in the sense that no binaries will run on it if I don't specify GOARM=5.

I believe the default is GOARM=6, so if it doesn't run with the default, you must have ARMv5. (I ask because ARM made a mess of its concurrency primitives, so it's basically impossible to run a multithreaded binary compiled for ARM v5 correctly on ARM v7 hardware.)

I'll see if I can start running it with GODEBUG=gccheckmark=1. Is there anything in particular I should be observing with that flag?

Panics. :) This enables an assertion in the runtime, so if it fails, it will panic with a bunch of debugging info.

@jtsylve
Copy link
Contributor

jtsylve commented Aug 13, 2015

I'm seeing the same thing on Go 1.5rc1 on Darwin x86_64 with no such error on Go 1.4.2

runtime:objectstart Span weird: p=0xc830fca000 k=0x64187e5 s.start=0xc830fca000 s.limit=0x0 s.state=2
fatal error: objectstart: bad pointer in unexpected span

runtime stack:
runtime.throw(0x42a56a0, 0x2b)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/panic.go:527 +0x90
runtime.heapBitsForObject(0xc830fca000, 0x0, 0x0, 0xc800000000, 0x923c2c0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/mbitmap.go:214 +0x28c
runtime.scanobject(0xc823282d20, 0xc82001e720)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/mgcmark.go:863 +0x232
runtime.gcDrainN(0xc82001e720, 0x1bee3)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/mgcmark.go:764 +0x8e
runtime.gcAssistAlloc.func1()
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/mgcmark.go:232 +0x172
runtime.systemstack(0xc82001d500)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/asm_amd64.s:262 +0x79
runtime.mstart()
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/proc1.go:674

goroutine 76 [running]:
runtime.systemstack_switch()
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/asm_amd64.s:216 fp=0xc82475b378 sp=0xc82475b370
runtime.gcAssistAlloc(0x12000, 0xc82048ca01)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/mgcmark.go:272 +0x1f8 fp=0xc82475b3d8 sp=0xc82475b378
runtime.mallocgc(0x12000, 0x41e8fe0, 0x1, 0x8000)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/malloc.go:711 +0x535 fp=0xc82475b4a8 sp=0xc82475b3d8
runtime.newarray(0x41e8fe0, 0x10200, 0xc82475b548)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/malloc.go:777 +0xc9 fp=0xc82475b4e8 sp=0xc82475b4a8
runtime.makeslice(0x41e0400, 0x10200, 0x10200, 0x0, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/slice.go:32 +0x165 fp=0xc82475b538 sp=0xc82475b4e8
bytes.makeSlice(0x10200, 0x0, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/bytes/buffer.go:195 +0x64 fp=0xc82475b588 sp=0xc82475b538
bytes.(*Buffer).ReadFrom(0xc82d77bd50, 0x5148928, 0xc825320bc0, 0x8000, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/bytes/buffer.go:167 +0xd3 fp=0xc82475b638 sp=0xc82475b588
io.copyBuffer(0x5148690, 0xc82d77bd50, 0x5148928, 0xc825320bc0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/io/io.go:375 +0x180 fp=0xc82475b6f8 sp=0xc82475b638
io.Copy(0x5148690, 0xc82d77bd50, 0x5148928, 0xc825320bc0, 0xc8204a2900, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/io/io.go:351 +0x64 fp=0xc82475b750 sp=0xc82475b6f8
io.CopyN(0x5148690, 0xc82d77bd50, 0x47a42b0, 0xc82268a020, 0x8000, 0x8000, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/io/io.go:327 +0xf7 fp=0xc82475b7d0 sp=0xc82475b750
go4n6/compress/zlib.(*reader).Read(0xc823282dc0, 0xc82dd06000, 0x8000, 0x8000, 0x0, 0x0, 0x0)
    /Users/joe/go/src/go4n6/compress/zlib/zlib.go:75 +0x198 fp=0xc82475b8e8 sp=0xc82475b7d0
io.(*LimitedReader).Read(0xc825320ba0, 0xc82dd06000, 0x8000, 0x8000, 0x407cc90, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/io/io.go:427 +0xbd fp=0xc82475b938 sp=0xc82475b8e8
bytes.(*Buffer).ReadFrom(0xc82d77bce0, 0x5148928, 0xc825320ba0, 0x0, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/bytes/buffer.go:173 +0x23f fp=0xc82475b9e8 sp=0xc82475b938
io.copyBuffer(0x5148690, 0xc82d77bce0, 0x5148928, 0xc825320ba0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/io/io.go:375 +0x180 fp=0xc82475baa8 sp=0xc82475b9e8
io.Copy(0x5148690, 0xc82d77bce0, 0x5148928, 0xc825320ba0, 0xc8204a2900, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/io/io.go:351 +0x64 fp=0xc82475bb00 sp=0xc82475baa8
io.CopyN(0x5148690, 0xc82d77bce0, 0x5148828, 0xc823282dc0, 0x8000, 0x8000, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/io/io.go:327 +0xf7 fp=0xc82475bb80 sp=0xc82475bb00
go4n6/disk/ewf.decompress(0x51487c8, 0xc82268a020, 0x18eef, 0x4255fe0, 0xc820094000, 0x0, 0x0, 0x0, 0x0, 0x0)
    /Users/joe/go/src/go4n6/disk/ewf/segment.go:279 +0x408 fp=0xc82475be80 sp=0xc82475bb80
go4n6/ioutil.(*LookaheadReader).start.func1(0xc821df8d50, 0xc820806000, 0x1)
    /Users/joe/go/src/go4n6/ioutil/lookahead.go:325 +0x3f8 fp=0xc82475bf88 sp=0xc82475be80
runtime.goexit()
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/asm_amd64.s:1696 +0x1 fp=0xc82475bf90 sp=0xc82475bf88
created by go4n6/ioutil.(*LookaheadReader).start
    /Users/joe/go/src/go4n6/ioutil/lookahead.go:333 +0x94

...

@jtsylve
Copy link
Contributor

jtsylve commented Aug 13, 2015

Full stack trace (Not sure it'll help without the source)

runtime:objectstart Span weird: p=0xc827f70000 k=0x6413fb8 s.start=0xc827f70000 s.limit=0x0 s.state=2
fatal error: objectstart: bad pointer in unexpected span

runtime stack:
runtime.throw(0x42a56a0, 0x2b)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/panic.go:527 +0x90
runtime.heapBitsForObject(0xc827f70000, 0x0, 0x0, 0xc800000000, 0x9405180)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/mbitmap.go:214 +0x28c
runtime.scanobject(0xc82b341720, 0xc820026720)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/mgcmark.go:863 +0x232
runtime.gcDrainN(0xc820026720, 0x8bc7)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/mgcmark.go:764 +0x8e
runtime.gcAssistAlloc.func1()
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/mgcmark.go:232 +0x172
runtime.systemstack(0xc82001ea00)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/asm_amd64.s:262 +0x79
runtime.mstart()
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/proc1.go:674

goroutine 75 [running]:
runtime.systemstack_switch()
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/asm_amd64.s:216 fp=0xc827dd9610 sp=0xc827dd9608
runtime.gcAssistAlloc(0x8000, 0x407cc01)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/mgcmark.go:272 +0x1f8 fp=0xc827dd9670 sp=0xc827dd9610
runtime.mallocgc(0x8000, 0x41e8fe0, 0x1, 0xc820032900)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/malloc.go:711 +0x535 fp=0xc827dd9740 sp=0xc827dd9670
runtime.newarray(0x41e8fe0, 0x8000, 0xc827dd97d0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/malloc.go:777 +0xc9 fp=0xc827dd9780 sp=0xc827dd9740
runtime.makeslice(0x41e0400, 0x0, 0x8000, 0x0, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/slice.go:32 +0x165 fp=0xc827dd97d0 sp=0xc827dd9780
go4n6/compress/zlib.(*reader).Read(0xc824739b80, 0xc827fd6000, 0x8000, 0x8000, 0x0, 0x0, 0x0)
    /Users/joe/go/src/go4n6/compress/zlib/zlib.go:73 +0xab fp=0xc827dd98e8 sp=0xc827dd97d0
io.(*LimitedReader).Read(0xc821dd9680, 0xc827fd6000, 0x8000, 0x8000, 0x407cca0, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/io/io.go:427 +0xbd fp=0xc827dd9938 sp=0xc827dd98e8
bytes.(*Buffer).ReadFrom(0xc82490ec40, 0x47b4da0, 0xc821dd9680, 0x0, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/bytes/buffer.go:173 +0x23f fp=0xc827dd99e8 sp=0xc827dd9938
io.copyBuffer(0x47b4bb8, 0xc82490ec40, 0x47b4da0, 0xc821dd9680, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/io/io.go:375 +0x180 fp=0xc827dd9aa8 sp=0xc827dd99e8
io.Copy(0x47b4bb8, 0xc82490ec40, 0x47b4da0, 0xc821dd9680, 0xc82047a000, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/io/io.go:351 +0x64 fp=0xc827dd9b00 sp=0xc827dd9aa8
io.CopyN(0x47b4bb8, 0xc82490ec40, 0x47b4d50, 0xc824739b80, 0x8000, 0x8000, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/io/io.go:327 +0xf7 fp=0xc827dd9b80 sp=0xc827dd9b00
go4n6/disk/ewf.decompress(0x47b4cf0, 0xc8219be060, 0x18a75, 0x4255fe0, 0xc820094000, 0x0, 0x0, 0x0, 0x0, 0x0)
    /Users/joe/go/src/go4n6/disk/ewf/segment.go:279 +0x408 fp=0xc827dd9e80 sp=0xc827dd9b80
go4n6/ioutil.(*LookaheadReader).start.func1(0xc821decc00, 0xc8207e6000, 0x0)
    /Users/joe/go/src/go4n6/ioutil/lookahead.go:325 +0x3f8 fp=0xc827dd9f88 sp=0xc827dd9e80
runtime.goexit()
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/asm_amd64.s:1696 +0x1 fp=0xc827dd9f90 sp=0xc827dd9f88
created by go4n6/ioutil.(*LookaheadReader).start
    /Users/joe/go/src/go4n6/ioutil/lookahead.go:333 +0x94

goroutine 1 [chan receive]:
go4n6/file/mft.(*MFT).Decode(0xc8227065a0, 0x51d42f8, 0xc822706570, 0x0, 0x0)
    /Users/joe/go/src/go4n6/file/mft/mft.go:224 +0x166
go4n6/fs/ntfs.(*NTFS).Entries(0xc821deaea0, 0xc822706101, 0x0, 0x0, 0x0, 0x0, 0x0)
    /Users/joe/go/src/go4n6/fs/ntfs/ntfs.go:130 +0x97
main.main()
    /Users/joe/src/ntfstest.go:43 +0x990

goroutine 17 [syscall, locked to thread]:
runtime.goexit()
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/asm_amd64.s:1696 +0x1

goroutine 101 [chan receive]:
go4n6/file/mft.(*MFT).decodeEntries.func1(0xc8205b8050, 0xc82001a120, 0xc8227065a0, 0xc82001a0c0)
    /Users/joe/go/src/go4n6/file/mft/entry.go:80 +0x79
created by go4n6/file/mft.(*MFT).decodeEntries
    /Users/joe/go/src/go4n6/file/mft/entry.go:86 +0x109

goroutine 99 [runnable]:
go4n6/ioutil.(*LookaheadReader).Get(0xc8207e6000, 0x18a6b, 0x0, 0x0, 0x0, 0x0, 0x0)
    /Users/joe/go/src/go4n6/ioutil/lookahead.go:161 +0x443
go4n6/disk/ewf.(*segment).Read(0xc820094000, 0xc82ac7f000, 0x5bb000, 0x5bb000, 0x8000, 0x0, 0x0)
    /Users/joe/go/src/go4n6/disk/ewf/segment.go:114 +0x1ea
go4n6/ioutil.(*MultiReadSeeker).Read(0xc820014900, 0xc82ac7f000, 0x5bb000, 0x5bb000, 0xc5358000, 0x0, 0x0)
    /Users/joe/go/src/go4n6/ioutil/multi.go:90 +0x204
go4n6/disk/ewf.(*Reader).Read(0xc820012410, 0xc82ac7f000, 0x5bb000, 0x5bb000, 0x0, 0x0, 0x0)
    <autogenerated>:6 +0x82
github.com/badgerodon/ioutil.(*SectionReader).Read(0xc822706180, 0xc82ac7f000, 0x5bb000, 0x5bb000, 0x0, 0x0, 0x0)
    /Users/joe/go/src/github.com/badgerodon/ioutil/section.go:41 +0x120
go4n6/partition/mbr.Partition.Read(0x5380100, 0xc822706180, 0xc8200866c0, 0xfffffe0700212080, 0x27ff00000000800, 0xc82ac7f000, 0x5bb000, 0x5bb000, 0xc5258000, 0x0, ...)
    /Users/joe/go/src/go4n6/partition/mbr/partition.go:388 +0x6d
go4n6/partition/mbr.(*Partition).Read(0xc8227061b0, 0xc82ac7f000, 0x5bb000, 0x5bb000, 0x0, 0x0, 0x0)
    <autogenerated>:4 +0xc8
github.com/badgerodon/ioutil.(*SectionReader).Read(0xc8227064e0, 0xc82ac7f000, 0x5bb000, 0x5bb000, 0x0, 0x0, 0x0)
    /Users/joe/go/src/github.com/badgerodon/ioutil/section.go:41 +0x120
github.com/badgerodon/ioutil.(*MultiReadSeeker).Read(0xc822706540, 0xc82ac7f000, 0x5bb000, 0x5bb000, 0x8000, 0x0, 0x0)
    /Users/joe/go/src/github.com/badgerodon/ioutil/multi.go:39 +0x204
go4n6/ioutil.(*MultiRangeReadSeeker).Read(0xc822706570, 0xc82ac7f000, 0x5bb000, 0x5bb000, 0x8000, 0x0, 0x0)
    <autogenerated>:24 +0x82
io.(*LimitedReader).Read(0xc821c727e0, 0xc82ac7f000, 0x5bb000, 0x5bb000, 0x8000, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/io/io.go:427 +0xbd
bytes.(*Buffer).ReadFrom(0xc826ce58f0, 0x47b4da0, 0xc821c727e0, 0x445000, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/bytes/buffer.go:173 +0x23f
io.copyBuffer(0x47b4bb8, 0xc826ce58f0, 0x47b4da0, 0xc821c727e0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/io/io.go:375 +0x180
io.Copy(0x47b4bb8, 0xc826ce58f0, 0x47b4da0, 0xc821c727e0, 0x4600e28, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/io/io.go:351 +0x64
io.CopyN(0x47b4bb8, 0xc826ce58f0, 0x51d42f8, 0xc822706570, 0xa00000, 0xa00000, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/io/io.go:327 +0xf7
go4n6/file/mft.(*MFT).decodeEntries(0xc8227065a0, 0x51d42f8, 0xc822706570, 0xc82001a0c0)
    /Users/joe/go/src/go4n6/file/mft/entry.go:92 +0x22f
created by go4n6/file/mft.(*MFT).Decode
    /Users/joe/go/src/go4n6/file/mft/mft.go:221 +0x123

goroutine 74 [semacquire]:
sync.runtime_Semacquire(0xc821decc0c)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/sema.go:43 +0x26
sync.(*WaitGroup).Wait(0xc821decc00)
    /usr/local/Cellar/go/1.5rc1/libexec/src/sync/waitgroup.go:126 +0xb4
go4n6/ioutil.(*LookaheadReader).start(0xc8207e6000)
    /Users/joe/go/src/go4n6/ioutil/lookahead.go:337 +0xbc
created by go4n6/ioutil.(*LookaheadReader).Get
    /Users/joe/go/src/go4n6/ioutil/lookahead.go:140 +0x1ec

goroutine 77 [runnable, locked to thread]:
go4n6/compress/zlib._Cfunc_inflate(0xc82b3417e8, 0xc800000000, 0x1)
    ??:0 +0x39
go4n6/compress/zlib.(*reader).Read(0xc82b3417c0, 0xc82636c000, 0x8000, 0x8000, 0x0, 0x0, 0x0)
    /Users/joe/go/src/go4n6/compress/zlib/zlib.go:99 +0x3d4
io.(*LimitedReader).Read(0xc825023cc0, 0xc82636c000, 0x8000, 0x8000, 0x407cca0, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/io/io.go:427 +0xbd
bytes.(*Buffer).ReadFrom(0xc824b64e70, 0x47b4da0, 0xc825023cc0, 0x0, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/bytes/buffer.go:173 +0x23f
io.copyBuffer(0x47b4bb8, 0xc824b64e70, 0x47b4da0, 0xc825023cc0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/io/io.go:375 +0x180
io.Copy(0x47b4bb8, 0xc824b64e70, 0x47b4da0, 0xc825023cc0, 0xc82048e900, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/io/io.go:351 +0x64
io.CopyN(0x47b4bb8, 0xc824b64e70, 0x47b4d50, 0xc82b3417c0, 0x8000, 0x8000, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/io/io.go:327 +0xf7
go4n6/disk/ewf.decompress(0x47b4cf0, 0xc8219bc120, 0x18a79, 0x4255fe0, 0xc820094000, 0x0, 0x0, 0x0, 0x0, 0x0)
    /Users/joe/go/src/go4n6/disk/ewf/segment.go:279 +0x408
go4n6/ioutil.(*LookaheadReader).start.func1(0xc821decc00, 0xc8207e6000, 0x2)
    /Users/joe/go/src/go4n6/ioutil/lookahead.go:325 +0x3f8
created by go4n6/ioutil.(*LookaheadReader).start
    /Users/joe/go/src/go4n6/ioutil/lookahead.go:333 +0x94

goroutine 76 [runnable]:
bytes.makeSlice.func1()
    /usr/local/Cellar/go/1.5rc1/libexec/src/bytes/buffer.go:190
bytes.makeSlice(0x10200, 0xc824076000, 0x10200, 0x10200)
    /usr/local/Cellar/go/1.5rc1/libexec/src/bytes/buffer.go:195 +0x92
bytes.(*Buffer).ReadFrom(0xc824598460, 0x47b4da0, 0xc821c73240, 0x8000, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/bytes/buffer.go:167 +0xd3
io.copyBuffer(0x47b4bb8, 0xc824598460, 0x47b4da0, 0xc821c73240, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/io/io.go:375 +0x180
io.Copy(0x47b4bb8, 0xc824598460, 0x47b4da0, 0xc821c73240, 0xc820032900, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/io/io.go:351 +0x64
io.CopyN(0x47b4bb8, 0xc824598460, 0x47a42b0, 0xc822686020, 0x8000, 0x8000, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/io/io.go:327 +0xf7
go4n6/compress/zlib.(*reader).Read(0xc82487f220, 0xc827d9c000, 0x8000, 0x8000, 0x0, 0x0, 0x0)
    /Users/joe/go/src/go4n6/compress/zlib/zlib.go:75 +0x198
io.(*LimitedReader).Read(0xc825023c40, 0xc827d9c000, 0x8000, 0x8000, 0x407cca0, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/io/io.go:427 +0xbd
bytes.(*Buffer).ReadFrom(0xc824b64cb0, 0x47b4da0, 0xc825023c40, 0x0, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/bytes/buffer.go:173 +0x23f
io.copyBuffer(0x47b4bb8, 0xc824b64cb0, 0x47b4da0, 0xc825023c40, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/io/io.go:375 +0x180
io.Copy(0x47b4bb8, 0xc824b64cb0, 0x47b4da0, 0xc825023c40, 0xc82048e900, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/io/io.go:351 +0x64
io.CopyN(0x47b4bb8, 0xc824b64cb0, 0x47b4d50, 0xc82487f220, 0x8000, 0x8000, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/io/io.go:327 +0xf7
go4n6/disk/ewf.decompress(0x47b4cf0, 0xc822686020, 0x18a74, 0x4255fe0, 0xc820094000, 0x0, 0x0, 0x0, 0x0, 0x0)
    /Users/joe/go/src/go4n6/disk/ewf/segment.go:279 +0x408
go4n6/ioutil.(*LookaheadReader).start.func1(0xc821decc00, 0xc8207e6000, 0x1)
    /Users/joe/go/src/go4n6/ioutil/lookahead.go:325 +0x3f8
created by go4n6/ioutil.(*LookaheadReader).start
    /Users/joe/go/src/go4n6/ioutil/lookahead.go:333 +0x94

goroutine 80 [runnable]:
go4n6/compress/zlib.(*reader).Read(0xc82b341540, 0xc828f26000, 0x8000, 0x8000, 0x0, 0x0, 0x0)
    /Users/joe/go/src/go4n6/compress/zlib/zlib.go:73 +0xe2
io.(*LimitedReader).Read(0xc825023b40, 0xc828f26000, 0x8000, 0x8000, 0x407cca0, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/io/io.go:427 +0xbd
bytes.(*Buffer).ReadFrom(0xc824b64af0, 0x47b4da0, 0xc825023b40, 0x0, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/bytes/buffer.go:173 +0x23f
io.copyBuffer(0x47b4bb8, 0xc824b64af0, 0x47b4da0, 0xc825023b40, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/io/io.go:375 +0x180
io.Copy(0x47b4bb8, 0xc824b64af0, 0x47b4da0, 0xc825023b40, 0xc82047a000, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/io/io.go:351 +0x64
io.CopyN(0x47b4bb8, 0xc824b64af0, 0x47b4d50, 0xc82b341540, 0x8000, 0x8000, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/io/io.go:327 +0xf7
go4n6/disk/ewf.decompress(0x47b4cf0, 0xc822690020, 0x18a6d, 0x4255fe0, 0xc820094000, 0x0, 0x0, 0x0, 0x0, 0x0)
    /Users/joe/go/src/go4n6/disk/ewf/segment.go:279 +0x408
go4n6/ioutil.(*LookaheadReader).start.func1(0xc821decc00, 0xc8207e6000, 0x5)
    /Users/joe/go/src/go4n6/ioutil/lookahead.go:325 +0x3f8
created by go4n6/ioutil.(*LookaheadReader).start
    /Users/joe/go/src/go4n6/ioutil/lookahead.go:333 +0x94

goroutine 79 [runnable]:
go4n6/compress/zlib.(*reader).Read(0xc824e86320, 0xc827ff8000, 0x8000, 0x8000, 0x0, 0x0, 0x0)
    /Users/joe/go/src/go4n6/compress/zlib/zlib.go:73 +0xe2
io.(*LimitedReader).Read(0xc8219bf960, 0xc827ff8000, 0x8000, 0x8000, 0x407cca0, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/io/io.go:427 +0xbd
bytes.(*Buffer).ReadFrom(0xc821a0c310, 0x47b4da0, 0xc8219bf960, 0x0, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/bytes/buffer.go:173 +0x23f
io.copyBuffer(0x47b4bb8, 0xc821a0c310, 0x47b4da0, 0xc8219bf960, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/io/io.go:375 +0x180
io.Copy(0x47b4bb8, 0xc821a0c310, 0x47b4da0, 0xc8219bf960, 0xc82048e000, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/io/io.go:351 +0x64
io.CopyN(0x47b4bb8, 0xc821a0c310, 0x47b4d50, 0xc824e86320, 0x8000, 0x8000, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/io/io.go:327 +0xf7
go4n6/disk/ewf.decompress(0x47b4cf0, 0xc82257d940, 0x18a76, 0x4255fe0, 0xc820094000, 0x0, 0x0, 0x0, 0x0, 0x0)
    /Users/joe/go/src/go4n6/disk/ewf/segment.go:279 +0x408
go4n6/ioutil.(*LookaheadReader).start.func1(0xc821decc00, 0xc8207e6000, 0x4)
    /Users/joe/go/src/go4n6/ioutil/lookahead.go:325 +0x3f8
created by go4n6/ioutil.(*LookaheadReader).start
    /Users/joe/go/src/go4n6/ioutil/lookahead.go:333 +0x94

goroutine 78 [runnable]:
go4n6/compress/zlib.(*reader).Read(0xc824e86280, 0xc823ca4000, 0x8000, 0x8000, 0x0, 0x0, 0x0)
    /Users/joe/go/src/go4n6/compress/zlib/zlib.go:73 +0xe2
io.(*LimitedReader).Read(0xc8219bf900, 0xc823ca4000, 0x8000, 0x8000, 0x407cca0, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/io/io.go:427 +0xbd
bytes.(*Buffer).ReadFrom(0xc821a0c230, 0x47b4da0, 0xc8219bf900, 0x0, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/bytes/buffer.go:173 +0x23f
io.copyBuffer(0x47b4bb8, 0xc821a0c230, 0x47b4da0, 0xc8219bf900, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/io/io.go:375 +0x180
io.Copy(0x47b4bb8, 0xc821a0c230, 0x47b4da0, 0xc8219bf900, 0xc82048e000, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/io/io.go:351 +0x64
io.CopyN(0x47b4bb8, 0xc821a0c230, 0x47b4d50, 0xc824e86280, 0x8000, 0x8000, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/io/io.go:327 +0xf7
go4n6/disk/ewf.decompress(0x47b4cf0, 0xc821d96160, 0x18a6b, 0x4255fe0, 0xc820094000, 0x0, 0x0, 0x0, 0x0, 0x0)
    /Users/joe/go/src/go4n6/disk/ewf/segment.go:279 +0x408
go4n6/ioutil.(*LookaheadReader).start.func1(0xc821decc00, 0xc8207e6000, 0x3)
    /Users/joe/go/src/go4n6/ioutil/lookahead.go:325 +0x3f8
created by go4n6/ioutil.(*LookaheadReader).start
    /Users/joe/go/src/go4n6/ioutil/lookahead.go:333 +0x94

goroutine 81 [runnable]:
go4n6/disk/ewf.decompress(0x47b4cf0, 0xc821deadc0, 0x18a77, 0x4255fe0, 0xc820094000, 0x0, 0x0, 0x0, 0x0, 0x0)
    /Users/joe/go/src/go4n6/disk/ewf/segment.go:278 +0x34b
go4n6/ioutil.(*LookaheadReader).start.func1(0xc821decc00, 0xc8207e6000, 0x6)
    /Users/joe/go/src/go4n6/ioutil/lookahead.go:325 +0x3f8
created by go4n6/ioutil.(*LookaheadReader).start
    /Users/joe/go/src/go4n6/ioutil/lookahead.go:333 +0x94

goroutine 104 [chan receive]:
go4n6/file/mft.(*MFT).decodeEntries.func1(0xc8205b8050, 0xc82001a120, 0xc8227065a0, 0xc82001a0c0)
    /Users/joe/go/src/go4n6/file/mft/entry.go:80 +0x79
created by go4n6/file/mft.(*MFT).decodeEntries
    /Users/joe/go/src/go4n6/file/mft/entry.go:86 +0x109

goroutine 103 [chan receive]:
go4n6/file/mft.(*MFT).decodeEntries.func1(0xc8205b8050, 0xc82001a120, 0xc8227065a0, 0xc82001a0c0)
    /Users/joe/go/src/go4n6/file/mft/entry.go:80 +0x79
created by go4n6/file/mft.(*MFT).decodeEntries
    /Users/joe/go/src/go4n6/file/mft/entry.go:86 +0x109

goroutine 102 [chan receive]:
go4n6/file/mft.(*MFT).decodeEntries.func1(0xc8205b8050, 0xc82001a120, 0xc8227065a0, 0xc82001a0c0)
    /Users/joe/go/src/go4n6/file/mft/entry.go:80 +0x79
created by go4n6/file/mft.(*MFT).decodeEntries
    /Users/joe/go/src/go4n6/file/mft/entry.go:86 +0x109

goroutine 105 [chan receive]:
go4n6/file/mft.(*MFT).decodeEntries.func1(0xc8205b8050, 0xc82001a120, 0xc8227065a0, 0xc82001a0c0)
    /Users/joe/go/src/go4n6/file/mft/entry.go:80 +0x79
created by go4n6/file/mft.(*MFT).decodeEntries
    /Users/joe/go/src/go4n6/file/mft/entry.go:86 +0x109

goroutine 100 [chan receive]:
go4n6/file/mft.(*MFT).decodeEntries.func1(0xc8205b8050, 0xc82001a120, 0xc8227065a0, 0xc82001a0c0)
    /Users/joe/go/src/go4n6/file/mft/entry.go:80 +0x79
created by go4n6/file/mft.(*MFT).decodeEntries
    /Users/joe/go/src/go4n6/file/mft/entry.go:86 +0x109

goroutine 106 [chan receive]:
go4n6/file/mft.(*MFT).decodeEntries.func1(0xc8205b8050, 0xc82001a120, 0xc8227065a0, 0xc82001a0c0)
    /Users/joe/go/src/go4n6/file/mft/entry.go:80 +0x79
created by go4n6/file/mft.(*MFT).decodeEntries
    /Users/joe/go/src/go4n6/file/mft/entry.go:86 +0x109

goroutine 107 [chan receive]:
go4n6/file/mft.(*MFT).decodeEntries.func1(0xc8205b8050, 0xc82001a120, 0xc8227065a0, 0xc82001a0c0)
    /Users/joe/go/src/go4n6/file/mft/entry.go:80 +0x79
created by go4n6/file/mft.(*MFT).decodeEntries
    /Users/joe/go/src/go4n6/file/mft/entry.go:86 +0x109
exit status 2

@jtsylve
Copy link
Contributor

jtsylve commented Aug 14, 2015

This also panics on HEAD, so the bug hasn't been fixed since rc1.

@aclements
Copy link
Member

@jtsylve, it looks like your problem is probably different, since it doesn't involve finalizers or dead spans, though it might be the same. The check that's failing is quite general.

Can you run and reproduce the problem with GODEBUG=gccheckmark=1? Also, it sounds like you can reproduce it fairly quickly. If that's right, I'd also like to know whether it happens with GODEBUG=gcstoptheworld=1,gcshrinkstackoff=1 and, if that stops it from happening, what happens with GODEBUG=gcstackbarrieroff=1.

Also, is there use of "unsafe" in your code? And is it possible to share the code or reduce it to a shareable test case?

@jtsylve
Copy link
Contributor

jtsylve commented Aug 14, 2015

Unfortunately I can't share the majority of the code and it's now a rather complicated codebase, so I'm not sure if I can reduce it to a POC to create the panic, but I'll see what I can do.

Bingo on the "unsafe" call. I'm using a custom Reader that uses zlib as a drop in replacement for compress/zlib (Because of performance). I get no such panic on compress/zlib I can at least share that code. (Although this did work fine on 1.4.2)

// #cgo LDFLAGS: -lz
// #include <zlib.h>
//
// // inflateInit is a macro so we need to do this
// int InflateInit(z_streamp s) {
//     return inflateInit(s);
// }
import "C"

import (
    "bytes"
    "errors"
    "io"
    "unsafe"
)

type reader struct {
    r     io.Reader
    inbuf []byte
    s     C.z_stream
}

// NewReader creates a new ReadCloser. Reads from the returned ReadCloser
// read and decompress data from r. The implementation buffers input and
// may read more data than necessary from r. It is the caller's
// responsibility to call Close on the ReadCloser when done.
func NewReader(r io.Reader) (io.ReadCloser, error) {
    rd := &reader{
        r: r,
    }

    err := C.InflateInit(&rd.s)
    if err != C.Z_OK {
        return nil, errors.New("Could not init inflate.")
    }

    return rd, nil
}

func (r *reader) Read(p []byte) (n int, err error) {
    if len(p) == 0 {
        return 0, nil
    }

    // We can assume that the input will be smaller than
    // output.
    maxIn := int64(len(p))

    if r.inbuf == nil {
        buf := bytes.NewBuffer(make([]byte, 0, maxIn))

        nIn, err := io.CopyN(buf, r.r, maxIn)
        if err != nil && err != io.EOF {
            return 0, err
        }

        if nIn == 0 && err == io.EOF {
            return 0, io.ErrUnexpectedEOF
        }

        r.s.avail_in = C.uInt(nIn)
        r.s.next_in = (*C.Bytef)(unsafe.Pointer(&buf.Bytes()[0]))
    } else {
        // We still have input from the last call
        r.s.avail_in = C.uInt(len(r.inbuf))
        r.s.next_in = (*C.Bytef)(unsafe.Pointer(&r.inbuf[0]))
    }

    var read int
    var ret C.int
    for ret != C.Z_STREAM_END {
        out := p[read:]
        r.s.avail_out = C.uInt(len(out))
        r.s.next_out = (*C.Bytef)(unsafe.Pointer(&out[0]))

        ret = C.inflate(&r.s, C.Z_NO_FLUSH)

        if ret != C.Z_STREAM_END && ret != C.Z_OK {
            return 0, errors.New("Could not deflate input.")
        }

        read = len(out) - int(r.s.avail_out)

        if r.s.avail_out == 0 {
            break
        }
    }

    if ret == C.Z_STREAM_END {
        return read, io.EOF
    }

    if r.s.avail_in == 0 {
        r.inbuf = nil
    } else {
        r.inbuf = C.GoBytes(unsafe.Pointer(r.s.next_in), C.int(r.s.avail_in))
    }

    return read, nil
}

// Close implements the io.Closer interface
//
// Calling Close does not close the wrapped io.Reader originally passed to NewReader
func (r *reader) Close() error {
    err := C.inflateEnd(&r.s)
    if err != C.Z_OK {
        return errors.New("Could not end inflate")
    }

    return nil
}

I'm not seeing much different in the outputs of setting those variables, but here they are. Perhaps I'm doing it wrong?

GODEBUG=gccheckmark=1 go run ntfstest.go

runtime:objectstart Span weird: p=0xc827a54000 k=0x6413d2a s.start=0xc827a54000 s.limit=0xc825cf5f80 s.state=2
fatal error: objectstart: bad pointer in unexpected span

goroutine 10 [running]:
runtime.throw(0x42a56a0, 0x2b)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/panic.go:527 +0x90 fp=0xc820028610 sp=0xc8200285f8
runtime.heapBitsForObject(0xc827a54000, 0x0, 0x0, 0xc800000000, 0x50a40e0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/mbitmap.go:214 +0x28c fp=0xc820028648 sp=0xc820028610
runtime.scanobject(0xc82588a6e0, 0xc820022720)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/mgcmark.go:863 +0x232 fp=0xc820028718 sp=0xc820028648
runtime.gcDrainUntilPreempt(0xc820022720, 0x7d0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/mgcmark.go:726 +0x152 fp=0xc820028750 sp=0xc820028718
runtime.gcBgMarkWorker(0xc820021500)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/mgc.go:1328 +0x474 fp=0xc8200287b8 sp=0xc820028750
runtime.goexit()
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/asm_amd64.s:1696 +0x1 fp=0xc8200287c0 sp=0xc8200287b8
created by runtime.gcBgMarkStartWorkers
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/mgc.go:1238 +0x93

goroutine 1 [chan receive]:
go4n6/file/mft.(*MFT).Decode(0xc820d683c0, 0x50047c8, 0xc820d68390, 0x0, 0x0)
    /Users/joe/go/src/go4n6/file/mft/mft.go:224 +0x166
go4n6/fs/ntfs.(*NTFS).Entries(0xc82223e280, 0xc8223c0101, 0x0, 0x0, 0x0, 0x0, 0x0)
    /Users/joe/go/src/go4n6/fs/ntfs/ntfs.go:130 +0x97
main.main()
    /Users/joe/src/ntfstest.go:43 +0x990

goroutine 17 [syscall, locked to thread]:
runtime.goexit()
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/asm_amd64.s:1696 +0x1

goroutine 100 [chan receive]:
go4n6/file/mft.(*MFT).decodeEntries.func1(0xc82254c960, 0xc82001a120, 0xc820d683c0, 0xc82001a0c0)
    /Users/joe/go/src/go4n6/file/mft/entry.go:80 +0x79
created by go4n6/file/mft.(*MFT).decodeEntries
    /Users/joe/go/src/go4n6/file/mft/entry.go:86 +0x109

goroutine 99 [runnable]:
go4n6/ioutil.(*LookaheadReader).Get(0xc82039e000, 0x18dca, 0x0, 0x0, 0x0, 0x0, 0x0)
    /Users/joe/go/src/go4n6/ioutil/lookahead.go:161 +0x443
go4n6/disk/ewf.(*segment).Read(0xc820094000, 0xc82afa1000, 0x145000, 0x145000, 0x8000, 0x0, 0x0)
    /Users/joe/go/src/go4n6/disk/ewf/segment.go:114 +0x1ea
go4n6/ioutil.(*MultiReadSeeker).Read(0xc820d3e120, 0xc82afa1000, 0x145000, 0x145000, 0xc6e50000, 0x0, 0x0)
    /Users/joe/go/src/go4n6/ioutil/multi.go:90 +0x204
go4n6/disk/ewf.(*Reader).Read(0xc8200123c0, 0xc82afa1000, 0x145000, 0x145000, 0x0, 0x0, 0x0)
    <autogenerated>:6 +0x82
github.com/badgerodon/ioutil.(*SectionReader).Read(0xc8223c0120, 0xc82afa1000, 0x145000, 0x145000, 0x0, 0x0, 0x0)
    /Users/joe/go/src/github.com/badgerodon/ioutil/section.go:41 +0x120
go4n6/partition/mbr.Partition.Read(0x5249700, 0xc8223c0120, 0xc820086240, 0xfffffe0700212080, 0x27ff00000000800, 0xc82afa1000, 0x145000, 0x145000, 0xc6d50000, 0x0, ...)
    /Users/joe/go/src/go4n6/partition/mbr/partition.go:388 +0x6d
go4n6/partition/mbr.(*Partition).Read(0xc8223c0150, 0xc82afa1000, 0x145000, 0x145000, 0x0, 0x0, 0x0)
    <autogenerated>:4 +0xc8
github.com/badgerodon/ioutil.(*SectionReader).Read(0xc820d68330, 0xc82afa1000, 0x145000, 0x145000, 0x0, 0x0, 0x0)
    /Users/joe/go/src/github.com/badgerodon/ioutil/section.go:41 +0x120
github.com/badgerodon/ioutil.(*MultiReadSeeker).Read(0xc820d68360, 0xc82afa1000, 0x145000, 0x145000, 0x8000, 0x0, 0x0)
    /Users/joe/go/src/github.com/badgerodon/ioutil/multi.go:39 +0x204
go4n6/ioutil.(*MultiRangeReadSeeker).Read(0xc820d68390, 0xc82afa1000, 0x145000, 0x145000, 0x8000, 0x0, 0x0)
    <autogenerated>:24 +0x82
io.(*LimitedReader).Read(0xc822ddc880, 0xc82afa1000, 0x145000, 0x145000, 0x8000, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/io/io.go:427 +0xbd
bytes.(*Buffer).ReadFrom(0xc8251db2d0, 0x47ad130, 0xc822ddc880, 0x8bb000, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/bytes/buffer.go:173 +0x23f
io.copyBuffer(0x47ad108, 0xc8251db2d0, 0x47ad130, 0xc822ddc880, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/io/io.go:375 +0x180
io.Copy(0x47ad108, 0xc8251db2d0, 0x47ad130, 0xc822ddc880, 0x4600000, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/io/io.go:351 +0x64
io.CopyN(0x47ad108, 0xc8251db2d0, 0x50047c8, 0xc820d68390, 0xa00000, 0xa00000, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/io/io.go:327 +0xf7
go4n6/file/mft.(*MFT).decodeEntries(0xc820d683c0, 0x50047c8, 0xc820d68390, 0xc82001a0c0)
    /Users/joe/go/src/go4n6/file/mft/entry.go:92 +0x22f
created by go4n6/file/mft.(*MFT).Decode
    /Users/joe/go/src/go4n6/file/mft/mft.go:221 +0x123

goroutine 90 [semacquire]:
sync.runtime_Semacquire(0xc82000b93c)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/sema.go:43 +0x26
sync.(*WaitGroup).Wait(0xc82000b930)
    /usr/local/Cellar/go/1.5rc1/libexec/src/sync/waitgroup.go:126 +0xb4
go4n6/ioutil.(*LookaheadReader).start(0xc82039e000)
    /Users/joe/go/src/go4n6/ioutil/lookahead.go:337 +0xbc
created by go4n6/ioutil.(*LookaheadReader).Get
    /Users/joe/go/src/go4n6/ioutil/lookahead.go:140 +0x1ec

goroutine 92 [sleep]:
time.Sleep(0x186a0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/time.go:59 +0xf9
time.Sleep(0x186a0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/time.go:53 +0x37
time.Sleep(0x186a0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/time.go:53 +0x37
go4n6/disk/ewf.decompress(0x47ad058, 0xc8222b2020, 0x18dcd, 0x4255fe0, 0xc820094000, 0x0, 0x0, 0x0, 0x0, 0x0)
    /Users/joe/go/src/go4n6/disk/ewf/segment.go:278 +0x314
go4n6/ioutil.(*LookaheadReader).start.func1(0xc82000b930, 0xc82039e000, 0x1)
    /Users/joe/go/src/go4n6/ioutil/lookahead.go:325 +0x3f8
created by go4n6/ioutil.(*LookaheadReader).start
    /Users/joe/go/src/go4n6/ioutil/lookahead.go:333 +0x94

goroutine 95 [runnable]:
time.Sleep(0x186a0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/time.go:48
bytes.makeSlice(0x10200, 0x0, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/bytes/buffer.go:195 +0x64
bytes.(*Buffer).ReadFrom(0xc82273f420, 0x47ad130, 0xc821be8180, 0x8000, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/bytes/buffer.go:167 +0xd3
io.copyBuffer(0x47ad108, 0xc82273f420, 0x47ad130, 0xc821be8180, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/io/io.go:375 +0x180
io.Copy(0x47ad108, 0xc82273f420, 0x47ad130, 0xc821be8180, 0xc820509680, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/io/io.go:351 +0x64
io.CopyN(0x47ad108, 0xc82273f420, 0x47a42b0, 0xc822244060, 0x8000, 0x8000, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/io/io.go:327 +0xf7
go4n6/compress/zlib.(*reader).Read(0xc82588a780, 0xc82328c000, 0x8000, 0x8000, 0x0, 0x0, 0x0)
    /Users/joe/go/src/go4n6/compress/zlib/zlib.go:75 +0x198
io.(*LimitedReader).Read(0xc821be8160, 0xc82328c000, 0x8000, 0x8000, 0x407cca0, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/io/io.go:427 +0xbd
bytes.(*Buffer).ReadFrom(0xc82273f3b0, 0x47ad130, 0xc821be8160, 0x0, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/bytes/buffer.go:173 +0x23f
io.copyBuffer(0x47ad108, 0xc82273f3b0, 0x47ad130, 0xc821be8160, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/io/io.go:375 +0x180
io.Copy(0x47ad108, 0xc82273f3b0, 0x47ad130, 0xc821be8160, 0xc820509680, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/io/io.go:351 +0x64
io.CopyN(0x47ad108, 0xc82273f3b0, 0x47ad0b8, 0xc82588a780, 0x8000, 0x8000, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/io/io.go:327 +0xf7
go4n6/disk/ewf.decompress(0x47ad058, 0xc822244060, 0x18ddd, 0x4255fe0, 0xc820094000, 0x0, 0x0, 0x0, 0x0, 0x0)
    /Users/joe/go/src/go4n6/disk/ewf/segment.go:279 +0x408
go4n6/ioutil.(*LookaheadReader).start.func1(0xc82000b930, 0xc82039e000, 0x4)
    /Users/joe/go/src/go4n6/ioutil/lookahead.go:325 +0x3f8
created by go4n6/ioutil.(*LookaheadReader).start
    /Users/joe/go/src/go4n6/ioutil/lookahead.go:333 +0x94

goroutine 96 [sleep]:
time.Sleep(0x186a0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/time.go:59 +0xf9
go4n6/disk/ewf.decompress(0x47ad058, 0xc82223e0e0, 0x18dcc, 0x4255fe0, 0xc820094000, 0x0, 0x0, 0x0, 0x0, 0x0)
    /Users/joe/go/src/go4n6/disk/ewf/segment.go:278 +0x314
go4n6/ioutil.(*LookaheadReader).start.func1(0xc82000b930, 0xc82039e000, 0x5)
    /Users/joe/go/src/go4n6/ioutil/lookahead.go:325 +0x3f8
created by go4n6/ioutil.(*LookaheadReader).start
    /Users/joe/go/src/go4n6/ioutil/lookahead.go:333 +0x94

goroutine 91 [sleep]:
time.Sleep(0x186a0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/time.go:59 +0xf9
time.Sleep(0x186a0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/time.go:53 +0x37
go4n6/disk/ewf.decompress(0x47ad058, 0xc822240060, 0x18dca, 0x4255fe0, 0xc820094000, 0x0, 0x0, 0x0, 0x0, 0x0)
    /Users/joe/go/src/go4n6/disk/ewf/segment.go:278 +0x314
go4n6/ioutil.(*LookaheadReader).start.func1(0xc82000b930, 0xc82039e000, 0x0)
    /Users/joe/go/src/go4n6/ioutil/lookahead.go:325 +0x3f8
created by go4n6/ioutil.(*LookaheadReader).start
    /Users/joe/go/src/go4n6/ioutil/lookahead.go:333 +0x94

goroutine 93 [sleep]:
time.Sleep(0x186a0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/time.go:59 +0xf9
go4n6/disk/ewf.decompress(0x47ad058, 0xc822258060, 0x18dcf, 0x4255fe0, 0xc820094000, 0x0, 0x0, 0x0, 0x0, 0x0)
    /Users/joe/go/src/go4n6/disk/ewf/segment.go:278 +0x314
go4n6/ioutil.(*LookaheadReader).start.func1(0xc82000b930, 0xc82039e000, 0x2)
    /Users/joe/go/src/go4n6/ioutil/lookahead.go:325 +0x3f8
created by go4n6/ioutil.(*LookaheadReader).start
    /Users/joe/go/src/go4n6/ioutil/lookahead.go:333 +0x94

goroutine 94 [sleep]:
time.Sleep(0x186a0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/time.go:59 +0xf9
time.Sleep(0x186a0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/time.go:53 +0x37
go4n6/disk/ewf.decompress(0x47ad058, 0xc8222a6020, 0x18dcb, 0x4255fe0, 0xc820094000, 0x0, 0x0, 0x0, 0x0, 0x0)
    /Users/joe/go/src/go4n6/disk/ewf/segment.go:278 +0x314
go4n6/ioutil.(*LookaheadReader).start.func1(0xc82000b930, 0xc82039e000, 0x3)
    /Users/joe/go/src/go4n6/ioutil/lookahead.go:325 +0x3f8
created by go4n6/ioutil.(*LookaheadReader).start
    /Users/joe/go/src/go4n6/ioutil/lookahead.go:333 +0x94

goroutine 97 [sleep]:
time.Sleep(0x186a0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/time.go:59 +0xf9
go4n6/disk/ewf.decompress(0x47ad058, 0xc82222e8e0, 0x18dce, 0x4255fe0, 0xc820094000, 0x0, 0x0, 0x0, 0x0, 0x0)
    /Users/joe/go/src/go4n6/disk/ewf/segment.go:278 +0x314
go4n6/ioutil.(*LookaheadReader).start.func1(0xc82000b930, 0xc82039e000, 0x6)
    /Users/joe/go/src/go4n6/ioutil/lookahead.go:325 +0x3f8
created by go4n6/ioutil.(*LookaheadReader).start
    /Users/joe/go/src/go4n6/ioutil/lookahead.go:333 +0x94

goroutine 105 [chan receive]:
go4n6/file/mft.(*MFT).decodeEntries.func1(0xc82254c960, 0xc82001a120, 0xc820d683c0, 0xc82001a0c0)
    /Users/joe/go/src/go4n6/file/mft/entry.go:80 +0x79
created by go4n6/file/mft.(*MFT).decodeEntries
    /Users/joe/go/src/go4n6/file/mft/entry.go:86 +0x109

goroutine 104 [chan receive]:
go4n6/file/mft.(*MFT).decodeEntries.func1(0xc82254c960, 0xc82001a120, 0xc820d683c0, 0xc82001a0c0)
    /Users/joe/go/src/go4n6/file/mft/entry.go:80 +0x79
created by go4n6/file/mft.(*MFT).decodeEntries
    /Users/joe/go/src/go4n6/file/mft/entry.go:86 +0x109

goroutine 103 [chan receive]:
go4n6/file/mft.(*MFT).decodeEntries.func1(0xc82254c960, 0xc82001a120, 0xc820d683c0, 0xc82001a0c0)
    /Users/joe/go/src/go4n6/file/mft/entry.go:80 +0x79
created by go4n6/file/mft.(*MFT).decodeEntries
    /Users/joe/go/src/go4n6/file/mft/entry.go:86 +0x109

goroutine 102 [chan receive]:
go4n6/file/mft.(*MFT).decodeEntries.func1(0xc82254c960, 0xc82001a120, 0xc820d683c0, 0xc82001a0c0)
    /Users/joe/go/src/go4n6/file/mft/entry.go:80 +0x79
created by go4n6/file/mft.(*MFT).decodeEntries
    /Users/joe/go/src/go4n6/file/mft/entry.go:86 +0x109

goroutine 106 [chan receive]:
go4n6/file/mft.(*MFT).decodeEntries.func1(0xc82254c960, 0xc82001a120, 0xc820d683c0, 0xc82001a0c0)
    /Users/joe/go/src/go4n6/file/mft/entry.go:80 +0x79
created by go4n6/file/mft.(*MFT).decodeEntries
    /Users/joe/go/src/go4n6/file/mft/entry.go:86 +0x109

goroutine 101 [chan receive]:
go4n6/file/mft.(*MFT).decodeEntries.func1(0xc82254c960, 0xc82001a120, 0xc820d683c0, 0xc82001a0c0)
    /Users/joe/go/src/go4n6/file/mft/entry.go:80 +0x79
created by go4n6/file/mft.(*MFT).decodeEntries
    /Users/joe/go/src/go4n6/file/mft/entry.go:86 +0x109

goroutine 107 [chan receive]:
go4n6/file/mft.(*MFT).decodeEntries.func1(0xc82254c960, 0xc82001a120, 0xc820d683c0, 0xc82001a0c0)
    /Users/joe/go/src/go4n6/file/mft/entry.go:80 +0x79
created by go4n6/file/mft.(*MFT).decodeEntries
    /Users/joe/go/src/go4n6/file/mft/entry.go:86 +0x109
exit status 2

GODEBUG=gcstoptheworld=1,gcshrinkstackoff=1 go run ntfstest.go

runtime:objectstart Span weird: p=0xc8240ce000 k=0x6412067 s.start=0xc8240ce000 s.limit=0xc8240de200 s.state=2
fatal error: objectstart: bad pointer in unexpected span

runtime stack:
runtime.throw(0x42a56a0, 0x2b)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/panic.go:527 +0x90 fp=0x7fff5fbff6c0 sp=0x7fff5fbff6a8
runtime.heapBitsForObject(0xc8240ce000, 0x0, 0x0, 0xc800000000, 0x51454e0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/mbitmap.go:214 +0x28c fp=0x7fff5fbff6f8 sp=0x7fff5fbff6c0
runtime.scanobject(0xc821ce6320, 0x7fff5fbff818)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/mgcmark.go:863 +0x232 fp=0x7fff5fbff7c8 sp=0x7fff5fbff6f8
runtime.gcDrain(0x7fff5fbff818, 0xffffffffffffffff)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/mgcmark.go:674 +0xf4 fp=0x7fff5fbff7f8 sp=0x7fff5fbff7c8
runtime.gchelper()
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/mgc.go:1703 +0x89 fp=0x7fff5fbff840 sp=0x7fff5fbff7f8
runtime.stopm()
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/proc1.go:1131 +0x146 fp=0x7fff5fbff868 sp=0x7fff5fbff840
runtime.gcstopm()
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/proc1.go:1321 +0xf8 fp=0x7fff5fbff898 sp=0x7fff5fbff868
runtime.schedule()
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/proc1.go:1580 +0x9c fp=0x7fff5fbff8d0 sp=0x7fff5fbff898
runtime.goschedImpl(0xc8200ae480)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/proc1.go:1697 +0x12a fp=0x7fff5fbff8e8 sp=0x7fff5fbff8d0
runtime.gopreempt_m(0xc8200ae480)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/proc1.go:1712 +0x32 fp=0x7fff5fbff8f8 sp=0x7fff5fbff8e8
runtime.newstack()
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/stack1.go:786 +0xa92 fp=0x7fff5fbffa70 sp=0x7fff5fbff8f8
runtime.morestack()
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/asm_amd64.s:330 +0x7f fp=0x7fff5fbffa78 sp=0x7fff5fbffa70

goroutine 1 [chan receive]:
runtime.gopark(0x42bb1b0, 0xc82001a118, 0x426e910, 0xc, 0x17, 0x3)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/proc.go:185 +0x163 fp=0xc820061b68 sp=0xc820061b40
runtime.goparkunlock(0xc82001a118, 0x426e910, 0xc, 0x17, 0x3)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/proc.go:191 +0x54 fp=0xc820061ba0 sp=0xc820061b68
runtime.chanrecv(0x41e0760, 0xc82001a0c0, 0xc820061ce8, 0xc820061c01, 0x40e0000)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/chan.go:505 +0x901 fp=0xc820061c60 sp=0xc820061ba0
runtime.chanrecv2(0x41e0760, 0xc82001a0c0, 0xc820061ce8, 0x51401c8)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/chan.go:354 +0x2b fp=0xc820061c90 sp=0xc820061c60
go4n6/file/mft.(*MFT).Decode(0xc8210fc5a0, 0x51401c8, 0xc8210fc570, 0x0, 0x0)
    /Users/joe/go/src/go4n6/file/mft/mft.go:224 +0x166 fp=0xc820061d28 sp=0xc820061c90
go4n6/fs/ntfs.(*NTFS).Entries(0xc821bb06a0, 0xc8210fc101, 0x0, 0x0, 0x0, 0x0, 0x0)
    /Users/joe/go/src/go4n6/fs/ntfs/ntfs.go:130 +0x97 fp=0xc820061d70 sp=0xc820061d28
main.main()
    /Users/joe/src/ntfstest.go:43 +0x990 fp=0xc820061f50 sp=0xc820061d70
runtime.main()
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/proc.go:111 +0x2b0 fp=0xc820061fa0 sp=0xc820061f50
runtime.goexit()
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/asm_amd64.s:1696 +0x1 fp=0xc820061fa8 sp=0xc820061fa0

goroutine 17 [syscall, locked to thread]:
runtime.goexit()
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/asm_amd64.s:1696 +0x1 fp=0xc820040fb8 sp=0xc820040fb0

goroutine 2 [force gc (idle)]:
runtime.gopark(0x42bb1b0, 0x4364860, 0x426f330, 0xf, 0x14, 0x1)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/proc.go:185 +0x163 fp=0xc82002c758 sp=0xc82002c730
runtime.goparkunlock(0x4364860, 0x426f330, 0xf, 0xc820000114, 0x1)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/proc.go:191 +0x54 fp=0xc82002c790 sp=0xc82002c758
runtime.forcegchelper()
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/proc.go:152 +0xb8 fp=0xc82002c7c0 sp=0xc82002c790
runtime.goexit()
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/asm_amd64.s:1696 +0x1 fp=0xc82002c7c8 sp=0xc82002c7c0
created by runtime.init.4
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/proc.go:141 +0x2b

goroutine 3 [GC sweep wait]:
runtime.gopark(0x42bb1b0, 0x43649a0, 0x426c130, 0xd, 0x407dc14, 0x1)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/proc.go:185 +0x163 fp=0xc82002cf48 sp=0xc82002cf20
runtime.goparkunlock(0x43649a0, 0x426c130, 0xd, 0x14, 0x1)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/proc.go:191 +0x54 fp=0xc82002cf80 sp=0xc82002cf48
runtime.bgsweep(0xc820064000)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/mgcsweep.go:67 +0x14d fp=0xc82002cfb8 sp=0xc82002cf80
runtime.goexit()
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/asm_amd64.s:1696 +0x1 fp=0xc82002cfc0 sp=0xc82002cfb8
created by runtime.gcenable
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/mgc.go:205 +0x53

goroutine 4 [finalizer wait]:
runtime.gopark(0x42bb1b0, 0x435f288, 0x426eff0, 0xe, 0x14, 0x1)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/proc.go:185 +0x163 fp=0xc82002d718 sp=0xc82002d6f0
runtime.goparkunlock(0x435f288, 0x426eff0, 0xe, 0x14, 0x1)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/proc.go:191 +0x54 fp=0xc82002d750 sp=0xc82002d718
runtime.runfinq()
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/mfinal.go:154 +0xaa fp=0xc82002d7c0 sp=0xc82002d750
runtime.goexit()
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/asm_amd64.s:1696 +0x1 fp=0xc82002d7c8 sp=0xc82002d7c0
created by runtime.createfing
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/mfinal.go:135 +0x60

goroutine 58 [semacquire]:
runtime.gopark(0x42bb1b0, 0x436ad40, 0x4271790, 0xa, 0x19, 0x4)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/proc.go:185 +0x163 fp=0xc82002fe80 sp=0xc82002fe58
runtime.goparkunlock(0x436ad40, 0x4271790, 0xa, 0xc820033619, 0x4)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/proc.go:191 +0x54 fp=0xc82002feb8 sp=0xc82002fe80
runtime.semacquire(0xc8205e4b6c, 0x40c2e01)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/sema.go:100 +0x2f7 fp=0xc82002ff18 sp=0xc82002feb8
sync.runtime_Semacquire(0xc8205e4b6c)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/sema.go:43 +0x26 fp=0xc82002ff30 sp=0xc82002ff18
sync.(*WaitGroup).Wait(0xc8205e4b60)
    /usr/local/Cellar/go/1.5rc1/libexec/src/sync/waitgroup.go:126 +0xb4 fp=0xc82002ff78 sp=0xc82002ff30
go4n6/ioutil.(*LookaheadReader).start(0xc820600000)
    /Users/joe/go/src/go4n6/ioutil/lookahead.go:337 +0xbc fp=0xc82002ffb8 sp=0xc82002ff78
runtime.goexit()
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/asm_amd64.s:1696 +0x1 fp=0xc82002ffc0 sp=0xc82002ffb8
created by go4n6/ioutil.(*LookaheadReader).Get
    /Users/joe/go/src/go4n6/ioutil/lookahead.go:140 +0x1ec

goroutine 59 [garbage collection]:
runtime.systemstack_switch()
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/asm_amd64.s:216 fp=0xc822e7f358 sp=0xc822e7f350
runtime.gc(0x1)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/mgc.go:1096 +0x3d0 fp=0xc822e7f650 sp=0xc822e7f358
runtime.startGC(0x1, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/mgc.go:850 +0x101 fp=0xc822e7f670 sp=0xc822e7f650
runtime.mallocgc(0x8000, 0x41e8fe0, 0x1, 0x43650a0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/malloc.go:705 +0x4fb fp=0xc822e7f740 sp=0xc822e7f670
runtime.newarray(0x41e8fe0, 0x8000, 0xc822e7f7d0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/malloc.go:777 +0xc9 fp=0xc822e7f780 sp=0xc822e7f740
runtime.makeslice(0x41e0400, 0x0, 0x8000, 0x0, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/slice.go:32 +0x165 fp=0xc822e7f7d0 sp=0xc822e7f780
go4n6/compress/zlib.(*reader).Read(0xc820a2ef00, 0xc824872000, 0x8000, 0x8000, 0x0, 0x0, 0x0)
    /Users/joe/go/src/go4n6/compress/zlib/zlib.go:73 +0xab fp=0xc822e7f8e8 sp=0xc822e7f7d0
io.(*LimitedReader).Read(0xc82092e620, 0xc824872000, 0x8000, 0x8000, 0x8001, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/io/io.go:427 +0xbd fp=0xc822e7f938 sp=0xc822e7f8e8
bytes.(*Buffer).ReadFrom(0xc821a1b500, 0x47b1210, 0xc82092e620, 0x0, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/bytes/buffer.go:173 +0x23f fp=0xc822e7f9e8 sp=0xc822e7f938
io.copyBuffer(0x47b11e8, 0xc821a1b500, 0x47b1210, 0xc82092e620, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/io/io.go:375 +0x180 fp=0xc822e7faa8 sp=0xc822e7f9e8
io.Copy(0x47b11e8, 0xc821a1b500, 0x47b1210, 0xc82092e620, 0x4059d1d, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/io/io.go:351 +0x64 fp=0xc822e7fb00 sp=0xc822e7faa8
io.CopyN(0x47b11e8, 0xc821a1b500, 0x47b1198, 0xc820a2ef00, 0x8000, 0x8000, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/io/io.go:327 +0xf7 fp=0xc822e7fb80 sp=0xc822e7fb00
go4n6/disk/ewf.decompress(0x47b1138, 0xc82092c060, 0x180ce, 0x4255fe0, 0xc82009c000, 0x0, 0x0, 0x0, 0x0, 0x0)
    /Users/joe/go/src/go4n6/disk/ewf/segment.go:279 +0x408 fp=0xc822e7fe80 sp=0xc822e7fb80
go4n6/ioutil.(*LookaheadReader).start.func1(0xc8205e4b60, 0xc820600000, 0x0)
    /Users/joe/go/src/go4n6/ioutil/lookahead.go:325 +0x3f8 fp=0xc822e7ff88 sp=0xc822e7fe80
runtime.goexit()
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/asm_amd64.s:1696 +0x1 fp=0xc822e7ff90 sp=0xc822e7ff88
created by go4n6/ioutil.(*LookaheadReader).start
    /Users/joe/go/src/go4n6/ioutil/lookahead.go:333 +0x94

goroutine 60 [runnable]:
runtime.shouldtriggergc(0xc822e83480)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/mgc.go:709 fp=0xc822e833d8 sp=0xc822e833d0
runtime.mallocgc(0x12000, 0x41e8fe0, 0x1, 0x8000)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/malloc.go:704 +0x4e0 fp=0xc822e834a8 sp=0xc822e833d8
runtime.newarray(0x41e8fe0, 0x10200, 0xc822e83548)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/malloc.go:777 +0xc9 fp=0xc822e834e8 sp=0xc822e834a8
runtime.makeslice(0x41e0400, 0x10200, 0x10200, 0x0, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/slice.go:32 +0x165 fp=0xc822e83538 sp=0xc822e834e8
bytes.makeSlice(0x10200, 0x0, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/bytes/buffer.go:195 +0x64 fp=0xc822e83588 sp=0xc822e83538
bytes.(*Buffer).ReadFrom(0xc821a3e930, 0x47b1210, 0xc82092c840, 0x8000, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/bytes/buffer.go:167 +0xd3 fp=0xc822e83638 sp=0xc822e83588
io.copyBuffer(0x47b11e8, 0xc821a3e930, 0x47b1210, 0xc82092c840, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/io/io.go:375 +0x180 fp=0xc822e836f8 sp=0xc822e83638
io.Copy(0x47b11e8, 0xc821a3e930, 0x47b1210, 0xc82092c840, 0x22e83fc000008000, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/io/io.go:351 +0x64 fp=0xc822e83750 sp=0xc822e836f8
io.CopyN(0x47b11e8, 0xc821a3e930, 0x47a42b0, 0xc820a4a020, 0x8000, 0x8000, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/io/io.go:327 +0xf7 fp=0xc822e837d0 sp=0xc822e83750
go4n6/compress/zlib.(*reader).Read(0xc820a64640, 0xc824390000, 0x8000, 0x8000, 0x0, 0x0, 0x0)
    /Users/joe/go/src/go4n6/compress/zlib/zlib.go:75 +0x198 fp=0xc822e838e8 sp=0xc822e837d0
io.(*LimitedReader).Read(0xc82092c820, 0xc824390000, 0x8000, 0x8000, 0x0, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/io/io.go:427 +0xbd fp=0xc822e83938 sp=0xc822e838e8
bytes.(*Buffer).ReadFrom(0xc821a3e8c0, 0x47b1210, 0xc82092c820, 0x0, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/bytes/buffer.go:173 +0x23f fp=0xc822e839e8 sp=0xc822e83938
io.copyBuffer(0x47b11e8, 0xc821a3e8c0, 0x47b1210, 0xc82092c820, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/io/io.go:375 +0x180 fp=0xc822e83aa8 sp=0xc822e839e8
io.Copy(0x47b11e8, 0xc821a3e8c0, 0x47b1210, 0xc82092c820, 0x4059d1d, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/io/io.go:351 +0x64 fp=0xc822e83b00 sp=0xc822e83aa8
io.CopyN(0x47b11e8, 0xc821a3e8c0, 0x47b1198, 0xc820a64640, 0x8000, 0x8000, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/io/io.go:327 +0xf7 fp=0xc822e83b80 sp=0xc822e83b00
go4n6/disk/ewf.decompress(0x47b1138, 0xc820a4a020, 0x1810d, 0x4255fe0, 0xc82009c000, 0x0, 0x0, 0x0, 0x0, 0x0)
    /Users/joe/go/src/go4n6/disk/ewf/segment.go:279 +0x408 fp=0xc822e83e80 sp=0xc822e83b80
go4n6/ioutil.(*LookaheadReader).start.func1(0xc8205e4b60, 0xc820600000, 0x1)
    /Users/joe/go/src/go4n6/ioutil/lookahead.go:325 +0x3f8 fp=0xc822e83f88 sp=0xc822e83e80
runtime.goexit()
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/asm_amd64.s:1696 +0x1 fp=0xc822e83f90 sp=0xc822e83f88
created by go4n6/ioutil.(*LookaheadReader).start
    /Users/joe/go/src/go4n6/ioutil/lookahead.go:333 +0x94

goroutine 61 [runnable]:
runtime.shouldtriggergc(0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/mgc.go:709 fp=0xc8210dba20 sp=0xc8210dba18
runtime.mallocgc(0x8000, 0x41e8fe0, 0x1, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/malloc.go:704 +0x4e0 fp=0xc8210dbaf0 sp=0xc8210dba20
runtime.newarray(0x41e8fe0, 0x8000, 0xc8210dbb90)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/malloc.go:777 +0xc9 fp=0xc8210dbb30 sp=0xc8210dbaf0
runtime.makeslice(0x41e0400, 0x0, 0x8000, 0x0, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/slice.go:32 +0x165 fp=0xc8210dbb80 sp=0xc8210dbb30
go4n6/disk/ewf.decompress(0x47b1138, 0xc82092e060, 0x1810f, 0x4255fe0, 0xc82009c000, 0x0, 0x0, 0x0, 0x0, 0x0)
    /Users/joe/go/src/go4n6/disk/ewf/segment.go:278 +0x314 fp=0xc8210dbe80 sp=0xc8210dbb80
go4n6/ioutil.(*LookaheadReader).start.func1(0xc8205e4b60, 0xc820600000, 0x2)
    /Users/joe/go/src/go4n6/ioutil/lookahead.go:325 +0x3f8 fp=0xc8210dbf88 sp=0xc8210dbe80
runtime.goexit()
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/asm_amd64.s:1696 +0x1 fp=0xc8210dbf90 sp=0xc8210dbf88
created by go4n6/ioutil.(*LookaheadReader).start
    /Users/joe/go/src/go4n6/ioutil/lookahead.go:333 +0x94

goroutine 62 [runnable, locked to thread]:
runtime.cgocall(0x4033b80, 0xc8200637d0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/cgocall.go:120 +0x11b fp=0xc820063788 sp=0xc820063758
go4n6/compress/zlib._Cfunc_inflate(0xc820a405c8, 0xc800000000, 0x1)
    ??:0 +0x39 fp=0xc8200637d0 sp=0xc820063788
go4n6/compress/zlib.(*reader).Read(0xc820a405a0, 0xc824082000, 0x8000, 0x8000, 0x0, 0x0, 0x0)
    /Users/joe/go/src/go4n6/compress/zlib/zlib.go:99 +0x3d4 fp=0xc8200638e8 sp=0xc8200637d0
io.(*LimitedReader).Read(0xc820a4a260, 0xc824082000, 0x8000, 0x8000, 0x8001, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/io/io.go:427 +0xbd fp=0xc820063938 sp=0xc8200638e8
bytes.(*Buffer).ReadFrom(0xc821a407e0, 0x47b1210, 0xc820a4a260, 0x0, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/bytes/buffer.go:173 +0x23f fp=0xc8200639e8 sp=0xc820063938
io.copyBuffer(0x47b11e8, 0xc821a407e0, 0x47b1210, 0xc820a4a260, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/io/io.go:375 +0x180 fp=0xc820063aa8 sp=0xc8200639e8
io.Copy(0x47b11e8, 0xc821a407e0, 0x47b1210, 0xc820a4a260, 0x4059d1d, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/io/io.go:351 +0x64 fp=0xc820063b00 sp=0xc820063aa8
io.CopyN(0x47b11e8, 0xc821a407e0, 0x47b1198, 0xc820a405a0, 0x8000, 0x8000, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/io/io.go:327 +0xf7 fp=0xc820063b80 sp=0xc820063b00
go4n6/disk/ewf.decompress(0x47b1138, 0xc8209200a0, 0x1810a, 0x4255fe0, 0xc82009c000, 0x0, 0x0, 0x0, 0x0, 0x0)
    /Users/joe/go/src/go4n6/disk/ewf/segment.go:279 +0x408 fp=0xc820063e80 sp=0xc820063b80
go4n6/ioutil.(*LookaheadReader).start.func1(0xc8205e4b60, 0xc820600000, 0x3)
    /Users/joe/go/src/go4n6/ioutil/lookahead.go:325 +0x3f8 fp=0xc820063f88 sp=0xc820063e80
runtime.goexit()
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/asm_amd64.s:1696 +0x1 fp=0xc820063f90 sp=0xc820063f88
created by go4n6/ioutil.(*LookaheadReader).start
    /Users/joe/go/src/go4n6/ioutil/lookahead.go:333 +0x94

goroutine 63 [runnable]:
syscall.Syscall(0x3, 0x7, 0xc8246f4000, 0x8000, 0x8000, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/syscall/asm_darwin_amd64.s:16 +0x5 fp=0xc82005f420 sp=0xc82005f418
syscall.read(0x7, 0xc8246f4000, 0x8000, 0x8000, 0x407cb80, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/syscall/zsyscall_darwin_amd64.go:972 +0x5f fp=0xc82005f460 sp=0xc82005f420
syscall.Read(0x7, 0xc8246f4000, 0x8000, 0x8000, 0xc8212cc000, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/syscall/syscall_unix.go:160 +0x4d fp=0xc82005f4a0 sp=0xc82005f460
os.(*File).read(0xc820922010, 0xc8246f4000, 0x8000, 0x8000, 0xc820033680, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/os/file_unix.go:211 +0x75 fp=0xc82005f4e0 sp=0xc82005f4a0
os.(*File).Read(0xc820922010, 0xc8246f4000, 0x8000, 0x8000, 0x0, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/os/file.go:95 +0x8a fp=0xc82005f538 sp=0xc82005f4e0
io.(*LimitedReader).Read(0xc82090cf80, 0xc8246f4000, 0x8000, 0x8000, 0x1, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/io/io.go:427 +0xbd fp=0xc82005f588 sp=0xc82005f538
bytes.(*Buffer).ReadFrom(0xc821a1a4d0, 0x47b1210, 0xc82090cf80, 0x0, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/bytes/buffer.go:173 +0x23f fp=0xc82005f638 sp=0xc82005f588
io.copyBuffer(0x47b11e8, 0xc821a1a4d0, 0x47b1210, 0xc82090cf80, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/io/io.go:375 +0x180 fp=0xc82005f6f8 sp=0xc82005f638
io.Copy(0x47b11e8, 0xc821a1a4d0, 0x47b1210, 0xc82090cf80, 0x2005ffc000008000, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/io/io.go:351 +0x64 fp=0xc82005f750 sp=0xc82005f6f8
io.CopyN(0x47b11e8, 0xc821a1a4d0, 0x47a42b0, 0xc82091e0a0, 0x8000, 0x8000, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/io/io.go:327 +0xf7 fp=0xc82005f7d0 sp=0xc82005f750
go4n6/compress/zlib.(*reader).Read(0xc820a72320, 0xc8244f4000, 0x8000, 0x8000, 0x0, 0x0, 0x0)
    /Users/joe/go/src/go4n6/compress/zlib/zlib.go:75 +0x198 fp=0xc82005f8e8 sp=0xc82005f7d0
io.(*LimitedReader).Read(0xc82090cf60, 0xc8244f4000, 0x8000, 0x8000, 0x0, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/io/io.go:427 +0xbd fp=0xc82005f938 sp=0xc82005f8e8
bytes.(*Buffer).ReadFrom(0xc821a1a460, 0x47b1210, 0xc82090cf60, 0x0, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/bytes/buffer.go:173 +0x23f fp=0xc82005f9e8 sp=0xc82005f938
io.copyBuffer(0x47b11e8, 0xc821a1a460, 0x47b1210, 0xc82090cf60, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/io/io.go:375 +0x180 fp=0xc82005faa8 sp=0xc82005f9e8
io.Copy(0x47b11e8, 0xc821a1a460, 0x47b1210, 0xc82090cf60, 0x4059d1d, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/io/io.go:351 +0x64 fp=0xc82005fb00 sp=0xc82005faa8
io.CopyN(0x47b11e8, 0xc821a1a460, 0x47b1198, 0xc820a72320, 0x8000, 0x8000, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/io/io.go:327 +0xf7 fp=0xc82005fb80 sp=0xc82005fb00
go4n6/disk/ewf.decompress(0x47b1138, 0xc82091e0a0, 0x1810e, 0x4255fe0, 0xc82009c000, 0x0, 0x0, 0x0, 0x0, 0x0)
    /Users/joe/go/src/go4n6/disk/ewf/segment.go:279 +0x408 fp=0xc82005fe80 sp=0xc82005fb80
go4n6/ioutil.(*LookaheadReader).start.func1(0xc8205e4b60, 0xc820600000, 0x4)
    /Users/joe/go/src/go4n6/ioutil/lookahead.go:325 +0x3f8 fp=0xc82005ff88 sp=0xc82005fe80
runtime.goexit()
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/asm_amd64.s:1696 +0x1 fp=0xc82005ff90 sp=0xc82005ff88
created by go4n6/ioutil.(*LookaheadReader).start
    /Users/joe/go/src/go4n6/ioutil/lookahead.go:333 +0x94

goroutine 64 [runnable, locked to thread]:
runtime.cgocall(0x4033b80, 0xc8210dd7d0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/cgocall.go:120 +0x11b fp=0xc8210dd788 sp=0xc8210dd758
go4n6/compress/zlib._Cfunc_inflate(0xc821ce6348, 0xc800000000, 0x1)
    ??:0 +0x39 fp=0xc8210dd7d0 sp=0xc8210dd788
go4n6/compress/zlib.(*reader).Read(0xc821ce6320, 0xc8240c6000, 0x8000, 0x8000, 0x0, 0x0, 0x0)
    /Users/joe/go/src/go4n6/compress/zlib/zlib.go:99 +0x3d4 fp=0xc8210dd8e8 sp=0xc8210dd7d0
io.(*LimitedReader).Read(0xc82092e220, 0xc8240c6000, 0x8000, 0x8000, 0x8001, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/io/io.go:427 +0xbd fp=0xc8210dd938 sp=0xc8210dd8e8
bytes.(*Buffer).ReadFrom(0xc821cfa4d0, 0x47b1210, 0xc82092e220, 0x0, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/bytes/buffer.go:173 +0x23f fp=0xc8210dd9e8 sp=0xc8210dd938
io.copyBuffer(0x47b11e8, 0xc821cfa4d0, 0x47b1210, 0xc82092e220, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/io/io.go:375 +0x180 fp=0xc8210ddaa8 sp=0xc8210dd9e8
io.Copy(0x47b11e8, 0xc821cfa4d0, 0x47b1210, 0xc82092e220, 0x4059d1d, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/io/io.go:351 +0x64 fp=0xc8210ddb00 sp=0xc8210ddaa8
io.CopyN(0x47b11e8, 0xc821cfa4d0, 0x47b1198, 0xc821ce6320, 0x8000, 0x8000, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/io/io.go:327 +0xf7 fp=0xc8210ddb80 sp=0xc8210ddb00
go4n6/disk/ewf.decompress(0x47b1138, 0xc820a70020, 0x1810b, 0x4255fe0, 0xc82009c000, 0x0, 0x0, 0x0, 0x0, 0x0)
    /Users/joe/go/src/go4n6/disk/ewf/segment.go:279 +0x408 fp=0xc8210dde80 sp=0xc8210ddb80
go4n6/ioutil.(*LookaheadReader).start.func1(0xc8205e4b60, 0xc820600000, 0x5)
    /Users/joe/go/src/go4n6/ioutil/lookahead.go:325 +0x3f8 fp=0xc8210ddf88 sp=0xc8210dde80
runtime.goexit()
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/asm_amd64.s:1696 +0x1 fp=0xc8210ddf90 sp=0xc8210ddf88
created by go4n6/ioutil.(*LookaheadReader).start
    /Users/joe/go/src/go4n6/ioutil/lookahead.go:333 +0x94

goroutine 65 [runnable, locked to thread]:
runtime.cgocall(0x4033b80, 0xc8210e17d0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/cgocall.go:120 +0x11b fp=0xc8210e1788 sp=0xc8210e1758
go4n6/compress/zlib._Cfunc_inflate(0xc820a2e5c8, 0xc800000000, 0x1)
    ??:0 +0x39 fp=0xc8210e17d0 sp=0xc8210e1788
go4n6/compress/zlib.(*reader).Read(0xc820a2e5a0, 0xc82410a000, 0x8000, 0x8000, 0x0, 0x0, 0x0)
    /Users/joe/go/src/go4n6/compress/zlib/zlib.go:99 +0x3d4 fp=0xc8210e18e8 sp=0xc8210e17d0
io.(*LimitedReader).Read(0xc82091f780, 0xc82410a000, 0x8000, 0x8000, 0x8001, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/io/io.go:427 +0xbd fp=0xc8210e1938 sp=0xc8210e18e8
bytes.(*Buffer).ReadFrom(0xc821a188c0, 0x47b1210, 0xc82091f780, 0x0, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/bytes/buffer.go:173 +0x23f fp=0xc8210e19e8 sp=0xc8210e1938
io.copyBuffer(0x47b11e8, 0xc821a188c0, 0x47b1210, 0xc82091f780, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/io/io.go:375 +0x180 fp=0xc8210e1aa8 sp=0xc8210e19e8
io.Copy(0x47b11e8, 0xc821a188c0, 0x47b1210, 0xc82091f780, 0x4059d1d, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/io/io.go:351 +0x64 fp=0xc8210e1b00 sp=0xc8210e1aa8
io.CopyN(0x47b11e8, 0xc821a188c0, 0x47b1198, 0xc820a2e5a0, 0x8000, 0x8000, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/io/io.go:327 +0xf7 fp=0xc8210e1b80 sp=0xc8210e1b00
go4n6/disk/ewf.decompress(0x47b1138, 0xc82090c680, 0x1810c, 0x4255fe0, 0xc82009c000, 0x0, 0x0, 0x0, 0x0, 0x0)
    /Users/joe/go/src/go4n6/disk/ewf/segment.go:279 +0x408 fp=0xc8210e1e80 sp=0xc8210e1b80
go4n6/ioutil.(*LookaheadReader).start.func1(0xc8205e4b60, 0xc820600000, 0x6)
    /Users/joe/go/src/go4n6/ioutil/lookahead.go:325 +0x3f8 fp=0xc8210e1f88 sp=0xc8210e1e80
runtime.goexit()
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/asm_amd64.s:1696 +0x1 fp=0xc8210e1f90 sp=0xc8210e1f88
created by go4n6/ioutil.(*LookaheadReader).start
    /Users/joe/go/src/go4n6/ioutil/lookahead.go:333 +0x94

goroutine 76 [runnable]:
runtime.gopark(0x42bb1b0, 0xc82001a238, 0x426e910, 0xc, 0x17, 0x3)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/proc.go:185 +0x163 fp=0xc820a3c5b8 sp=0xc820a3c590
runtime.goparkunlock(0xc82001a238, 0x426e910, 0xc, 0x4169e17, 0x3)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/proc.go:191 +0x54 fp=0xc820a3c5f0 sp=0xc820a3c5b8
runtime.chanrecv(0x41e07c0, 0xc82001a1e0, 0xc820a3c740, 0x41e8701, 0xc8220c0000)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/chan.go:505 +0x901 fp=0xc820a3c6b0 sp=0xc820a3c5f0
runtime.chanrecv2(0x41e07c0, 0xc82001a1e0, 0xc820a3c740, 0x41e0400)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/chan.go:354 +0x2b fp=0xc820a3c6e0 sp=0xc820a3c6b0
go4n6/ioutil.(*LookaheadReader).Get(0xc820600000, 0x180ce, 0x0, 0x0, 0x0, 0x0, 0x0)
    /Users/joe/go/src/go4n6/ioutil/lookahead.go:161 +0x443 fp=0xc820a3c7c8 sp=0xc820a3c6e0
go4n6/disk/ewf.(*segment).Read(0xc82009c000, 0xc8234d0000, 0x490000, 0x490000, 0x8000, 0x0, 0x0)
    /Users/joe/go/src/go4n6/disk/ewf/segment.go:114 +0x1ea fp=0xc820a3c858 sp=0xc820a3c7c8
go4n6/ioutil.(*MultiReadSeeker).Read(0xc82000e6f0, 0xc8234d0000, 0x490000, 0x490000, 0xc0670000, 0x0, 0x0)
    /Users/joe/go/src/go4n6/ioutil/multi.go:90 +0x204 fp=0xc820a3c928 sp=0xc820a3c858
go4n6/disk/ewf.(*Reader).Read(0xc8200143c0, 0xc8234d0000, 0x490000, 0x490000, 0x0, 0x0, 0x0)
    <autogenerated>:6 +0x82 fp=0xc820a3c978 sp=0xc820a3c928
github.com/badgerodon/ioutil.(*SectionReader).Read(0xc8210fc120, 0xc8234d0000, 0x490000, 0x490000, 0x0, 0x0, 0x0)
    /Users/joe/go/src/github.com/badgerodon/ioutil/section.go:41 +0x120 fp=0xc820a3c9c8 sp=0xc820a3c978
go4n6/partition/mbr.Partition.Read(0x5540000, 0xc8210fc120, 0xc82008e240, 0xfffffe0700212080, 0x27ff00000000800, 0xc8234d0000, 0x490000, 0x490000, 0xc0570000, 0x0, ...)
    /Users/joe/go/src/go4n6/partition/mbr/partition.go:388 +0x6d fp=0xc820a3ca18 sp=0xc820a3c9c8
go4n6/partition/mbr.(*Partition).Read(0xc8210fc150, 0xc8234d0000, 0x490000, 0x490000, 0x0, 0x0, 0x0)
    <autogenerated>:4 +0xc8 fp=0xc820a3ca78 sp=0xc820a3ca18
github.com/badgerodon/ioutil.(*SectionReader).Read(0xc8210fc4e0, 0xc8234d0000, 0x490000, 0x490000, 0x0, 0x0, 0x0)
    /Users/joe/go/src/github.com/badgerodon/ioutil/section.go:41 +0x120 fp=0xc820a3cac8 sp=0xc820a3ca78
github.com/badgerodon/ioutil.(*MultiReadSeeker).Read(0xc8210fc540, 0xc8234d0000, 0x490000, 0x490000, 0x8000, 0x0, 0x0)
    /Users/joe/go/src/github.com/badgerodon/ioutil/multi.go:39 +0x204 fp=0xc820a3cb98 sp=0xc820a3cac8
go4n6/ioutil.(*MultiRangeReadSeeker).Read(0xc8210fc570, 0xc8234d0000, 0x490000, 0x490000, 0x8000, 0x0, 0x0)
    <autogenerated>:24 +0x82 fp=0xc820a3cbe8 sp=0xc820a3cb98
io.(*LimitedReader).Read(0xc821bb06c0, 0xc8234d0000, 0x490000, 0x490000, 0x8000, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/io/io.go:427 +0xbd fp=0xc820a3cc38 sp=0xc820a3cbe8
bytes.(*Buffer).ReadFrom(0xc821cfa460, 0x47b1210, 0xc821bb06c0, 0x570000, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/bytes/buffer.go:173 +0x23f fp=0xc820a3cce8 sp=0xc820a3cc38
io.copyBuffer(0x47b11e8, 0xc821cfa460, 0x47b1210, 0xc821bb06c0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/io/io.go:375 +0x180 fp=0xc820a3cda8 sp=0xc820a3cce8
io.Copy(0x47b11e8, 0xc821cfa460, 0x47b1210, 0xc821bb06c0, 0xc82001a120, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/io/io.go:351 +0x64 fp=0xc820a3ce00 sp=0xc820a3cda8
io.CopyN(0x47b11e8, 0xc821cfa460, 0x51401c8, 0xc8210fc570, 0xa00000, 0xa00000, 0x0, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/io/io.go:327 +0xf7 fp=0xc820a3ce80 sp=0xc820a3ce00
go4n6/file/mft.(*MFT).decodeEntries(0xc8210fc5a0, 0x51401c8, 0xc8210fc570, 0xc82001a0c0)
    /Users/joe/go/src/go4n6/file/mft/entry.go:92 +0x22f fp=0xc820a3cf90 sp=0xc820a3ce80
runtime.goexit()
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/asm_amd64.s:1696 +0x1 fp=0xc820a3cf98 sp=0xc820a3cf90
created by go4n6/file/mft.(*MFT).Decode
    /Users/joe/go/src/go4n6/file/mft/mft.go:221 +0x123

goroutine 79 [chan receive]:
runtime.gopark(0x42bb1b0, 0xc82001a178, 0x426e910, 0xc, 0x17, 0x3)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/proc.go:185 +0x163 fp=0xc820a2a620 sp=0xc820a2a5f8
runtime.goparkunlock(0xc82001a178, 0x426e910, 0xc, 0xc820d4e517, 0x3)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/proc.go:191 +0x54 fp=0xc820a2a658 sp=0xc820a2a620
runtime.chanrecv(0x41e0700, 0xc82001a120, 0xc820a2a768, 0xc820a2a701, 0xc820a20000)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/chan.go:505 +0x901 fp=0xc820a2a718 sp=0xc820a2a658
runtime.chanrecv2(0x41e0700, 0xc82001a120, 0xc820a2a768, 0xc820d4e900)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/chan.go:354 +0x2b fp=0xc820a2a748 sp=0xc820a2a718
go4n6/file/mft.(*MFT).decodeEntries.func1(0xc82000adf0, 0xc82001a120, 0xc8210fc5a0, 0xc82001a0c0)
    /Users/joe/go/src/go4n6/file/mft/entry.go:80 +0x79 fp=0xc820a2a7a0 sp=0xc820a2a748
runtime.goexit()
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/asm_amd64.s:1696 +0x1 fp=0xc820a2a7a8 sp=0xc820a2a7a0
created by go4n6/file/mft.(*MFT).decodeEntries
    /Users/joe/go/src/go4n6/file/mft/entry.go:86 +0x109

goroutine 78 [chan receive]:
runtime.gopark(0x42bb1b0, 0xc82001a178, 0x426e910, 0xc, 0x17, 0x3)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/proc.go:185 +0x163 fp=0xc820a2ae20 sp=0xc820a2adf8
runtime.goparkunlock(0xc82001a178, 0x426e910, 0xc, 0xc820d50517, 0x3)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/proc.go:191 +0x54 fp=0xc820a2ae58 sp=0xc820a2ae20
runtime.chanrecv(0x41e0700, 0xc82001a120, 0xc820a2af68, 0xc820a2af01, 0xc820a20000)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/chan.go:505 +0x901 fp=0xc820a2af18 sp=0xc820a2ae58
runtime.chanrecv2(0x41e0700, 0xc82001a120, 0xc820a2af68, 0xc820d50900)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/chan.go:354 +0x2b fp=0xc820a2af48 sp=0xc820a2af18
go4n6/file/mft.(*MFT).decodeEntries.func1(0xc82000adf0, 0xc82001a120, 0xc8210fc5a0, 0xc82001a0c0)
    /Users/joe/go/src/go4n6/file/mft/entry.go:80 +0x79 fp=0xc820a2afa0 sp=0xc820a2af48
runtime.goexit()
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/asm_amd64.s:1696 +0x1 fp=0xc820a2afa8 sp=0xc820a2afa0
created by go4n6/file/mft.(*MFT).decodeEntries
    /Users/joe/go/src/go4n6/file/mft/entry.go:86 +0x109

goroutine 77 [chan receive]:
runtime.gopark(0x42bb1b0, 0xc82001a178, 0x426e910, 0xc, 0x17, 0x3)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/proc.go:185 +0x163 fp=0xc820a2b620 sp=0xc820a2b5f8
runtime.goparkunlock(0xc82001a178, 0x426e910, 0xc, 0x407e417, 0x3)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/proc.go:191 +0x54 fp=0xc820a2b658 sp=0xc820a2b620
runtime.chanrecv(0x41e0700, 0xc82001a120, 0xc820a2b768, 0xc820a2b701, 0xc820a20000)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/chan.go:505 +0x901 fp=0xc820a2b718 sp=0xc820a2b658
runtime.chanrecv2(0x41e0700, 0xc82001a120, 0xc820a2b768, 0xc820d52900)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/chan.go:354 +0x2b fp=0xc820a2b748 sp=0xc820a2b718
go4n6/file/mft.(*MFT).decodeEntries.func1(0xc82000adf0, 0xc82001a120, 0xc8210fc5a0, 0xc82001a0c0)
    /Users/joe/go/src/go4n6/file/mft/entry.go:80 +0x79 fp=0xc820a2b7a0 sp=0xc820a2b748
runtime.goexit()
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/asm_amd64.s:1696 +0x1 fp=0xc820a2b7a8 sp=0xc820a2b7a0
created by go4n6/file/mft.(*MFT).decodeEntries
    /Users/joe/go/src/go4n6/file/mft/entry.go:86 +0x109

goroutine 80 [chan receive]:
runtime.gopark(0x42bb1b0, 0xc82001a178, 0x426e910, 0xc, 0x17, 0x3)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/proc.go:185 +0x163 fp=0xc82002b620 sp=0xc82002b5f8
runtime.goparkunlock(0xc82001a178, 0x426e910, 0xc, 0x42bbc17, 0x3)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/proc.go:191 +0x54 fp=0xc82002b658 sp=0xc82002b620
runtime.chanrecv(0x41e0700, 0xc82001a120, 0xc82002b768, 0xc82002b701, 0xc820020000)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/chan.go:505 +0x901 fp=0xc82002b718 sp=0xc82002b658
runtime.chanrecv2(0x41e0700, 0xc82001a120, 0xc82002b768, 0xc8205e45d0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/chan.go:354 +0x2b fp=0xc82002b748 sp=0xc82002b718
go4n6/file/mft.(*MFT).decodeEntries.func1(0xc82000adf0, 0xc82001a120, 0xc8210fc5a0, 0xc82001a0c0)
    /Users/joe/go/src/go4n6/file/mft/entry.go:80 +0x79 fp=0xc82002b7a0 sp=0xc82002b748
runtime.goexit()
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/asm_amd64.s:1696 +0x1 fp=0xc82002b7a8 sp=0xc82002b7a0
created by go4n6/file/mft.(*MFT).decodeEntries
    /Users/joe/go/src/go4n6/file/mft/entry.go:86 +0x109

goroutine 81 [chan receive]:
runtime.gopark(0x42bb1b0, 0xc82001a178, 0x426e910, 0xc, 0x17, 0x3)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/proc.go:185 +0x163 fp=0xc82002ee20 sp=0xc82002edf8
runtime.goparkunlock(0xc82001a178, 0x426e910, 0xc, 0x42bbc17, 0x3)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/proc.go:191 +0x54 fp=0xc82002ee58 sp=0xc82002ee20
runtime.chanrecv(0x41e0700, 0xc82001a120, 0xc82002ef68, 0xc82002ef01, 0xc820020000)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/chan.go:505 +0x901 fp=0xc82002ef18 sp=0xc82002ee58
runtime.chanrecv2(0x41e0700, 0xc82001a120, 0xc82002ef68, 0xc8205e4a10)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/chan.go:354 +0x2b fp=0xc82002ef48 sp=0xc82002ef18
go4n6/file/mft.(*MFT).decodeEntries.func1(0xc82000adf0, 0xc82001a120, 0xc8210fc5a0, 0xc82001a0c0)
    /Users/joe/go/src/go4n6/file/mft/entry.go:80 +0x79 fp=0xc82002efa0 sp=0xc82002ef48
runtime.goexit()
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/asm_amd64.s:1696 +0x1 fp=0xc82002efa8 sp=0xc82002efa0
created by go4n6/file/mft.(*MFT).decodeEntries
    /Users/joe/go/src/go4n6/file/mft/entry.go:86 +0x109

goroutine 82 [chan receive]:
runtime.gopark(0x42bb1b0, 0xc82001a178, 0x426e910, 0xc, 0x17, 0x3)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/proc.go:185 +0x163 fp=0xc82002de20 sp=0xc82002ddf8
runtime.goparkunlock(0xc82001a178, 0x426e910, 0xc, 0x42bbc17, 0x3)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/proc.go:191 +0x54 fp=0xc82002de58 sp=0xc82002de20
runtime.chanrecv(0x41e0700, 0xc82001a120, 0xc82002df68, 0xc82002df01, 0xc820020000)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/chan.go:505 +0x901 fp=0xc82002df18 sp=0xc82002de58
runtime.chanrecv2(0x41e0700, 0xc82001a120, 0xc82002df68, 0xc8205e4a10)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/chan.go:354 +0x2b fp=0xc82002df48 sp=0xc82002df18
go4n6/file/mft.(*MFT).decodeEntries.func1(0xc82000adf0, 0xc82001a120, 0xc8210fc5a0, 0xc82001a0c0)
    /Users/joe/go/src/go4n6/file/mft/entry.go:80 +0x79 fp=0xc82002dfa0 sp=0xc82002df48
runtime.goexit()
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/asm_amd64.s:1696 +0x1 fp=0xc82002dfa8 sp=0xc82002dfa0
created by go4n6/file/mft.(*MFT).decodeEntries
    /Users/joe/go/src/go4n6/file/mft/entry.go:86 +0x109

goroutine 83 [chan receive]:
runtime.gopark(0x42bb1b0, 0xc82001a178, 0x426e910, 0xc, 0x17, 0x3)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/proc.go:185 +0x163 fp=0xc820028620 sp=0xc8200285f8
runtime.goparkunlock(0xc82001a178, 0x426e910, 0xc, 0x17, 0x3)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/proc.go:191 +0x54 fp=0xc820028658 sp=0xc820028620
runtime.chanrecv(0x41e0700, 0xc82001a120, 0xc820028768, 0xc820028701, 0xc820020000)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/chan.go:505 +0x901 fp=0xc820028718 sp=0xc820028658
runtime.chanrecv2(0x41e0700, 0xc82001a120, 0xc820028768, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/chan.go:354 +0x2b fp=0xc820028748 sp=0xc820028718
go4n6/file/mft.(*MFT).decodeEntries.func1(0xc82000adf0, 0xc82001a120, 0xc8210fc5a0, 0xc82001a0c0)
    /Users/joe/go/src/go4n6/file/mft/entry.go:80 +0x79 fp=0xc8200287a0 sp=0xc820028748
runtime.goexit()
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/asm_amd64.s:1696 +0x1 fp=0xc8200287a8 sp=0xc8200287a0
created by go4n6/file/mft.(*MFT).decodeEntries
    /Users/joe/go/src/go4n6/file/mft/entry.go:86 +0x109

goroutine 84 [chan receive]:
runtime.gopark(0x42bb1b0, 0xc82001a178, 0x426e910, 0xc, 0x17, 0x3)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/proc.go:185 +0x163 fp=0xc820028e20 sp=0xc820028df8
runtime.goparkunlock(0xc82001a178, 0x426e910, 0xc, 0x17, 0x3)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/proc.go:191 +0x54 fp=0xc820028e58 sp=0xc820028e20
runtime.chanrecv(0x41e0700, 0xc82001a120, 0xc820028f68, 0xc820028f01, 0xc820020000)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/chan.go:505 +0x901 fp=0xc820028f18 sp=0xc820028e58
runtime.chanrecv2(0x41e0700, 0xc82001a120, 0xc820028f68, 0x0)
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/chan.go:354 +0x2b fp=0xc820028f48 sp=0xc820028f18
go4n6/file/mft.(*MFT).decodeEntries.func1(0xc82000adf0, 0xc82001a120, 0xc8210fc5a0, 0xc82001a0c0)
    /Users/joe/go/src/go4n6/file/mft/entry.go:80 +0x79 fp=0xc820028fa0 sp=0xc820028f48
runtime.goexit()
    /usr/local/Cellar/go/1.5rc1/libexec/src/runtime/asm_amd64.s:1696 +0x1 fp=0xc820028fa8 sp=0xc820028fa0
created by go4n6/file/mft.(*MFT).decodeEntries
    /Users/joe/go/src/go4n6/file/mft/entry.go:86 +0x109
exit status 2

@aclements
Copy link
Member

Thanks for the quick reply, @jtsylve.

    r.s.next_in = (*C.Bytef)(unsafe.Pointer(&buf.Bytes()[0]))

is definitely not safe. As soon as you leave that scope, the backing store of buf will be reachable only through the C heap (via the z_stream_s object malloc'd by inflateInit). Since the GC can't trace through the C heap, it's free to free buf. At that point all bets are off. I'm actually kind of surprised this works in 1.4.2. I think you're just getting lucky.

Depending on where p comes from, the same may be true of

r.s.next_out = (*C.Bytef)(unsafe.Pointer(&out[0]))

@zeebo
Copy link
Contributor Author

zeebo commented Aug 14, 2015

I bet we have similar code of dubious nature in our code base. I haven't had any crashes with the debug environment variable yet.

I wonder if automated tooling can be written that just detects if the last usage of a variable in some function is in an unsafe.Pointer(&var) kind of form. I'd be ok with false positives if it helped me find all those issues.

@aclements
Copy link
Member

I bet we have similar code of dubious nature in our code base.

One of the things we're hoping to do for 1.6 is to write down the rules of pointers and Cgo. We've even tinkered with ways of enforcing these rules, but so far no concrete changes have come of that.

I wonder if automated tooling can be written that just detects if the last usage of a variable in some function is in an unsafe.Pointer(&var) kind of form.

I know that go vet does some checking of unsafe.Pointer use, though I'm not sure what exactly.

@zeebo
Copy link
Contributor Author

zeebo commented Aug 14, 2015

As far as I'm aware the only checking it does is to make sure you don't squirrel away pointer values as integer types so the GC is still aware of them. :(

@jtsylve
Copy link
Contributor

jtsylve commented Aug 14, 2015

How can I achieve a similar result that is considered "safe" unsafe code?

On Fri, Aug 14, 2015, 13:03 Jeff notifications@github.com wrote:

As far as I'm aware the only checking it does is to make sure you don't
squirrel away pointer values as integer types so the GC is still aware of
them. :(


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

@griesemer
Copy link
Contributor

FYI: I've seen this a while back (Aug 5) on the dashboard: http://build.golang.org/log/11aafe2c6f15fae5d9ab375e677e8114d366e339

@aclements
Copy link
Member

Thanks, but all of the instances of this on the dashboard were from a cluster when we first enabled the bad pointer check. Russ promptly disabled it, then fixed the problems we were able to find on arm64 and re-enabled it in 4addec3.

@jtsylve
Copy link
Contributor

jtsylve commented Aug 15, 2015

So I fixed the scoping issue. That wasn't the problem that was causing panics; however, I was able to figure out what was.

The C.z_stream structure was being allocated by cgo. zlib then allocates pointers inside of that struct and the Go GC saw them as invalid (since it had no record of the allocations). The solution was to only store a pointer to z_stream sized data so that the GC wouldn't do pointer inspection on it.

I assume this is intended behavior for the GC, but it is a real "gotya" and should be added to that new cgo documentation that was mentioned.

For reference here's the updated (working) code.

diff:

@@ -23,11 +23,16 @@ package zlib

 // #cgo LDFLAGS: -lz
 // #include <zlib.h>
+// #include <stdlib.h>
 //
 // // inflateInit is a macro so we need to do this
 // int InflateInit(z_streamp s) {
 //     return inflateInit(s);
 // }
+//
+// z_streamp new_zstream() {
+//     return (z_streamp) calloc(sizeof(z_stream), 1);
+// }
 import "C"

 import (
@@ -40,7 +45,7 @@ import (
 type reader struct {
    r     io.Reader
    inbuf []byte
-   s     C.z_stream
+   s     *C.z_stream
 }

 // NewReader creates a new ReadCloser. Reads from the returned ReadCloser
@@ -50,9 +55,10 @@ type reader struct {
 func NewReader(r io.Reader) (io.ReadCloser, error) {
    rd := &reader{
        r: r,
+       s: C.new_zstream(),
    }

-   err := C.InflateInit(&rd.s)
+   err := C.InflateInit(rd.s)
    if err != C.Z_OK {
        return nil, errors.New("Could not init inflate.")
    }
@@ -69,8 +75,9 @@ func (r *reader) Read(p []byte) (n int, err error) {
    // output.
    maxIn := int64(len(p))

+   var buf *bytes.Buffer
    if r.inbuf == nil {
-       buf := bytes.NewBuffer(make([]byte, 0, maxIn))
+       buf = bytes.NewBuffer(make([]byte, 0, maxIn))

        nIn, err := io.CopyN(buf, r.r, maxIn)
        if err != nil && err != io.EOF {
@@ -96,7 +103,7 @@ func (r *reader) Read(p []byte) (n int, err error) {
        r.s.avail_out = C.uInt(len(out))
        r.s.next_out = (*C.Bytef)(unsafe.Pointer(&out[0]))

-       ret = C.inflate(&r.s, C.Z_NO_FLUSH)
+       ret = C.inflate(r.s, C.Z_NO_FLUSH)

        if ret != C.Z_STREAM_END && ret != C.Z_OK {
            return 0, errors.New("Could not deflate input.")
@@ -126,10 +133,12 @@ func (r *reader) Read(p []byte) (n int, err error) {
 //
 // Calling Close does not close the wrapped io.Reader originally passed to NewReader
 func (r *reader) Close() error {
-   err := C.inflateEnd(&r.s)
+   err := C.inflateEnd(r.s)
    if err != C.Z_OK {
        return errors.New("Could not end inflate")
    }

+   C.free(unsafe.Pointer(r.s))
+
    return nil
 }

Full code:

// #cgo LDFLAGS: -lz
// #include <zlib.h>
// #include <stdlib.h>
//
// // inflateInit is a macro so we need to do this
// int InflateInit(z_streamp s) {
//     return inflateInit(s);
// }
//
// z_streamp new_zstream() {
//     return (z_streamp) calloc(sizeof(z_stream), 1);
// }
import "C"

import (
    "bytes"
    "errors"
    "io"
    "unsafe"
)

type reader struct {
    r     io.Reader
    inbuf []byte
    s     *C.z_stream
}

// NewReader creates a new ReadCloser. Reads from the returned ReadCloser
// read and decompress data from r. The implementation buffers input and
// may read more data than necessary from r. It is the caller's
// responsibility to call Close on the ReadCloser when done.
func NewReader(r io.Reader) (io.ReadCloser, error) {
    rd := &reader{
        r: r,
        s: C.new_zstream(),
    }

    err := C.InflateInit(rd.s)
    if err != C.Z_OK {
        return nil, errors.New("Could not init inflate.")
    }

    return rd, nil
}

func (r *reader) Read(p []byte) (n int, err error) {
    if len(p) == 0 {
        return 0, nil
    }

    // We can assume that the input will be smaller than
    // output.
    maxIn := int64(len(p))

    var buf *bytes.Buffer
    if r.inbuf == nil {
        buf = bytes.NewBuffer(make([]byte, 0, maxIn))

        nIn, err := io.CopyN(buf, r.r, maxIn)
        if err != nil && err != io.EOF {
            return 0, err
        }

        if nIn == 0 && err == io.EOF {
            return 0, io.ErrUnexpectedEOF
        }

        r.s.avail_in = C.uInt(nIn)
        r.s.next_in = (*C.Bytef)(unsafe.Pointer(&buf.Bytes()[0]))
    } else {
        // We still have input from the last call
        r.s.avail_in = C.uInt(len(r.inbuf))
        r.s.next_in = (*C.Bytef)(unsafe.Pointer(&r.inbuf[0]))
    }

    var read int
    var ret C.int
    for ret != C.Z_STREAM_END {
        out := p[read:]
        r.s.avail_out = C.uInt(len(out))
        r.s.next_out = (*C.Bytef)(unsafe.Pointer(&out[0]))

        ret = C.inflate(r.s, C.Z_NO_FLUSH)

        if ret != C.Z_STREAM_END && ret != C.Z_OK {
            return 0, errors.New("Could not deflate input.")
        }

        read = len(out) - int(r.s.avail_out)

        if r.s.avail_out == 0 {
            break
        }
    }

    if ret == C.Z_STREAM_END {
        return read, io.EOF
    }

    if r.s.avail_in == 0 {
        r.inbuf = nil
    } else {
        r.inbuf = C.GoBytes(unsafe.Pointer(r.s.next_in), C.int(r.s.avail_in))
    }

    return read, nil
}

// Close implements the io.Closer interface
//
// Calling Close does not close the wrapped io.Reader originally passed to NewReader
func (r *reader) Close() error {
    err := C.inflateEnd(r.s)
    if err != C.Z_OK {
        return errors.New("Could not end inflate")
    }

    C.free(unsafe.Pointer(r.s))

    return nil
}

@aclements
Copy link
Member

aclements commented Aug 15, 2015 via email

@aclements
Copy link
Member

BTW, @zeebo, if you have any other panics of this form (or other forms, for that matter), just having more samples would be very helpful for establishing or ruling out patterns.

@jtsylve
Copy link
Contributor

jtsylve commented Aug 15, 2015

Initially I wasn't storing a pointer to a C heap, I was allocating the struct directly on the Go heap (C.z_stream vs *C.z_stream) and passing it to C. Since CG had access to the entire struct it was causing panics by the pointers inside that struct that were initialized by zlib. Now I'm just storing a pointer to the C heap, so there are no such errors. This is likely the better way of doing it since none of those pointers need to be garbage collected anyway. Again, I assume that this is intended behavior, but it was non obvious (at least to me) so it might be nice to document it.

As far as the scoping issues, I may be missing something. The buf and p variables that I'm passing pointers to C don't go out of scope until the function returns. At that point libz is finished using them. I suppose those pointers are still stored in the z_stream struct, but they shouldn't be accessed. That being said, since there are no guarantees that a future version of libz won't invalidate this assumption, I suppose I should be storing them in the same scope as the z_stream pointer (In my case inside of the Reader struct).

@aclements
Copy link
Member

aclements commented Aug 15, 2015 via email

@jtsylve
Copy link
Contributor

jtsylve commented Aug 15, 2015

In my copy of zlib, z_stream is a pointer type and inflateInit mallocs
memory and returns the z_stream pointer to it. Perhaps your version is
different.

Indeed it must be (from zlib.h shipped with OS X)

typedef struct z_stream_s {
    Bytef    *next_in;  /* next input byte */
    uInt     avail_in;  /* number of bytes available at next_in */
    uLong    total_in;  /* total nb of input bytes read so far */

    Bytef    *next_out; /* next output byte should be put there */
    uInt     avail_out; /* remaining free space at next_out */
    uLong    total_out; /* total nb of bytes output so far */

    char     *msg;      /* last error message, NULL if no error */
    struct internal_state FAR *state; /* not visible by applications */

    alloc_func zalloc;  /* used to allocate the internal state */
    free_func  zfree;   /* used to free the internal state */
    voidpf     opaque;  /* private data object passed to zalloc and zfree */

    int     data_type;  /* best guess about the data type: binary or text */
    uLong   adler;      /* adler32 value of the uncompressed data */
    uLong   reserved;   /* reserved for future use */
} z_stream;

typedef z_stream FAR *z_streamp;
ZEXTERN int ZEXPORT inflateInit OF((z_streamp strm));

All the more reason not to make assumptions about library changes.

And, again, even if it were a struct and it contained pointers initialized
by zlib, that would be perfectly fine because the Go heap is allowed to
point to the C heap.

What about pointers to the Go heap that C adjusts? In the above case the next_in pointer is actually adjusted by the call to inflate. So now what the GC would see is a pointer into the middle of a GO allocation that it didn't set. I'm not familiar enough with the GC internals to know if that's a problem, but the panic suggests that it is. (Especially since this fix does prevent the panic)

Sorry, I was sloppy when I said "scope." In fact, the garbage collector is
free to free buf the moment after you last mention it in your code, which
is before the inflate call.

That is something I didn't know about the GC! I wouldn't have assumed that was the case since the reference is still being stored in the variable, but it does make sense.

@jtsylve
Copy link
Contributor

jtsylve commented Aug 15, 2015

Something else I just noticed is that some of those pointers in z_stream are actually function pointers (alloc_func & free_func), so they wouldn't likely be pointing at the C heap. The GC may have taken issue with those.

@rsc
Copy link
Contributor

rsc commented Aug 15, 2015

I split this into new issues #12157 (linux/arm) and #12158 (darwin/amd64), since the failure modes are different. Closing this issue.

@rsc rsc closed this as completed Aug 15, 2015
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

8 participants