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: sweep increased allocation count #19473

Closed
reusee opened this issue Mar 9, 2017 · 11 comments
Closed

runtime: sweep increased allocation count #19473

reusee opened this issue Mar 9, 2017 · 11 comments
Milestone

Comments

@reusee
Copy link

reusee commented Mar 9, 2017

What did you do?

ran a data-collecting program

What did you expect to see?

no crash

What did you see instead?

crash

runtime: nelems=85 nalloc=6 previous allocCount=5 nfreed=65535
fatal error:      
sweep increased allocation count

runtime stack:
runtime.throw(0x8e319b, 0x20)
	/home/reus/go/src/runtime/panic.go:596 +0x95
runtime.(*mspan).sweep(0x7fb1d81add18, 0x0, 0xc420000f00)
	/home/reus/go/src/runtime/mgcsweep.go:286 +0x8fa
runtime.sweepone(0x432386)
	/home/reus/go/src/runtime/mgcsweep.go:110 +0x1b6
runtime.gosweepone.func1()
	/home/reus/go/src/runtime/mgcsweep.go:125 +0x2b
runtime.systemstack(0xc42001c000)
	/home/reus/go/src/runtime/asm_amd64.s:327 +0x79
runtime.mstart()
	/home/reus/go/src/runtime/proc.go:1119

goroutine 3 [running]:
runtime.systemstack_switch()
	/home/reus/go/src/runtime/asm_amd64.s:281 fp=0xc420026f70 sp=0xc420026f68
runtime.gosweepone(0x0)
	/home/reus/go/src/runtime/mgcsweep.go:124 +0x53 fp=0xc420026fa0 sp=0xc420026f70
runtime.bgsweep(0xc420054000)
	/home/reus/go/src/runtime/mgcsweep.go:59 +0xb4 fp=0xc420026fd8 sp=0xc420026fa0
runtime.goexit()
	/home/reus/go/src/runtime/asm_amd64.s:2142 +0x1 fp=0xc420026fe0 sp=0xc420026fd8
created by runtime.gcenable
	/home/reus/go/src/runtime/mgc.go:212 +0x61


System details

go version devel +2bd6360e3b Wed Mar 8 03:24:44 2017 +0000 linux/amd64
GOARCH="amd64"
GOBIN=""
GOEXE=""
GOHOSTARCH="amd64"
GOHOSTOS="linux"
GOOS="linux"
GOPATH="/home/reus"
GORACE=""
GOROOT="/home/reus/go"
GOTOOLDIR="/home/reus/go/pkg/tool/linux_amd64"
GCCGO="gccgo"
CC="gcc"
GOGCCFLAGS="-fPIC -m64 -pthread -fmessage-length=0 -fdebug-prefix-map=/tmp/go-build839785292=/tmp/go-build -gno-record-gcc-switches"
CXX="g++"
CGO_ENABLED="1"
CGO_CFLAGS="-g -O2"
CGO_CPPFLAGS=""
CGO_CXXFLAGS="-g -O2"
CGO_FFLAGS="-g -O2"
CGO_LDFLAGS="-g -O2"
PKG_CONFIG="pkg-config"
GOROOT/bin/go version: go version devel +2bd6360e3b Wed Mar 8 03:24:44 2017 +0000 linux/amd64
GOROOT/bin/go tool compile -V: compile version devel +2bd6360e3b Wed Mar 8 03:24:44 2017 +0000 X:framepointer
uname -sr: Linux 4.9.11-1-ARCH
/usr/lib/libc.so.6: GNU C Library (GNU libc) stable release version 2.24, by Roland McGrath et al.
gdb --version: GNU gdb (GDB) 7.12.1
@reusee
Copy link
Author

reusee commented Mar 9, 2017

> env GODEBUG=gccheckmark=1 GOTRACEBACK=crash GOGC=1 ./lalaworker all

runtime: marking free object 0xc420c28900 found at *(0xc420491790+0x18)
base=0xc420491790 k=0x6210248 s.base()=0xc42048a000 s.limit=0xc420492000 s.sizeclass=66 s.elemsize=32768 s.state=_MSpanStack
 *(base+0) = 0xc42049c380
 *(base+8) = 0xb334e0
 *(base+16) = 0xc4200141c0
 *(base+24) = 0xc420c28900 <==
 *(base+32) = 0xc42066ce01
 *(base+40) = 0x0
 *(base+48) = 0x459991
 *(base+56) = 0xc42049c380
 *(base+64) = 0xb39760
 *(base+72) = 0xc4202b0040
 *(base+80) = 0x2020202020202020
 *(base+88) = 0x2020202020202020
 *(base+96) = 0x2020202020202020
 *(base+104) = 0x20676d693c202020
 *(base+112) = 0xc42048a800
 *(base+120) = 0x2e676d692f2f3a70
 *(base+128) = 0x6d6f632e63697676
 *(base+136) = 0x343635643362342f
 *(base+144) = 0x6132336335383433
 *(base+152) = 0x3237656436346435
 *(base+160) = 0x3066346630633932
 *(base+168) = 0x34314067706a2e31
 *(base+176) = 0x2d3030362d302d36
 *(base+184) = 0x3036327c61303039
 *(base+192) = 0x2022683039335f77
 *(base+200) = 0xd3e22223d746c61
 *(base+208) = 0x202020202020200a
 *(base+216) = 0x2020202020202020
 *(base+224) = 0x2020202020202020
 *(base+232) = 0x2020202020202020
 *(base+240) = 0x63206e6170733c20
 *(base+248) = 0x6e69223d7373616c
 *(base+256) = 0x6c79747320226f66
 *(base+264) = 0x2d74786574223d65
 *(base+272) = 0x65633a6e67696c61
 *(base+280) = 0xd3e223b7265746e
 *(base+288) = 0x202020202020200a
 *(base+296) = 0x2020202020202020
 *(base+304) = 0x2020202020202020
 *(base+312) = 0x2020202020202020
 *(base+320) = 0x70733c2020202020
 *(base+328) = 0x7373616c63206e61
 *(base+336) = 0x625f6f666e69223d
 *(base+344) = 0x6170732f3c3e2267
 *(base+352) = 0x202020200a0d3e6e
 *(base+360) = 0x2020202020202020
 *(base+368) = 0x2020202020202020
 *(base+376) = 0x2020202020202020
 *(base+384) = 0x2020202020202020
 *(base+392) = 0x2020202020200a0d
 *(base+400) = 0x2020202020202020
 *(base+408) = 0x2020202020202020
 *(base+416) = 0x2020202020202020
 *(base+424) = 0x2020202020202020
 *(base+432) = 0x202020200a0d2020
 *(base+440) = 0x2020202020202020
 *(base+448) = 0x2020202020202020
 *(base+456) = 0x2020202020202020
 *(base+464) = 0x2020202020202020
 *(base+472) = 0x2020202020202020
 *(base+480) = 0x6c63206e6170733c
 *(base+488) = 0x697270223d737361
 *(base+496) = 0x6170733c3e226563
 *(base+504) = 0x3d7373616c63206e
 *(base+512) = 0xc23e226e61757922
 *(base+520) = 0x3e6e6170732f3ca5
 *(base+528) = 0x732f3c30302e3333
 *(base+536) = 0x20200a0d3e6e6170
 *(base+544) = 0x2020202020202020
 *(base+552) = 0x2020202020202020
 *(base+560) = 0x2020202020202020
 *(base+568) = 0x2020202020202020
 *(base+576) = 0xa0d202020202020
 *(base+584) = 0x2020202020202020
 *(base+592) = 0x2020202020202020
 *(base+600) = 0x2020202020202020
 *(base+608) = 0x2020202020202020
 *(base+616) = 0x2020202020202020
 *(base+624) = 0x2020202020200a0d
 *(base+632) = 0x2020202020202020
 *(base+640) = 0x2020202020202020
 *(base+648) = 0x2020202020202020
 *(base+656) = 0x2020202020202020
 *(base+664) = 0x202020200a0d2020
 *(base+672) = 0x2020202020202020
 *(base+680) = 0x2020202020202020
 *(base+688) = 0x2020202020202020
 *(base+696) = 0x2020202020202020
 *(base+704) = 0x2020202020200a0d
 *(base+712) = 0x2020202020202020
 *(base+720) = 0x2020202020202020
 *(base+728) = 0x2020202020202020
 *(base+736) = 0x6e6170732f3c2020
 *(base+744) = 0x20202020200a0d3e
 *(base+752) = 0x2020202020202020
 *(base+760) = 0x2020202020202020
 *(base+768) = 0x3c20202020202020
 *(base+776) = 0x2020200a0d3e612f
 *(base+784) = 0x2020202020202020
 *(base+792) = 0x2020202020202020
 *(base+800) = 0x200a0d2020202020
 *(base+808) = 0x2020202020202020
 *(base+816) = 0x2020202020202020
 *(base+824) = 0x2020200a0d202020
 *(base+832) = 0x2020202020202020
 *(base+840) = 0x200a0d2020202020
 *(base+848) = 0x2020202020202020
 *(base+856) = 0x2020202020202020
 *(base+864) = 0x2020200a0d202020
 *(base+872) = 0x2020202020202020
 *(base+880) = 0x2020202020202020
 *(base+888) = 0x200a0d2020202020
 *(base+896) = 0x2020202020202020
 *(base+904) = 0x2020202020202020
 *(base+912) = 0xd20202020202020
 *(base+920) = 0x202020202020200a
 *(base+928) = 0x2020202020202020
 *(base+936) = 0x2020202020202020
 *(base+944) = 0x20613c2020202020
 *(base+952) = 0x692f223d66657268
 *(base+960) = 0x393338332f6d6574
 *(base+968) = 0x616c632022333734
 *(base+976) = 0x6d657469223d7373
 *(base+984) = 0x69206164762d6a20
 *(base+992) = 0xa0d226564696873
 *(base+1000) = 0x2020202020202020
 *(base+1008) = 0x2020202020202020
 *(base+1016) = 0x2020202020202020
 ...
obj=0xc420c28900 k=0x6210614 s.base()=0xc420c28000 s.limit=0xc420c2a000 s.sizeclass=9 s.elemsize=128 s.state=_MSpanInUse
 *(obj+0) = 0x6fc23ac00
 *(obj+8) = 0x0
 *(obj+16) = 0x0
 *(obj+24) = 0x0
 *(obj+32) = 0x0
 *(obj+40) = 0x0
 *(obj+48) = 0x1
 *(obj+56) = 0x0
 *(obj+64) = 0x6fc23ac00
 *(obj+72) = 0x0
 *(obj+80) = 0x0
 *(obj+88) = 0x8d07b1
 *(obj+96) = 0x3
 *(obj+104) = 0xc42053d2c0
 *(obj+112) = 0xf
 *(obj+120) = 0x0
fatal error: marking free object

runtime stack:
runtime.throw(0x8db759, 0x13)
	/home/reus/go/src/runtime/panic.go:596 +0x95 fp=0x7f1e37ffe7c0 sp=0x7f1e37ffe7a0
runtime.greyobject(0xc420c28900, 0xc420491790, 0x18, 0xc41ff9ebb7, 0xc400000000, 0x7f1e51e6fd48, 0xc42001d228, 0x12)
	/home/reus/go/src/runtime/mgcmark.go:1249 +0x4c4 fp=0x7f1e37ffe7f0 sp=0x7f1e37ffe7c0
runtime.scanblock(0xc420491790, 0x28, 0x8f9dcd, 0xc42001d228)
	/home/reus/go/src/runtime/mgcmark.go:1080 +0x160 fp=0x7f1e37ffe868 sp=0x7f1e37ffe7f0
runtime.scanframeworker(0x7f1e37ffeb40, 0x7f1e37ffec18, 0xc42001d228)
	/home/reus/go/src/runtime/mgcmark.go:851 +0x10a fp=0x7f1e37ffe908 sp=0x7f1e37ffe868
runtime.scanstack.func1(0x7f1e37ffeb40, 0x0, 0xb408a0)
	/home/reus/go/src/runtime/mgcmark.go:774 +0x3d fp=0x7f1e37ffe930 sp=0x7f1e37ffe908
runtime.gentraceback(0xffffffffffffffff, 0xffffffffffffffff, 0x0, 0xc420543380, 0x0, 0x0, 0x7fffffff, 0x7f1e37ffed18, 0x0, 0x0, ...)
	/home/reus/go/src/runtime/traceback.go:330 +0x110f fp=0x7f1e37ffeba8 sp=0x7f1e37ffe930
runtime.scanstack(0xc420543380, 0xc42001d228)
	/home/reus/go/src/runtime/mgcmark.go:777 +0x154 fp=0x7f1e37ffed40 sp=0x7f1e37ffeba8
runtime.scang(0xc420543380, 0xc42001d228)
	/home/reus/go/src/runtime/proc.go:853 +0x203 fp=0x7f1e37ffed90 sp=0x7f1e37ffed40
runtime.markroot.func1()
	/home/reus/go/src/runtime/mgcmark.go:264 +0x77 fp=0x7f1e37ffedd0 sp=0x7f1e37ffed90
runtime.systemstack(0x7f1e37ffee30)
	/home/reus/go/src/runtime/asm_amd64.s:343 +0xab fp=0x7f1e37ffedd8 sp=0x7f1e37ffedd0
runtime.markroot(0xc42001d228, 0xcf)
	/home/reus/go/src/runtime/mgcmark.go:245 +0x2f4 fp=0x7f1e37ffee58 sp=0x7f1e37ffedd8
runtime.gcDrain(0xc42001d228, 0x6)
	/home/reus/go/src/runtime/mgcmark.go:910 +0xbe fp=0x7f1e37ffee90 sp=0x7f1e37ffee58
runtime.gcBgMarkWorker.func2()
	/home/reus/go/src/runtime/mgc.go:1505 +0xfa fp=0x7f1e37ffeec0 sp=0x7f1e37ffee90
runtime.systemstack(0xc42001f900)
	/home/reus/go/src/runtime/asm_amd64.s:327 +0x79 fp=0x7f1e37ffeec8 sp=0x7f1e37ffeec0
runtime.mstart()
	/home/reus/go/src/runtime/proc.go:1119 fp=0x7f1e37ffeed0 sp=0x7f1e37ffeec8

goroutine 18 [GC worker (idle)]:
runtime.systemstack_switch()
	/home/reus/go/src/runtime/asm_amd64.s:281 fp=0xc420022748 sp=0xc420022740
runtime.gcBgMarkWorker(0xc42001c000)
	/home/reus/go/src/runtime/mgc.go:1492 +0x20a fp=0xc4200227d8 sp=0xc420022748
runtime.goexit()
	/home/reus/go/src/runtime/asm_amd64.s:2142 +0x1 fp=0xc4200227e0 sp=0xc4200227d8
created by runtime.gcBgMarkStartWorkers
	/home/reus/go/src/runtime/mgc.go:1387 +0x7e


@reusee
Copy link
Author

reusee commented Mar 9, 2017

The following program can reproduce the issue:

package main

import (
	"github.com/jmoiron/sqlx"
	_ "github.com/lib/pq"
	"sync"
)

func main() {
	db, err := sqlx.Connect("postgres", "user=reus dbname=reus sslmode=disable")
	if err != nil {
		panic(err)
	}
	defer db.Close()

	const N = 10000

	wg := new(sync.WaitGroup)
	wg.Add(N)
	sem := make(chan bool, 4)
	for i := 0; i < N; i++ {
		sem <- true
		go func() {

			defer func() {
				<-sem
				wg.Done()
			}()

			tx := db.MustBegin()

			var text string
			err := tx.Get(&text, `INSERT INTO foo (foo) VALUES ($1) RETURNING foo`, "FOO")
			if err != nil {
				panic(err)
			}

			err = tx.Commit()
			if err != nil {
				panic(err)
			}

		}()
	}

	wg.Wait()
}

run with:

env GODEBUG=gccheckmark=1 GOTRACEBACK=crash GOGC=1 ./a

crash:

runtime:greyobject: checkmarks finds unexpected unmarked object obj=0xc4200d8100
runtime: found obj at *(0xc4200d0f90+0x18)
base=0xc4200d0f90 k=0x6210068 s.base()=0xc4200ca000 s.limit=0x0 s.sizeclass=0 s.elemsize=0 s.state=_MSpanStack
 *(base+0) = 0xc420088280
 *(base+8) = 0x7368e0
 *(base+16) = 0xc420070160
 *(base+24) = 0xc4200d8100 <==
obj=0xc4200d8100 k=0x621006c s.base()=0xc4200d8000 s.limit=0xc4200da000 s.sizeclass=9 s.elemsize=128 s.state=_MSpanInUse
 *(obj+0) = 0xc4200900a0
 *(obj+8) = 0x0
 *(obj+16) = 0x0
 *(obj+24) = 0x0
 *(obj+32) = 0x0
 *(obj+40) = 0x0
 *(obj+48) = 0x0
 *(obj+56) = 0x1
 *(obj+64) = 0x0
 *(obj+72) = 0x0
 *(obj+80) = 0x0
 *(obj+88) = 0x0
 *(obj+96) = 0xc420070920
 *(obj+104) = 0x7397e0
 *(obj+112) = 0xc42009a4c0
 *(obj+120) = 0x0
fatal error: checkmark found unmarked object

runtime stack:
runtime.throw(0x638d93, 0x1f)
	/home/reus/go/src/runtime/panic.go:596 +0x95 fp=0x7fed9ab216f8 sp=0x7fed9ab216d8
runtime.greyobject(0xc4200d8100, 0xc4200d0f90, 0x18, 0xc41fff93f7, 0xc400000000, 0x7fed9c289140, 0xc42001d828, 0x2)
	/home/reus/go/src/runtime/mgcmark.go:1234 +0x324 fp=0x7fed9ab21728 sp=0x7fed9ab216f8
runtime.scanblock(0xc4200d0f90, 0x28, 0x6445a1, 0xc42001d828)
	/home/reus/go/src/runtime/mgcmark.go:1080 +0x160 fp=0x7fed9ab217a0 sp=0x7fed9ab21728
runtime.scanframeworker(0x7fed9ab21a78, 0x7fed9ab21b50, 0xc42001d828)
	/home/reus/go/src/runtime/mgcmark.go:851 +0x10a fp=0x7fed9ab21840 sp=0x7fed9ab217a0
runtime.scanstack.func1(0x7fed9ab21a78, 0x0, 0x73ee00)
	/home/reus/go/src/runtime/mgcmark.go:774 +0x3d fp=0x7fed9ab21868 sp=0x7fed9ab21840
runtime.gentraceback(0xffffffffffffffff, 0xffffffffffffffff, 0x0, 0xc420057c80, 0x0, 0x0, 0x7fffffff, 0x7fed9ab21c50, 0x0, 0x0, ...)
	/home/reus/go/src/runtime/traceback.go:330 +0x110f fp=0x7fed9ab21ae0 sp=0x7fed9ab21868
runtime.scanstack(0xc420057c80, 0xc42001d828)
	/home/reus/go/src/runtime/mgcmark.go:777 +0x154 fp=0x7fed9ab21c78 sp=0x7fed9ab21ae0
runtime.scang(0xc420057c80, 0xc42001d828)
	/home/reus/go/src/runtime/proc.go:853 +0x203 fp=0x7fed9ab21cc8 sp=0x7fed9ab21c78
runtime.markroot.func1()
	/home/reus/go/src/runtime/mgcmark.go:264 +0x77 fp=0x7fed9ab21d08 sp=0x7fed9ab21cc8
runtime.systemstack(0x7fed9ab21d68)
	/home/reus/go/src/runtime/asm_amd64.s:343 +0xab fp=0x7fed9ab21d10 sp=0x7fed9ab21d08
runtime.markroot(0xc42001d828, 0x7fed0000001e)
	/home/reus/go/src/runtime/mgcmark.go:245 +0x2f4 fp=0x7fed9ab21d90 sp=0x7fed9ab21d10
runtime.gcDrain(0xc42001d828, 0x0)
	/home/reus/go/src/runtime/mgcmark.go:910 +0xbe fp=0x7fed9ab21dc8 sp=0x7fed9ab21d90
runtime.gchelper()
	/home/reus/go/src/runtime/mgc.go:1875 +0x98 fp=0x7fed9ab21df8 sp=0x7fed9ab21dc8
runtime.stopm()
	/home/reus/go/src/runtime/proc.go:1639 +0xdd fp=0x7fed9ab21e20 sp=0x7fed9ab21df8
runtime.gcstopm()
	/home/reus/go/src/runtime/proc.go:1840 +0xb7 fp=0x7fed9ab21e48 sp=0x7fed9ab21e20
runtime.schedule()
	/home/reus/go/src/runtime/proc.go:2172 +0x2dd fp=0x7fed9ab21e88 sp=0x7fed9ab21e48
runtime.park_m(0xc420057680)
	/home/reus/go/src/runtime/proc.go:2271 +0xb6 fp=0x7fed9ab21ec0 sp=0x7fed9ab21e88
runtime.mcall(0x0)
	/home/reus/go/src/runtime/asm_amd64.s:269 +0x5b fp=0x7fed9ab21ed0 sp=0x7fed9ab21ec0

goroutine 1 [chan send]:
runtime.gopark(0x640958, 0xc4200c80c8, 0x632ab0, 0x9, 0xc42001c016, 0x3)
	/home/reus/go/src/runtime/proc.go:271 +0x12c fp=0xc420034e00 sp=0xc420034dd0
runtime.goparkunlock(0xc4200c80c8, 0x632ab0, 0x9, 0x411016, 0x3)
	/home/reus/go/src/runtime/proc.go:277 +0x5e fp=0xc420034e40 sp=0xc420034e00
runtime.chansend(0x5e6940, 0xc4200c8070, 0x6588ce, 0xc420034f01, 0x5c3b44, 0x5c3b7a)
	/home/reus/go/src/runtime/chan.go:229 +0x27f fp=0xc420034ee0 sp=0xc420034e40
runtime.chansend1(0x5e6940, 0xc4200c8070, 0x6588ce)
	/home/reus/go/src/runtime/chan.go:113 +0x4d fp=0xc420034f20 sp=0xc420034ee0
main.main()
	/home/reus/a.go:22 +0x114 fp=0xc420034f88 sp=0xc420034f20
runtime.main()
	/home/reus/go/src/runtime/proc.go:185 +0x20a fp=0xc420034fe0 sp=0xc420034f88
runtime.goexit()
	/home/reus/go/src/runtime/asm_amd64.s:2142 +0x1 fp=0xc420034fe8 sp=0xc420034fe0

goroutine 17 [syscall, locked to thread]:
runtime.goexit()
	/home/reus/go/src/runtime/asm_amd64.s:2142 +0x1 fp=0xc420036fe8 sp=0xc420036fe0

goroutine 2 [force gc (idle)]:
runtime.gopark(0x640958, 0x753350, 0x633ebb, 0xf, 0x640814, 0x1)
	/home/reus/go/src/runtime/proc.go:271 +0x12c fp=0xc420024768 sp=0xc420024738
runtime.goparkunlock(0x753350, 0x633ebb, 0xf, 0xc420000114, 0x1)
	/home/reus/go/src/runtime/proc.go:277 +0x5e fp=0xc4200247a8 sp=0xc420024768
runtime.forcegchelper()
	/home/reus/go/src/runtime/proc.go:226 +0x9e fp=0xc4200247e0 sp=0xc4200247a8
runtime.goexit()
	/home/reus/go/src/runtime/asm_amd64.s:2142 +0x1 fp=0xc4200247e8 sp=0xc4200247e0
created by runtime.init.4
	/home/reus/go/src/runtime/proc.go:215 +0x35

goroutine 3 [GC sweep wait]:
runtime.gopark(0x640958, 0x7534e0, 0x633757, 0xd, 0x450514, 0x1)
	/home/reus/go/src/runtime/proc.go:271 +0x12c fp=0xc420024f60 sp=0xc420024f30
runtime.goparkunlock(0x7534e0, 0x633757, 0xd, 0x14, 0x1)
	/home/reus/go/src/runtime/proc.go:277 +0x5e fp=0xc420024fa0 sp=0xc420024f60
runtime.bgsweep(0xc420054000)
	/home/reus/go/src/runtime/mgcsweep.go:72 +0x127 fp=0xc420024fd8 sp=0xc420024fa0
runtime.goexit()
	/home/reus/go/src/runtime/asm_amd64.s:2142 +0x1 fp=0xc420024fe0 sp=0xc420024fd8
created by runtime.gcenable
	/home/reus/go/src/runtime/mgc.go:212 +0x61

goroutine 4 [garbage collection]:
runtime.systemstack_switch()
	/home/reus/go/src/runtime/asm_amd64.s:281 fp=0xc420025550 sp=0xc420025548
runtime.gcMarkTermination()
	/home/reus/go/src/runtime/mgc.go:1226 +0x1e9 fp=0xc420025728 sp=0xc420025550
runtime.gcMarkDone()
	/home/reus/go/src/runtime/mgc.go:1188 +0x1fe fp=0xc420025748 sp=0xc420025728
runtime.gcBgMarkWorker(0xc42001a000)
	/home/reus/go/src/runtime/mgc.go:1556 +0x2fe fp=0xc4200257d8 sp=0xc420025748
runtime.goexit()
	/home/reus/go/src/runtime/asm_amd64.s:2142 +0x1 fp=0xc4200257e0 sp=0xc4200257d8
created by runtime.gcBgMarkStartWorkers
	/home/reus/go/src/runtime/mgc.go:1387 +0x7e

goroutine 5 [GC worker (idle)]:
runtime.gopark(0x6407f0, 0xc420010170, 0x63414c, 0x10, 0x14, 0x0)
	/home/reus/go/src/runtime/proc.go:271 +0x12c fp=0xc420025f48 sp=0xc420025f18
runtime.gcBgMarkWorker(0xc42001b300)
	/home/reus/go/src/runtime/mgc.go:1439 +0x143 fp=0xc420025fd8 sp=0xc420025f48
runtime.goexit()
	/home/reus/go/src/runtime/asm_amd64.s:2142 +0x1 fp=0xc420025fe0 sp=0xc420025fd8
created by runtime.gcBgMarkStartWorkers
	/home/reus/go/src/runtime/mgc.go:1387 +0x7e

goroutine 18 [GC worker (idle)]:
runtime.gopark(0x6407f0, 0xc420070000, 0x63414c, 0x10, 0x14, 0x0)
	/home/reus/go/src/runtime/proc.go:271 +0x12c fp=0xc420020748 sp=0xc420020718
runtime.gcBgMarkWorker(0xc42001c600)
	/home/reus/go/src/runtime/mgc.go:1439 +0x143 fp=0xc4200207d8 sp=0xc420020748
runtime.goexit()
	/home/reus/go/src/runtime/asm_amd64.s:2142 +0x1 fp=0xc4200207e0 sp=0xc4200207d8
created by runtime.gcBgMarkStartWorkers
	/home/reus/go/src/runtime/mgc.go:1387 +0x7e

goroutine 19 [GC worker (idle)]:
runtime.gopark(0x6407f0, 0xc420070010, 0x63414c, 0x10, 0x14, 0x0)
	/home/reus/go/src/runtime/proc.go:271 +0x12c fp=0xc420020f48 sp=0xc420020f18
runtime.gcBgMarkWorker(0xc42001d900)
	/home/reus/go/src/runtime/mgc.go:1439 +0x143 fp=0xc420020fd8 sp=0xc420020f48
runtime.goexit()
	/home/reus/go/src/runtime/asm_amd64.s:2142 +0x1 fp=0xc420020fe0 sp=0xc420020fd8
created by runtime.gcBgMarkStartWorkers
	/home/reus/go/src/runtime/mgc.go:1387 +0x7e

goroutine 20 [finalizer wait]:
runtime.gopark(0x640958, 0x770810, 0x633b96, 0xe, 0x14, 0x1)
	/home/reus/go/src/runtime/proc.go:271 +0x12c fp=0xc420021710 sp=0xc4200216e0
runtime.goparkunlock(0x770810, 0x633b96, 0xe, 0x14, 0x1)
	/home/reus/go/src/runtime/proc.go:277 +0x5e fp=0xc420021750 sp=0xc420021710
runtime.runfinq()
	/home/reus/go/src/runtime/mfinal.go:175 +0xbd fp=0xc4200217e0 sp=0xc420021750
runtime.goexit()
	/home/reus/go/src/runtime/asm_amd64.s:2142 +0x1 fp=0xc4200217e8 sp=0xc4200217e0
created by runtime.createfing
	/home/reus/go/src/runtime/mfinal.go:156 +0x62

goroutine 21 [chan receive]:
runtime.gopark(0x640958, 0xc42008e118, 0x633501, 0xc, 0xc42001ad17, 0x3)
	/home/reus/go/src/runtime/proc.go:271 +0x12c fp=0xc420021e78 sp=0xc420021e48
runtime.goparkunlock(0xc42008e118, 0x633501, 0xc, 0x17, 0x3)
	/home/reus/go/src/runtime/proc.go:277 +0x5e fp=0xc420021eb8 sp=0xc420021e78
runtime.chanrecv(0x5e6b80, 0xc42008e0c0, 0xc420021fc0, 0x1, 0x0)
	/home/reus/go/src/runtime/chan.go:513 +0x31b fp=0xc420021f68 sp=0xc420021eb8
runtime.chanrecv2(0x5e6b80, 0xc42008e0c0, 0xc420021fc0, 0x0)
	/home/reus/go/src/runtime/chan.go:400 +0x35 fp=0xc420021fa0 sp=0xc420021f68
database/sql.(*DB).connectionOpener(0xc4200900a0)
	/home/reus/go/src/database/sql/sql.go:837 +0x4a fp=0xc420021fd8 sp=0xc420021fa0
runtime.goexit()
	/home/reus/go/src/runtime/asm_amd64.s:2142 +0x1 fp=0xc420021fe0 sp=0xc420021fd8
created by database/sql.Open
	/home/reus/go/src/database/sql/sql.go:582 +0x1fd

goroutine 66 [runnable]:
syscall.Syscall(0x1, 0x5, 0xc4200d6020, 0x23, 0x23, 0x23, 0x0)
	/home/reus/go/src/syscall/asm_linux_amd64.s:18 +0x5 fp=0xc420038598 sp=0xc420038590
syscall.write(0x5, 0xc4200d6020, 0x23, 0x200, 0x77, 0x0, 0x0)
	/home/reus/go/src/syscall/zsyscall_linux_amd64.go:1029 +0x55 fp=0xc4200385f0 sp=0xc420038598
syscall.Write(0x5, 0xc4200d6020, 0x23, 0x200, 0xc4200d6020, 0x1, 0x0)
	/home/reus/go/src/syscall/syscall_unix.go:181 +0x49 fp=0xc420038638 sp=0xc4200385f0
internal/poll.(*FD).Write(0xc420088200, 0xc4200d6020, 0x23, 0x200, 0x0, 0x0, 0x0)
	/home/reus/go/src/internal/poll/fd_unix.go:213 +0x141 fp=0xc420038698 sp=0xc420038638
net.(*netFD).Write(0xc420088200, 0xc4200d6020, 0x23, 0x200, 0x3, 0xc420070cd0, 0x3)
	/home/reus/go/src/net/fd_unix.go:225 +0x52 fp=0xc420038700 sp=0xc420038698
net.(*conn).Write(0xc42000e030, 0xc4200d6020, 0x23, 0x200, 0x0, 0x0, 0x0)
	/home/reus/go/src/net/net.go:194 +0x6d fp=0xc420038768 sp=0xc420038700
github.com/lib/pq.(*conn).send(0xc4200d6000, 0xc4200388a0)
	/home/reus/src/github.com/lib/pq/conn.go:904 +0x89 fp=0xc4200387b0 sp=0xc420038768
github.com/lib/pq.(*stmt).exec(0xc4200908c0, 0xc420070ca0, 0x1, 0x1)
	/home/reus/src/github.com/lib/pq/conn.go:1274 +0x93d fp=0xc4200388f0 sp=0xc4200387b0
github.com/lib/pq.(*conn).query(0xc4200d6000, 0x63cf57, 0x2f, 0xc420070ca0, 0x1, 0x1, 0x0, 0x0, 0x0)
	/home/reus/src/github.com/lib/pq/conn.go:856 +0x385 fp=0xc420038998 sp=0xc4200388f0
github.com/lib/pq.(*conn).QueryContext(0xc4200d6000, 0x739820, 0xc420070170, 0x63cf57, 0x2f, 0xc4200184e0, 0x1, 0x1, 0x44f7e0, 0xc420038b40, ...)
	/home/reus/src/github.com/lib/pq/conn_go18.go:18 +0x1f1 fp=0xc420038a78 sp=0xc420038998
database/sql.ctxDriverQuery(0x739820, 0xc420070170, 0x7fed9c204858, 0xc4200d6000, 0x63cf57, 0x2f, 0xc4200184e0, 0x1, 0x1, 0x42735e, ...)
	/home/reus/go/src/database/sql/ctxutil.go:48 +0x28d fp=0xc420038b00 sp=0xc420038a78
database/sql.(*DB).queryConn.func1()
	/home/reus/go/src/database/sql/sql.go:1264 +0x99 fp=0xc420038b98 sp=0xc420038b00
database/sql.withLock(0x737fa0, 0xc4200c80e0, 0xc420038cd0)
	/home/reus/go/src/database/sql/sql.go:2545 +0x65 fp=0xc420038bc0 sp=0xc420038b98
database/sql.(*DB).queryConn(0xc4200900a0, 0x739820, 0xc420070170, 0xc4200c80e0, 0x640358, 0x63cf57, 0x2f, 0xc420070c90, 0x1, 0x1, ...)
	/home/reus/go/src/database/sql/sql.go:1263 +0x664 fp=0xc420038d40 sp=0xc420038bc0
database/sql.(*Tx).QueryContext(0xc420088600, 0x739820, 0xc420070170, 0x63cf57, 0x2f, 0xc420070c90, 0x1, 0x1, 0x0, 0x0, ...)
	/home/reus/go/src/database/sql/sql.go:1729 +0x176 fp=0xc420038dc0 sp=0xc420038d40
database/sql.(*Tx).Query(0xc420088600, 0x63cf57, 0x2f, 0xc420070c90, 0x1, 0x1, 0x7fed9c2d22b1, 0xc420052702, 0xc9)
	/home/reus/go/src/database/sql/sql.go:1734 +0x82 fp=0xc420038e28 sp=0xc420038dc0
github.com/jmoiron/sqlx.(*Tx).QueryRowx(0xc4200184b0, 0x63cf57, 0x2f, 0xc420070c90, 0x1, 0x1, 0x4110b6)
	/home/reus/src/github.com/jmoiron/sqlx/sqlx.go:435 +0x73 fp=0xc420038ea0 sp=0xc420038e28
github.com/jmoiron/sqlx.Get(0x7392a0, 0xc4200184b0, 0x5e1e40, 0xc420070c80, 0x63cf57, 0x2f, 0xc420070c90, 0x1, 0x1, 0x1, ...)
	/home/reus/src/github.com/jmoiron/sqlx/sqlx.go:675 +0x6d fp=0xc420038ee8 sp=0xc420038ea0
github.com/jmoiron/sqlx.(*Tx).Get(0xc4200184b0, 0x5e1e40, 0xc420070c80, 0x63cf57, 0x2f, 0xc420070c90, 0x1, 0x1, 0x0, 0x0)
	/home/reus/src/github.com/jmoiron/sqlx/sqlx.go:443 +0x90 fp=0xc420038f50 sp=0xc420038ee8
main.main.func1(0xc4200c8070, 0xc4200103b0, 0xc4200727b0)
	/home/reus/a.go:33 +0x120 fp=0xc420038fc8 sp=0xc420038f50
runtime.goexit()
	/home/reus/go/src/runtime/asm_amd64.s:2142 +0x1 fp=0xc420038fd0 sp=0xc420038fc8
created by main.main
	/home/reus/a.go:23 +0x14a

goroutine 39 [runnable]:
runtime.gopark(0x640958, 0x770fa8, 0x633a70, 0xe, 0x2a, 0x2)
	/home/reus/go/src/runtime/proc.go:271 +0x12c fp=0xc420033810 sp=0xc4200337e0
runtime.goparkunlock(0x770fa8, 0x633a70, 0xe, 0x102a, 0x2)
	/home/reus/go/src/runtime/proc.go:277 +0x5e fp=0xc420033850 sp=0xc420033810
runtime.gcParkAssist(0xc420057288)
	/home/reus/go/src/runtime/mgcmark.go:649 +0x121 fp=0xc420033888 sp=0xc420033850
runtime.gcAssistAlloc(0xc420057200)
	/home/reus/go/src/runtime/mgcmark.go:499 +0x199 fp=0xc4200338c8 sp=0xc420033888
runtime.mallocgc(0x5, 0x0, 0x0, 0x0)
	/home/reus/go/src/runtime/malloc.go:579 +0x9c7 fp=0xc420033968 sp=0xc4200338c8
runtime.rawstring(0x5, 0x0, 0x0, 0x0, 0x0, 0x0)
	/home/reus/go/src/runtime/string.go:237 +0x85 fp=0xc420033998 sp=0xc420033968
runtime.rawstringtmp(0x0, 0x5, 0xc420033a20, 0x41114d, 0xc420102040, 0xc4200b6026, 0xc420102040)
	/home/reus/go/src/runtime/string.go:107 +0x78 fp=0xc4200339d8 sp=0xc420033998
runtime.slicebytetostring(0x0, 0xc4200b6020, 0x5, 0x200, 0x5, 0xc4200b6000)
	/home/reus/go/src/runtime/string.go:89 +0x3e fp=0xc420033a30 sp=0xc4200339d8
github.com/lib/pq.(*readBuf).string(0xc420102040, 0xc420033b43, 0xc420102040)
	/home/reus/src/github.com/lib/pq/buf.go:38 +0xd6 fp=0xc420033a88 sp=0xc420033a30
github.com/lib/pq.(*conn).simpleExec(0xc4200b6000, 0x631e6b, 0x5, 0xc420033c10, 0x0, 0x0, 0x1a200000001, 0x0, 0x0)
	/home/reus/src/github.com/lib/pq/conn.go:623 +0x331 fp=0xc420033b70 sp=0xc420033a88
github.com/lib/pq.(*conn).Begin(0xc4200b6000, 0x0, 0x0, 0x0, 0x0)
	/home/reus/src/github.com/lib/pq/conn.go:529 +0xf1 fp=0xc420033bf8 sp=0xc420033b70
github.com/lib/pq.(*conn).BeginTx(0xc4200b6000, 0x739820, 0xc420070170, 0x0, 0xc4200b6000, 0xc420033c01, 0x427875, 0x4110b6, 0xc420033c98)
	/home/reus/src/github.com/lib/pq/conn_go18.go:48 +0xd2 fp=0xc420033c48 sp=0xc420033bf8
database/sql.ctxDriverBegin(0x739820, 0xc420070170, 0x0, 0x7392e0, 0xc4200b6000, 0x42735e, 0xc420014098, 0x737fc8, 0xc420054168)
	/home/reus/go/src/database/sql/ctxutil.go:107 +0xa6 fp=0xc420033cd0 sp=0xc420033c48
database/sql.(*DB).begin.func1()
	/home/reus/go/src/database/sql/sql.go:1366 +0x6b fp=0xc420033d48 sp=0xc420033cd0
database/sql.withLock(0x737fa0, 0xc4200c8000, 0xc420033dd8)
	/home/reus/go/src/database/sql/sql.go:2545 +0x65 fp=0xc420033d70 sp=0xc420033d48
database/sql.(*DB).begin(0xc4200900a0, 0x739820, 0xc420070170, 0x0, 0xc420057201, 0xc4200e9e78, 0x0, 0x0)
	/home/reus/go/src/database/sql/sql.go:1365 +0x152 fp=0xc420033e18 sp=0xc420033d70
database/sql.(*DB).BeginTx(0xc4200900a0, 0x739820, 0xc420070170, 0x0, 0xc420028a80, 0x640480, 0xc42009a198)
	/home/reus/go/src/database/sql/sql.go:1342 +0x70 fp=0xc420033e88 sp=0xc420033e18
database/sql.(*DB).Begin(0xc4200900a0, 0x640480, 0x0, 0x0)
	/home/reus/go/src/database/sql/sql.go:1356 +0x4c fp=0xc420033ed0 sp=0xc420033e88
github.com/jmoiron/sqlx.(*DB).Beginx(0xc4200727b0, 0xc4200e9f50, 0xc4200e9f58, 0xc42009a180)
	/home/reus/src/github.com/jmoiron/sqlx/sqlx.go:335 +0x32 fp=0xc420033f20 sp=0xc420033ed0
github.com/jmoiron/sqlx.(*DB).MustBegin(0xc4200727b0, 0x640480)
	/home/reus/src/github.com/jmoiron/sqlx/sqlx.go:326 +0x2b fp=0xc420033f50 sp=0xc420033f20
main.main.func1(0xc4200c8070, 0xc4200103b0, 0xc4200727b0)
	/home/reus/a.go:30 +0x69 fp=0xc420033fc8 sp=0xc420033f50
runtime.goexit()
	/home/reus/go/src/runtime/asm_amd64.s:2142 +0x1 fp=0xc420033fd0 sp=0xc420033fc8
created by main.main
	/home/reus/a.go:23 +0x14a

goroutine 46 [runnable]:
syscall.Syscall(0x1, 0x7, 0xc4200d62e0, 0xc, 0xc, 0xc, 0x0)
	/home/reus/go/src/syscall/asm_linux_amd64.s:18 +0x5 fp=0xc420032b20 sp=0xc420032b18
syscall.write(0x7, 0xc4200d62e0, 0xc, 0x200, 0x77, 0x0, 0x0)
	/home/reus/go/src/syscall/zsyscall_linux_amd64.go:1029 +0x55 fp=0xc420032b78 sp=0xc420032b20
syscall.Write(0x7, 0xc4200d62e0, 0xc, 0x200, 0x30, 0xc420032c70, 0x427a74)
	/home/reus/go/src/syscall/syscall_unix.go:181 +0x49 fp=0xc420032bc0 sp=0xc420032b78
internal/poll.(*FD).Write(0xc420088300, 0xc4200d62e0, 0xc, 0x200, 0x0, 0x0, 0x0)
	/home/reus/go/src/internal/poll/fd_unix.go:213 +0x141 fp=0xc420032c20 sp=0xc420032bc0
net.(*netFD).Write(0xc420088300, 0xc4200d62e0, 0xc, 0x200, 0x0, 0x19, 0x2)
	/home/reus/go/src/net/fd_unix.go:225 +0x52 fp=0xc420032c88 sp=0xc420032c20
net.(*conn).Write(0xc4200fa000, 0xc4200d62e0, 0xc, 0x200, 0x0, 0x0, 0x0)
	/home/reus/go/src/net/net.go:194 +0x6d fp=0xc420032cf0 sp=0xc420032c88
github.com/lib/pq.(*conn).send(0xc4200d62c0, 0xc420032df0)
	/home/reus/src/github.com/lib/pq/conn.go:904 +0x89 fp=0xc420032d38 sp=0xc420032cf0
github.com/lib/pq.(*conn).simpleExec(0xc4200d62c0, 0x6320cd, 0x6, 0xc420032ea0, 0x41114d, 0xc420014158, 0x737fc8, 0xc42008e120, 0xc4200e0158)
	/home/reus/src/github.com/lib/pq/conn.go:617 +0x188 fp=0xc420032e20 sp=0xc420032d38
github.com/lib/pq.(*conn).Commit(0xc4200d62c0, 0x0, 0x0)
	/home/reus/src/github.com/lib/pq/conn.go:572 +0x15d fp=0xc420032e98 sp=0xc420032e20
database/sql.(*Tx).Commit.func1()
	/home/reus/go/src/database/sql/sql.go:1509 +0x3c fp=0xc420032ec8 sp=0xc420032e98
database/sql.withLock(0x737fa0, 0xc4200c8150, 0xc420032f28)
	/home/reus/go/src/database/sql/sql.go:2545 +0x65 fp=0xc420032ef0 sp=0xc420032ec8
database/sql.(*Tx).Commit(0xc4200ea200, 0x5e1e40, 0xc4200105b0)
	/home/reus/go/src/database/sql/sql.go:1508 +0xd4 fp=0xc420032f50 sp=0xc420032ef0
main.main.func1(0xc4200c8070, 0xc4200103b0, 0xc4200727b0)
	/home/reus/a.go:38 +0x156 fp=0xc420032fc8 sp=0xc420032f50
runtime.goexit()
	/home/reus/go/src/runtime/asm_amd64.s:2142 +0x1 fp=0xc420032fd0 sp=0xc420032fc8
created by main.main
	/home/reus/a.go:23 +0x14a

goroutine 10 [runnable]:
runtime.gopark(0x640958, 0x770fa8, 0x633a70, 0xe, 0x2a, 0x2)
	/home/reus/go/src/runtime/proc.go:271 +0x12c fp=0xc4200f7558 sp=0xc4200f7528
runtime.goparkunlock(0x770fa8, 0x633a70, 0xe, 0xc4200b652a, 0x2)
	/home/reus/go/src/runtime/proc.go:277 +0x5e fp=0xc4200f7598 sp=0xc4200f7558
runtime.gcParkAssist(0xc420057588)
	/home/reus/go/src/runtime/mgcmark.go:649 +0x121 fp=0xc4200f75d0 sp=0xc4200f7598
runtime.gcAssistAlloc(0xc420057500)
	/home/reus/go/src/runtime/mgcmark.go:499 +0x199 fp=0xc4200f7610 sp=0xc4200f75d0
runtime.mallocgc(0x18, 0x5f14a0, 0xc4200b6501, 0x770900)
	/home/reus/go/src/runtime/malloc.go:579 +0x9c7 fp=0xc4200f76b0 sp=0xc4200f7610
runtime.newobject(0x5f14a0, 0xc420096040)
	/home/reus/go/src/runtime/malloc.go:803 +0x38 fp=0xc4200f76e0 sp=0xc4200f76b0
github.com/lib/pq.(*conn).recv(0xc4200b6580, 0xc420096040, 0xc4200180c0)
	/home/reus/src/github.com/lib/pq/conn.go:986 +0x31 fp=0xc4200f7720 sp=0xc4200f76e0
github.com/lib/pq.(*conn).startup(0xc4200b6580, 0xc4200180c0)
	/home/reus/src/github.com/lib/pq/conn.go:1105 +0xbb5 fp=0xc4200f78b8 sp=0xc4200f7720
github.com/lib/pq.DialOpen(0x7389a0, 0x770900, 0x63ae87, 0x25, 0x0, 0x0, 0x0, 0x0)
	/home/reus/src/github.com/lib/pq/conn.go:335 +0x76e fp=0xc4200f7af8 sp=0xc4200f78b8
github.com/lib/pq.Open(0x63ae87, 0x25, 0x0, 0x0, 0x0, 0x0)
	/home/reus/src/github.com/lib/pq/conn.go:242 +0x4d fp=0xc4200f7b48 sp=0xc4200f7af8
github.com/lib/pq.(*drv).Open(0x770900, 0x63ae87, 0x25, 0x0, 0x0, 0x0, 0x0)
	/home/reus/src/github.com/lib/pq/conn.go:41 +0x35 fp=0xc4200f7b88 sp=0xc4200f7b48
database/sql.(*DB).conn(0xc4200900a0, 0x739820, 0xc420070170, 0x1, 0x0, 0x0, 0x0)
	/home/reus/go/src/database/sql/sql.go:965 +0x146 fp=0xc4200f7d70 sp=0xc4200f7b88
database/sql.(*DB).begin(0xc4200900a0, 0x739820, 0xc420070170, 0x0, 0xc420057501, 0xc420022678, 0x0, 0x0)
	/home/reus/go/src/database/sql/sql.go:1360 +0x8a fp=0xc4200f7e18 sp=0xc4200f7d70
database/sql.(*DB).BeginTx(0xc4200900a0, 0x739820, 0xc420070170, 0x0, 0xc420052700, 0x640480, 0xc420014198)
	/home/reus/go/src/database/sql/sql.go:1342 +0x70 fp=0xc4200f7e88 sp=0xc4200f7e18
database/sql.(*DB).Begin(0xc4200900a0, 0x640480, 0x0, 0x0)
	/home/reus/go/src/database/sql/sql.go:1356 +0x4c fp=0xc4200f7ed0 sp=0xc4200f7e88
github.com/jmoiron/sqlx.(*DB).Beginx(0xc4200727b0, 0xc420022750, 0xc420022758, 0xc420014180)
	/home/reus/src/github.com/jmoiron/sqlx/sqlx.go:335 +0x32 fp=0xc4200f7f20 sp=0xc4200f7ed0
github.com/jmoiron/sqlx.(*DB).MustBegin(0xc4200727b0, 0x640480)
	/home/reus/src/github.com/jmoiron/sqlx/sqlx.go:326 +0x2b fp=0xc4200f7f50 sp=0xc4200f7f20
main.main.func1(0xc4200c8070, 0xc4200103b0, 0xc4200727b0)
	/home/reus/a.go:30 +0x69 fp=0xc4200f7fc8 sp=0xc4200f7f50
runtime.goexit()
	/home/reus/go/src/runtime/asm_amd64.s:2142 +0x1 fp=0xc4200f7fd0 sp=0xc4200f7fc8
created by main.main
	/home/reus/a.go:23 +0x14a

goroutine 11 [runnable]:
runtime.gopark(0x640958, 0x75fb20, 0x632f5f, 0xa, 0xc4200dc319, 0x4)
	/home/reus/go/src/runtime/proc.go:271 +0x12c fp=0xc420022d48 sp=0xc420022d18
runtime.goparkunlock(0x75fb20, 0x632f5f, 0xa, 0x19, 0x4)
	/home/reus/go/src/runtime/proc.go:277 +0x5e fp=0xc420022d88 sp=0xc420022d48
runtime.semacquire1(0x770f78, 0x411100, 0x0)
	/home/reus/go/src/runtime/sema.go:144 +0x1c1 fp=0xc420022df8 sp=0xc420022d88
runtime.semacquire(0x770f78)
	/home/reus/go/src/runtime/sema.go:95 +0x39 fp=0xc420022e20 sp=0xc420022df8
runtime.gcMarkDone()
	/home/reus/go/src/runtime/mgc.go:1090 +0x31 fp=0xc420022e40 sp=0xc420022e20
runtime.gcAssistAlloc(0xc420057680)
	/home/reus/go/src/runtime/mgcmark.go:474 +0x1cc fp=0xc420022e80 sp=0xc420022e40
runtime.mallocgc(0x10, 0x5fbbe0, 0x640a01, 0xc4200576a8)
	/home/reus/go/src/runtime/malloc.go:579 +0x9c7 fp=0xc420022f20 sp=0xc420022e80
runtime.newobject(0x5fbbe0, 0x4beb3f)
	/home/reus/go/src/runtime/malloc.go:803 +0x38 fp=0xc420022f50 sp=0xc420022f20
database/sql.(*Rows).close(0xc4200d8080, 0x7368e0, 0xc420070160, 0xc420088000, 0xc4200dc101)
	/home/reus/go/src/database/sql/sql.go:2421 +0x31 fp=0xc420022f90 sp=0xc420022f50
database/sql.(*Rows).awaitDone(0xc4200d8080, 0x7397e0, 0xc4200da000)
	/home/reus/go/src/database/sql/sql.go:2122 +0x8e fp=0xc420022fc8 sp=0xc420022f90
runtime.goexit()
	/home/reus/go/src/runtime/asm_amd64.s:2142 +0x1 fp=0xc420022fd0 sp=0xc420022fc8
created by database/sql.(*Rows).initContextClose
	/home/reus/go/src/database/sql/sql.go:2116 +0x92

goroutine 42 [runnable]:
runtime.gopark(0x640958, 0x770fa8, 0x633a70, 0xe, 0x2a, 0x2)
	/home/reus/go/src/runtime/proc.go:271 +0x12c fp=0xc4200d05c8 sp=0xc4200d0598
runtime.goparkunlock(0x770fa8, 0x633a70, 0xe, 0x44f72a, 0x2)
	/home/reus/go/src/runtime/proc.go:277 +0x5e fp=0xc4200d0608 sp=0xc4200d05c8
runtime.gcParkAssist(0xc420057b88)
	/home/reus/go/src/runtime/mgcmark.go:649 +0x121 fp=0xc4200d0640 sp=0xc4200d0608
runtime.gcAssistAlloc(0xc420057b00)
	/home/reus/go/src/runtime/mgcmark.go:499 +0x199 fp=0xc4200d0680 sp=0xc4200d0640
runtime.mallocgc(0x10, 0x5fbbe0, 0x640a01, 0xc420057b28)
	/home/reus/go/src/runtime/malloc.go:579 +0x9c7 fp=0xc4200d0720 sp=0xc4200d0680
runtime.newobject(0x5fbbe0, 0x4beb3f)
	/home/reus/go/src/runtime/malloc.go:803 +0x38 fp=0xc4200d0750 sp=0xc4200d0720
database/sql.(*Rows).close(0xc4200ea080, 0x7368e0, 0xc420070160, 0x430628, 0x640820)
	/home/reus/go/src/database/sql/sql.go:2421 +0x31 fp=0xc4200d0790 sp=0xc4200d0750
database/sql.(*Rows).awaitDone(0xc4200ea080, 0x7397e0, 0xc4200e0080)
	/home/reus/go/src/database/sql/sql.go:2122 +0x8e fp=0xc4200d07c8 sp=0xc4200d0790
runtime.goexit()
	/home/reus/go/src/runtime/asm_amd64.s:2142 +0x1 fp=0xc4200d07d0 sp=0xc4200d07c8
created by database/sql.(*Rows).initContextClose
	/home/reus/go/src/database/sql/sql.go:2116 +0x92

goroutine 27 [runnable (scan)]:
runtime.gopark(0x640958, 0x770fa8, 0x633a70, 0xe, 0x2a, 0x2)
	/home/reus/go/src/runtime/proc.go:271 +0x12c fp=0xc4200d0dc8 sp=0xc4200d0d98
runtime.goparkunlock(0x770fa8, 0x633a70, 0xe, 0x44f72a, 0x2)
	/home/reus/go/src/runtime/proc.go:277 +0x5e fp=0xc4200d0e08 sp=0xc4200d0dc8
runtime.gcParkAssist(0xc420057d08)
	/home/reus/go/src/runtime/mgcmark.go:649 +0x121 fp=0xc4200d0e40 sp=0xc4200d0e08
runtime.gcAssistAlloc(0xc420057c80)
	/home/reus/go/src/runtime/mgcmark.go:499 +0x199 fp=0xc4200d0e80 sp=0xc4200d0e40
runtime.mallocgc(0x10, 0x5fbbe0, 0x640a01, 0xc420057ca8)
	/home/reus/go/src/runtime/malloc.go:579 +0x9c7 fp=0xc4200d0f20 sp=0xc4200d0e80
runtime.newobject(0x5fbbe0, 0x4beb3f)
	/home/reus/go/src/runtime/malloc.go:803 +0x38 fp=0xc4200d0f50 sp=0xc4200d0f20
database/sql.(*Rows).close(0xc420088280, 0x7368e0, 0xc420070160, 0xc4200d8100, 0xc420062301)
	/home/reus/go/src/database/sql/sql.go:2421 +0x31 fp=0xc4200d0f90 sp=0xc4200d0f50
database/sql.(*Rows).awaitDone(0xc420088280, 0x7397e0, 0xc42009a480)
	/home/reus/go/src/database/sql/sql.go:2122 +0x8e fp=0xc4200d0fc8 sp=0xc4200d0f90
runtime.goexit()
	/home/reus/go/src/runtime/asm_amd64.s:2142 +0x1 fp=0xc4200d0fd0 sp=0xc4200d0fc8
created by database/sql.(*Rows).initContextClose
	/home/reus/go/src/database/sql/sql.go:2116 +0x92

goroutine 62 [runnable]:
database/sql.(*Rows).awaitDone(0xc420110000, 0x7397e0, 0xc4200142c0)
	/home/reus/go/src/database/sql/sql.go:2120 fp=0xc4200e97c8 sp=0xc4200e97c0
runtime.goexit()
	/home/reus/go/src/runtime/asm_amd64.s:2142 +0x1 fp=0xc4200e97d0 sp=0xc4200e97c8
created by database/sql.(*Rows).initContextClose
	/home/reus/go/src/database/sql/sql.go:2116 +0x92

goroutine 30 [runnable]:
runtime.gopark(0x640958, 0x770fa8, 0x633a70, 0xe, 0x2a, 0x2)
	/home/reus/go/src/runtime/proc.go:271 +0x12c fp=0xc4200ce5c8 sp=0xc4200ce598
runtime.goparkunlock(0x770fa8, 0x633a70, 0xe, 0x44f72a, 0x2)
	/home/reus/go/src/runtime/proc.go:277 +0x5e fp=0xc4200ce608 sp=0xc4200ce5c8
runtime.gcParkAssist(0xc420001d08)
	/home/reus/go/src/runtime/mgcmark.go:649 +0x121 fp=0xc4200ce640 sp=0xc4200ce608
runtime.gcAssistAlloc(0xc420001c80)
	/home/reus/go/src/runtime/mgcmark.go:499 +0x199 fp=0xc4200ce680 sp=0xc4200ce640
runtime.mallocgc(0x10, 0x5fbbe0, 0x640a01, 0xc420001ca8)
	/home/reus/go/src/runtime/malloc.go:579 +0x9c7 fp=0xc4200ce720 sp=0xc4200ce680
runtime.newobject(0x5fbbe0, 0x4beb3f)
	/home/reus/go/src/runtime/malloc.go:803 +0x38 fp=0xc4200ce750 sp=0xc4200ce720
database/sql.(*Rows).close(0xc420088480, 0x7368e0, 0xc420070160, 0x0, 0x0)
	/home/reus/go/src/database/sql/sql.go:2421 +0x31 fp=0xc4200ce790 sp=0xc4200ce750
database/sql.(*Rows).awaitDone(0xc420088480, 0x7397e0, 0xc42009a580)
	/home/reus/go/src/database/sql/sql.go:2122 +0x8e fp=0xc4200ce7c8 sp=0xc4200ce790
runtime.goexit()
	/home/reus/go/src/runtime/asm_amd64.s:2142 +0x1 fp=0xc4200ce7d0 sp=0xc4200ce7c8
created by database/sql.(*Rows).initContextClose
	/home/reus/go/src/database/sql/sql.go:2116 +0x92

goroutine 45 [runnable]:
runtime.gopark(0x640958, 0x770fa8, 0x633a70, 0xe, 0x2a, 0x2)
	/home/reus/go/src/runtime/proc.go:271 +0x12c fp=0xc4200e9dc8 sp=0xc4200e9d98
runtime.goparkunlock(0x770fa8, 0x633a70, 0xe, 0x44f72a, 0x2)
	/home/reus/go/src/runtime/proc.go:277 +0x5e fp=0xc4200e9e08 sp=0xc4200e9dc8
runtime.gcParkAssist(0xc420104388)
	/home/reus/go/src/runtime/mgcmark.go:649 +0x121 fp=0xc4200e9e40 sp=0xc4200e9e08
runtime.gcAssistAlloc(0xc420104300)
	/home/reus/go/src/runtime/mgcmark.go:499 +0x199 fp=0xc4200e9e80 sp=0xc4200e9e40
runtime.mallocgc(0x10, 0x5fbbe0, 0x640a01, 0xc420104328)
	/home/reus/go/src/runtime/malloc.go:579 +0x9c7 fp=0xc4200e9f20 sp=0xc4200e9e80
runtime.newobject(0x5fbbe0, 0x4beb3f)
	/home/reus/go/src/runtime/malloc.go:803 +0x38 fp=0xc4200e9f50 sp=0xc4200e9f20
database/sql.(*Rows).close(0xc4200ea180, 0x7368e0, 0xc420070160, 0x0, 0x454a71)
	/home/reus/go/src/database/sql/sql.go:2421 +0x31 fp=0xc4200e9f90 sp=0xc4200e9f50
database/sql.(*Rows).awaitDone(0xc4200ea180, 0x7397e0, 0xc4200e0100)
	/home/reus/go/src/database/sql/sql.go:2122 +0x8e fp=0xc4200e9fc8 sp=0xc4200e9f90
runtime.goexit()
	/home/reus/go/src/runtime/asm_amd64.s:2142 +0x1 fp=0xc4200e9fd0 sp=0xc4200e9fc8
created by database/sql.(*Rows).initContextClose
	/home/reus/go/src/database/sql/sql.go:2116 +0x92

goroutine 47 [runnable]:
database/sql.(*Tx).awaitDone(0xc4200ea200)
	/home/reus/go/src/database/sql/sql.go:1437 fp=0xc4200ca7d8 sp=0xc4200ca7d0
runtime.goexit()
	/home/reus/go/src/runtime/asm_amd64.s:2142 +0x1 fp=0xc4200ca7e0 sp=0xc4200ca7d8
created by database/sql.(*DB).begin
	/home/reus/go/src/database/sql/sql.go:1383 +0x26e

goroutine 33 [runnable]:
runtime.gopark(0x640958, 0x770fa8, 0x633a70, 0xe, 0x2a, 0x2)
	/home/reus/go/src/runtime/proc.go:271 +0x12c fp=0xc4200265c8 sp=0xc420026598
runtime.goparkunlock(0x770fa8, 0x633a70, 0xe, 0x44f72a, 0x2)
	/home/reus/go/src/runtime/proc.go:277 +0x5e fp=0xc420026608 sp=0xc4200265c8
runtime.gcParkAssist(0xc420106088)
	/home/reus/go/src/runtime/mgcmark.go:649 +0x121 fp=0xc420026640 sp=0xc420026608
runtime.gcAssistAlloc(0xc420106000)
	/home/reus/go/src/runtime/mgcmark.go:499 +0x199 fp=0xc420026680 sp=0xc420026640
runtime.mallocgc(0x10, 0x5fbbe0, 0x640a01, 0xc420106028)
	/home/reus/go/src/runtime/malloc.go:579 +0x9c7 fp=0xc420026720 sp=0xc420026680
runtime.newobject(0x5fbbe0, 0x4beb3f)
	/home/reus/go/src/runtime/malloc.go:803 +0x38 fp=0xc420026750 sp=0xc420026720
database/sql.(*Rows).close(0xc420088580, 0x7368e0, 0xc420070160, 0x0, 0x454a71)
	/home/reus/go/src/database/sql/sql.go:2421 +0x31 fp=0xc420026790 sp=0xc420026750
database/sql.(*Rows).awaitDone(0xc420088580, 0x7397e0, 0xc42009a600)
	/home/reus/go/src/database/sql/sql.go:2122 +0x8e fp=0xc4200267c8 sp=0xc420026790
runtime.goexit()
	/home/reus/go/src/runtime/asm_amd64.s:2142 +0x1 fp=0xc4200267d0 sp=0xc4200267c8
created by database/sql.(*Rows).initContextClose
	/home/reus/go/src/database/sql/sql.go:2116 +0x92

goroutine 67 [runnable]:
runtime.gopark(0x640958, 0x770fa8, 0x633a70, 0xe, 0x2a, 0x2)
	/home/reus/go/src/runtime/proc.go:271 +0x12c fp=0xc420026dc8 sp=0xc420026d98
runtime.goparkunlock(0x770fa8, 0x633a70, 0xe, 0x73982a, 0x2)
	/home/reus/go/src/runtime/proc.go:277 +0x5e fp=0xc420026e08 sp=0xc420026dc8
runtime.gcParkAssist(0xc420106208)
	/home/reus/go/src/runtime/mgcmark.go:649 +0x121 fp=0xc420026e40 sp=0xc420026e08
runtime.gcAssistAlloc(0xc420106180)
	/home/reus/go/src/runtime/mgcmark.go:499 +0x199 fp=0xc420026e80 sp=0xc420026e40
runtime.mallocgc(0x60, 0x0, 0xc420026f01, 0xc42009a1c0)
	/home/reus/go/src/runtime/malloc.go:579 +0x9c7 fp=0xc420026f20 sp=0xc420026e80
runtime.makechan(0x5e6b80, 0x0, 0x0)
	/home/reus/go/src/runtime/chan.go:83 +0xa9 fp=0xc420026f68 sp=0xc420026f20
context.(*cancelCtx).Done(0xc42009a640, 0x0)
	/home/reus/go/src/context/context.go:328 +0x95 fp=0xc420026fa8 sp=0xc420026f68
database/sql.(*Tx).awaitDone(0xc420088600)
	/home/reus/go/src/database/sql/sql.go:1440 +0x34 fp=0xc420026fd8 sp=0xc420026fa8
runtime.goexit()
	/home/reus/go/src/runtime/asm_amd64.s:2142 +0x1 fp=0xc420026fe0 sp=0xc420026fd8
created by database/sql.(*DB).begin
	/home/reus/go/src/database/sql/sql.go:1383 +0x26e
fish: 'env GODEBUG=gccheckmark=1 GOTRA…' terminated by signal SIGABRT (Abort)

@reusee
Copy link
Author

reusee commented Mar 9, 2017

Bisecting shows that it's introduced by commit c026845

@bradfitz
Copy link
Contributor

bradfitz commented Mar 9, 2017

@aclements, I'll let you either keep this or dup it into #19468 or #19029 as you wish.

I don't see how a database/sql change (c026845) can cause runtime crashes, unless the compiler is getting something wrong and that change just happens to tickle it.

@bradfitz bradfitz added this to the Go1.9 milestone Mar 9, 2017
@rasky
Copy link
Member

rasky commented Mar 9, 2017

@reusee can you try to keep c026845 as a local change and bisect before that? it could be a compiler/runtime bug which is triggered by the code as modified by that commit, as you would need to reapply that commit on top of previous commits.

@reusee
Copy link
Author

reusee commented Mar 9, 2017

@rasky I'll give it a try.

And I found that it's context.cancelCtx.cancel that trigger the crash: https://github.com/golang/go/blob/master/src/context/context.go#L367. But I'm not able to make a reproduce with context yet.

@reusee
Copy link
Author

reusee commented Mar 9, 2017

Backporting c026845 and bisecting gives 8179b9b as the first bad commit.

@rasky
Copy link
Member

rasky commented Mar 9, 2017

/cc @randall77 as author of the commit causing regression

@josharian
Copy link
Contributor

This is probably a dup of #19078.

@randall77
Copy link
Contributor

#19078 has been fixed - can someone check whether this issue is fixed on tip?

@reusee
Copy link
Author

reusee commented Mar 14, 2017

It's fixed.

@reusee reusee closed this as completed Mar 14, 2017
@golang golang locked and limited conversation to collaborators Mar 14, 2018
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

7 participants