garbage collection issue in FreeBSD

[dhobsd]

What steps will reproduce the problem?
1. Create a test.go with

package main

import (
       "fmt";
       "os";
       "runtime";
)

func process(file string, c chan string) {
       fmt.Printf("processing %s...\n", file);
       for i := uint(0); i < 1<<31; i++ {}
       c <- file
}

func main() {
       runtime.GOMAXPROCS(4);

       c := make(chan string);

       for i := 1; i < len(os.Args); i++ {
               go process(os.Args[i], c)
       }

       for i := 1; i < len(os.Args); i++ {
               fmt.Printf("Done processing %s\n", <-c);
       }
}

2. Compile and Run on FreeBSD

What is the expected output? What do you see instead?

Occasionally (maybe 50% of the time) it runs properly. The rest of the
time, I either get segfaults in MCentral_Free (looks like it's trying to
free nil) or the following trace:

> ./6.out a b c
processing a...
processing b...
odd span state=0 span=0xa1000d8a68 base=0xa1001b0000 sizeclass=10 n=27
size=144 npages=1
s->base sizeclass 10 v=0xa1001b0000 base=0xa1001b0000 gcref=0xa10024c9f0
blocksize=4096 nobj=27 size=144 end=0xa10024ca5c end=0xa1001b1000
throw: bad gcref

panic PC=0xa10019c478
throw+0x3e /usr/home/dho/golang/src/pkg/runtime/runtime.c:74
        throw(0x441e46, 0x0)
mlookup+0x270 /usr/home/dho/golang/src/pkg/runtime/malloc.c:164
        mlookup(0x1b0000, 0xa1, 0x0, 0x0, 0x0, ...)
malloc+0xe7 /usr/home/dho/golang/src/pkg/runtime/malloc.c:47
        malloc(0x90, 0x0)
malg+0x1e /usr/home/dho/golang/src/pkg/runtime/proc.c:737
        malg(0x8000, 0x0)
minit+0x1b /usr/home/dho/golang/src/pkg/runtime/freebsd/thread.c:164
        minit()
mstart+0x42 /usr/home/dho/golang/src/pkg/runtime/proc.c:392
        mstart()
thr_start+0xb /usr/home/dho/golang/src/pkg/runtime/freebsd/amd64/sys.s:32
        thr_start()

goroutine 4 [1]:
goexit /usr/home/dho/golang/src/pkg/runtime/proc.c:135
        goexit()
0xa100147018 unknown pc

goroutine 3 [2]:
runtime·entersyscall+0x50 /usr/home/dho/golang/src/pkg/runtime/proc.c:545
        runtime·entersyscall()
syscall·Syscall+0x5b
/usr/home/dho/golang/src/pkg/syscall/asm_freebsd_amd64.s:46
        syscall·Syscall()
syscall·Write+0x5d /usr/home/dho/golang/src/pkg/syscall/exec.go:17
        syscall·Write(0x1, 0xa1, 0x171c40, 0xa1, 0x10, ...)
os·*File·Write+0x5f /usr/home/dho/golang/src/pkg/os/file.go:162
        os·*File·Write(0x172d50, 0xa1, 0x171c40, 0xa1, 0x10, ...)
fmt·Fprintf+0xe8 /usr/home/dho/golang/src/pkg/fmt/print.go:214
        fmt·Fprintf(0x1af000, 0xa1, 0x172d50, 0xa1, 0x45a9d0, ...)
fmt·Printf+0x72 /usr/home/dho/golang/src/pkg/fmt/print.go:220
        fmt·Printf(0x45a9d0, 0x0, 0x11, 0x0, 0x444c18, ...)
main·process+0x5a /usr/home/dho/test.go:9
        main·process(0x147010, 0xa1, 0x1, 0x0, 0x192000, ...)
goexit /usr/home/dho/golang/src/pkg/runtime/proc.c:135
        goexit()
0xa100147010 unknown pc

goroutine 2 [2]:
runtime·entersyscall+0x50 /usr/home/dho/golang/src/pkg/runtime/proc.c:545
        runtime·entersyscall()
syscall·Syscall+0x5b
/usr/home/dho/golang/src/pkg/syscall/asm_freebsd_amd64.s:46
        syscall·Syscall()
syscall·Write+0x5d /usr/home/dho/golang/src/pkg/syscall/exec.go:17
        syscall·Write(0x1, 0xa1, 0x171840, 0xa1, 0x10, ...)
os·*File·Write+0x5f /usr/home/dho/golang/src/pkg/os/file.go:162
        os·*File·Write(0x172d50, 0xa1, 0x171840, 0xa1, 0x10, ...)
fmt·Fprintf+0xe8 /usr/home/dho/golang/src/pkg/fmt/print.go:214
        fmt·Fprintf(0x1af000, 0xa1, 0x172d50, 0xa1, 0x45a9d0, ...)
fmt·Printf+0x72 /usr/home/dho/golang/src/pkg/fmt/print.go:220
        fmt·Printf(0x45a9d0, 0x0, 0x11, 0x0, 0x444c18, ...)
main·process+0x5a /usr/home/dho/test.go:9
        main·process(0x147008, 0xa1, 0x1, 0x0, 0x192000, ...)
goexit /usr/home/dho/golang/src/pkg/runtime/proc.c:135
        goexit()
0xa100147008 unknown pc

goroutine 1 [4]:
gosched+0x34 /usr/home/dho/golang/src/pkg/runtime/proc.c:521
        gosched()
chanrecv+0x318 /usr/home/dho/golang/src/pkg/runtime/chan.c:319
        chanrecv(0x192000, 0xa1, 0x174f80, 0xa1, 0x0, ...)
runtime·chanrecv1+0x50 /usr/home/dho/golang/src/pkg/runtime/chan.c:415
        runtime·chanrecv1(0x192000, 0xa1)
main·main+0xc3 /usr/home/dho/test.go:23
        main·main()
mainstart+0xf /usr/home/dho/golang/src/pkg/runtime/amd64/asm.s:54
        mainstart()
goexit /usr/home/dho/golang/src/pkg/runtime/proc.c:135
        goexit()
Segmentation fault (core dumped)

What is your $GOOS?  $GOARCH?
freebsd/amd64

Which revision are you using?  (hg identify)
68ebc44e8429 tip


Please provide any additional information below.
Looks like it's my bug and my problem :)

[dhobsd]

Comment 1:

In GDB it seems to be crashing in MCentral_Alloc around here:
     80         s->ref++;
     81         v = s->freelist;
     82         s->freelist = v->next;
     83         if(s->freelist == nil) {
  41304d:       ff 42 30                incl   0x30(%rdx)        // s->ref++
  413050:       48 8b 5a 28             mov    0x28(%rdx),%rbx   // s->freelist
  413054:       48 89 5c 24 20          mov    %rbx,0x20(%rsp)   // v = ^
**413059:       48 8b 0b                mov    (%rbx),%rcx       // %rbx = 3; (3) = boom
  41305c:       48 89 4a 28             mov    %rcx,0x28(%rdx)
  413060:       48 8b 42 28             mov    0x28(%rdx),%rax
  413064:       48 83 f8 00             cmp    $0x0,%rax
No idea why the freelist is getting corrupted.

[dhobsd]

Comment 2:

There's yet another unique (and also interesting trace):
throw: unlock of unlocked lock
panic PC=0xa10019c3d0
throw+0x3e /usr/home/dho/golang/src/pkg/runtime/runtime.c:74
        throw(0x436e07, 0x0)
umtx_unlock+0x31 /usr/home/dho/golang/src/pkg/runtime/freebsd/thread.c:76
        umtx_unlock(0x6692a8, 0x0)
unlock+0x3d /usr/home/dho/golang/src/pkg/runtime/freebsd/thread.c:99
        unlock(0x6692a8, 0x0)
MCentral_Grow+0x1c /usr/home/dho/golang/src/pkg/runtime/mcentral.c:165
        MCentral_Grow(0x6692a8, 0x0)
MCentral_AllocList+0x40 /usr/home/dho/golang/src/pkg/runtime/mcentral.c:47
        MCentral_AllocList(0x6692a8, 0x0, 0x20, 0x0, 0x19c510, ...)
MCache_Alloc+0x66 /usr/home/dho/golang/src/pkg/runtime/mcache.c:23
        MCache_Alloc(0x38ca8, 0xa1, 0xa, 0x0, 0x90, ...)
malloc+0x8f /usr/home/dho/golang/src/pkg/runtime/malloc.c:31
        malloc(0x90, 0x0)
malg+0x1e /usr/home/dho/golang/src/pkg/runtime/proc.c:737
        malg(0x8000, 0x0)
minit+0x1b /usr/home/dho/golang/src/pkg/runtime/freebsd/thread.c:164
        minit()
mstart+0x42 /usr/home/dho/golang/src/pkg/runtime/proc.c:392
        mstart()
thr_start+0xb /usr/home/dho/golang/src/pkg/runtime/freebsd/amd64/sys.s:32
        thr_start()
goroutine 4 [1]:
goexit /usr/home/dho/golang/src/pkg/runtime/proc.c:135
        goexit()
0x4233a8 unknown pc
goroutine 1 [4]:
gosched+0x34 /usr/home/dho/golang/src/pkg/runtime/proc.c:521
        gosched()
chanrecv+0x318 /usr/home/dho/golang/src/pkg/runtime/chan.c:319
        chanrecv(0x192000, 0xa1, 0x174f88, 0xa1, 0x0, ...)
runtime·chanrecv1+0x50 /usr/home/dho/golang/src/pkg/runtime/chan.c:415
        runtime·chanrecv1(0x192000, 0xa1)
main·main+0xa1 /usr/home/dho/test.go:24
        main·main()
mainstart+0xf /usr/home/dho/golang/src/pkg/runtime/amd64/asm.s:54
        mainstart()
goexit /usr/home/dho/golang/src/pkg/runtime/proc.c:135
        goexit()

[dhobsd]

Comment 3:

Is it possible that cas() is broken somehow?

[dhobsd]

Comment 4:

Interestingly, Russ's malloc changes from yesterday seem to have made a serious
difference in my ability to get some of these really weird different traces. I'm no
longer able to get the double unlock, but I now see a couple new segfaults that never
generate any traces. Part of the issue, I think, is bugs in the signal handling, but
it seems that there are still issues where m or g are improper.
--dho

[gopherbot]

Comment 5 by rd1rd2:

Looking at the code, I think this happens when param in newosproc is overwritten
after the original thread returns - but the new thread still needs it.  I don't have
easy access to a FreeBSD box so I can't test this.
But, it's very consistent with it crashing about 50% of the time.

[gopherbot]

Comment 6 by rd1rd2:

Looking at the code, I think this happens when param in newosproc is overwritten
after the original thread returns - but the new thread still needs it.  I don't have
easy access to a FreeBSD box so I can't test this.
But, it's very consistent with it crashing about 50% of the time.

[rsc]

Comment 7:

Fixed as of c36376f7c054

Owner changed to r...@golang.org.

Status changed to Fixed.