api-analytics icon indicating copy to clipboard operation
api-analytics copied to clipboard

Bug: go race condition causing a SIGSEGV

Open JasonLovesDoggo opened this issue 1 year ago • 1 comments

I've been having memory leak issues for ~7 months now on a project of mine and I traced it to this project see the following panic log.

error
2024/12/20 23:50:19 [Recovery] 2024/12/20 - 23:50:19 panic recovered:
error
runtime error: invalid memory address or nil pointer dereference
error
/usr/local/go/src/runtime/panic.go:261 (0x4506d7)
info
/usr/local/go/src/runtime/signal_unix.go:881 (0x4506a5)
info
/usr/local/go/src/runtime/mbitmap_allocheaders.go:535 (0x4169f9)
info
/usr/local/go/src/runtime/slice.go:258 (0x451de4)
info
/go/pkg/mod/github.com/tom-draper/api-analytics/analytics/go/[email protected]/core.go:50 (0x99a35e)
info
/go/pkg/mod/github.com/tom-draper/api-analytics/analytics/go/[email protected]/analytics.go:40 (0x99d536)
info
/go/pkg/mod/github.com/gin-gonic/[email protected]/context.go:185 (0x8db479)
info
/go/pkg/mod/github.com/gin-gonic/[email protected]/recovery.go:102 (0x8db467)
info
/go/pkg/mod/github.com/gin-gonic/[email protected]/context.go:185 (0x8db479)
info
/go/pkg/mod/github.com/gin-gonic/[email protected]/recovery.go:102 (0x8db467)
info
/go/pkg/mod/github.com/gin-gonic/[email protected]/context.go:185 (0x8da5a4)
info
/go/pkg/mod/github.com/gin-gonic/[email protected]/logger.go:249 (0x8da58b)
info
/go/pkg/mod/github.com/gin-gonic/[email protected]/context.go:185 (0x8d9991)
info
/go/pkg/mod/github.com/gin-gonic/[email protected]/gin.go:633 (0x8d9400)
info
/go/pkg/mod/github.com/gin-gonic/[email protected]/gin.go:589 (0x8d9091)
info
/usr/local/go/src/net/http/server.go:3137 (0x66922d)
info
/usr/local/go/src/net/http/server.go:2039 (0x665327)
info
/usr/local/go/src/runtime/asm_amd64.s:1695 (0x46e1e0)
info
info
SIGSEGV: segmentation violation
info
PC=0x416217 m=9 sigcode=1 addr=0x20
info
info
goroutine 0 gp=0xc0003a6540 m=9 mp=0xc00058a008 [idle]:
info
runtime.(*mspan).typePointersOfUnchecked(0xc009a4ab00?, 0xc00010a1a0?)
info
	/usr/local/go/src/runtime/mbitmap_allocheaders.go:202 +0x37 fp=0xc0002e9e80 sp=0xc0002e9e60 pc=0x416217
info
runtime.scanobject(0xc00003f768?, 0xc00003f768)
info
	/usr/local/go/src/runtime/mgcmark.go:1446 +0xb5 fp=0xc0002e9f10 sp=0xc0002e9e80 pc=0x421b95
info
runtime.gcDrain(0xc00003f768, 0x3)
info
	/usr/local/go/src/runtime/mgcmark.go:1242 +0x1f4 fp=0xc0002e9f78 sp=0xc0002e9f10 pc=0x4214f4
info
runtime.gcDrainMarkWorkerDedicated(...)
info
	/usr/local/go/src/runtime/mgcmark.go:1124
info
runtime.gcBgMarkWorker.func2()
info
	/usr/local/go/src/runtime/mgc.go:1387 +0xa5 fp=0xc0002e9fc8 sp=0xc0002e9f78 pc=0x41db65
info
runtime.systemstack(0x0)
info
	/usr/local/go/src/runtime/asm_amd64.s:509 +0x4a fp=0xc0002e9fd8 sp=0xc0002e9fc8 pc=0x46c3aa

The rest of the panic log is 20k+ lines of listing all goroutines on my project.

JasonLovesDoggo avatar Dec 21 '24 02:12 JasonLovesDoggo

From a little guesswork I'm assuming it's due to a race condition in the logging code where requests data is being passed to a goroutine and then immediately set to nil as the goroutine tries to access the requests slice after it's been nullified

It could also be due to shared slice access between goroutines without synchronization

either way, sending a copy()'d requests to the goroutine before setting to nil should fix it

JasonLovesDoggo avatar Dec 21 '24 02:12 JasonLovesDoggo