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 : fatal error: malloc deadlock #41775

Closed
finnbear opened this issue Oct 4, 2020 · 7 comments
Closed

runtime : fatal error: malloc deadlock #41775

finnbear opened this issue Oct 4, 2020 · 7 comments
Labels
arch-wasm WebAssembly issues FrozenDueToAge NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one.
Milestone

Comments

@finnbear
Copy link

finnbear commented Oct 4, 2020

What version of Go are you using (go version)?

$ go version
go version go1.15.2 linux/amd64

Does this issue reproduce with the latest release?

The above is the latest release

What operating system and processor architecture are you using (go env)?

Firefox web browser on Linux

go env Output
$ GOOS=js GOARCH=wasm go env
GO111MODULE=""
GOARCH="wasm"
GOBIN=""
GOCACHE="/home/finnb/.cache/go-build"
GOENV="/home/finnb/.config/go/env"
GOEXE=""
GOFLAGS=""
GOHOSTARCH="amd64"
GOHOSTOS="linux"
GOINSECURE=""
GOMODCACHE="/home/finnb/go/pkg/mod"
GONOPROXY=""
GONOSUMDB=""
GOOS="js"
GOPATH="/home/finnb/go"
GOPRIVATE=""
GOPROXY="https://proxy.golang.org,direct"
GOROOT="/home/finnb/sdk/go1.15.2"
GOSUMDB="sum.golang.org"
GOTMPDIR=""
GOTOOLDIR="/home/finnb/sdk/go1.15.2/pkg/tool/linux_amd64"
GCCGO="gccgo"
GOWASM=""
AR="ar"
CC="gcc"
CXX="g++"
CGO_ENABLED="0"
GOMOD="/home/finnb/git/finnbear/project_name_here/src/client/go.mod"
CGO_CFLAGS="-g -O2"
CGO_CPPFLAGS=""
CGO_CXXFLAGS="-g -O2"
CGO_FFLAGS="-g -O2"
CGO_LDFLAGS="-g -O2"
PKG_CONFIG="pkg-config"
GOGCCFLAGS="-fPIC -fmessage-length=0 -fdebug-prefix-map=/tmp/go-build021444874=/tmp/go-build -gno-record-gcc-switches"

What did you do?

I refreshed the page containing my WebAssembly app.

What did you expect to see?

App works properly, neither the new page/instance of the app nor the old page/instance of the app crashes. That is to say that the app starts without error but also exits cleanly when the page is being destroyed.

What did you see instead?

first time (malloc deadlock stack trace)
fatal error: malloc deadlock wasm.js:50:14
 wasm.js:50:14
goroutine 6 [running]: wasm.js:50:14
runtime.throw(0x5dd0f, 0xf) wasm.js:50:14
	/home/finnb/sdk/go1.15.2/src/runtime/panic.go:1116 +0x7 fp=0x1471720 sp=0x14716f8 pc=0x11df0007 wasm.js:50:14
runtime.mallocgc(0x10, 0x37420, 0x16a3001, 0x16cf0007) wasm.js:50:14
	/home/finnb/sdk/go1.15.2/src/runtime/malloc.go:959 +0xd3 fp=0x14717c0 sp=0x1471720 pc=0x109a00d3 wasm.js:50:14
runtime.newobject(0x37420, 0x4042000000000000) wasm.js:50:14
	/home/finnb/sdk/go1.15.2/src/runtime/malloc.go:1195 +0x4 fp=0x14717e8 sp=0x14717c0 pc=0x109c0004 wasm.js:50:14
runtime.handleEvent() wasm.js:50:14
	/home/finnb/sdk/go1.15.2/src/runtime/lock_js.go:232 +0x2 fp=0x1471838 sp=0x14717e8 pc=0x10910002 wasm.js:50:14
runtime.(*mheap).alloc(0x27e820, 0x1, 0x27010c, 0x3f4) wasm.js:50:14
	/home/finnb/sdk/go1.15.2/src/runtime/mheap.go:912 +0xb fp=0x1471880 sp=0x1471838 pc=0x1156000b wasm.js:50:14
runtime.(*mcentral).grow(0x27f8c8, 0x0) wasm.js:50:14
	/home/finnb/sdk/go1.15.2/src/runtime/mcentral.go:506 +0x6 fp=0x14718b8 sp=0x1471880 pc=0x10e80006 wasm.js:50:14
runtime.(*mcentral).cacheSpan(0x27f8c8, 0x18ec968) wasm.js:50:14
	/home/finnb/sdk/go1.15.2/src/runtime/mcentral.go:177 +0x53 fp=0x1471938 sp=0x14718b8 pc=0x10e60053 wasm.js:50:14
runtime.(*mcache).refill(0x2a0108, 0xc) wasm.js:50:14
	/home/finnb/sdk/go1.15.2/src/runtime/mcache.go:142 +0xc fp=0x1471960 sp=0x1471938 pc=0x10e3000c wasm.js:50:14
runtime.(*mcache).nextFree(0x2a0108, 0xc, 0x50, 0x53d20, 0x10cd0016) wasm.js:50:14
	/home/finnb/sdk/go1.15.2/src/runtime/malloc.go:880 +0xa fp=0x1471998 sp=0x1471960 pc=0x1099000a wasm.js:50:14
runtime.mallocgc(0x50, 0x53d20, 0x2a0101, 0x1000400016a3680) wasm.js:50:14
	/home/finnb/sdk/go1.15.2/src/runtime/malloc.go:1061 +0xb0 fp=0x1471a38 sp=0x1471998 pc=0x109a00b0 wasm.js:50:14
runtime.makeslice(0x53d20, 0x5, 0x5, 0x279680) wasm.js:50:14
	/home/finnb/sdk/go1.15.2/src/runtime/slice.go:98 +0xd fp=0x1471a60 sp=0x1471a38 pc=0x1282000d wasm.js:50:14
syscall/js.makeArgs(0x1471b90, 0x5, 0x5, 0x1282000d, 0x10, 0x22ee0, 0x279601, 0x16aa220, 0x16cf0007) wasm.js:50:14
	/home/finnb/sdk/go1.15.2/src/syscall/js/js.go:362 +0x2 fp=0x1471aa8 sp=0x1471a60 pc=0x16cf0002 wasm.js:50:14
syscall/js.Value.Invoke(0x7ff800040000004a, 0x41aa60, 0x1471b90, 0x5, 0x5, 0x10c70009, 0x16a73e0) wasm.js:50:14
	/home/finnb/sdk/go1.15.2/src/syscall/js/js.go:411 +0x2 fp=0x1471b58 sp=0x1471aa8 pc=0x16d20002 wasm.js:50:14
mazean/client/renderer/gl.DrawElementsInstancedI(...) wasm.js:50:14
	/home/finnb/git/finnbear/mazean/src/client/renderer/gl/gl.go:701 wasm.js:50:14
mazean/client/renderer.(*Instances).Draw(0x4e4c00) wasm.js:50:14
	/home/finnb/git/finnbear/mazean/src/client/renderer/instances.go:157 +0xc fp=0x1471be8 sp=0x1471b58 pc=0x1b4f000c wasm.js:50:14
mazean/client/renderer.(*Instances).BindAndDraw(0x4e4c00) wasm.js:50:14
	/home/finnb/git/finnbear/mazean/src/client/renderer/instances.go:140 +0x9 fp=0x1471c48 sp=0x1471be8 pc=0x1b4d0009 wasm.js:50:14
mazean/client/renderer.renderScene(0xd580150673af7, 0xd580150673af7, 0xf4f835b5e2d6261, 0x166b900, 0x166b980, 0x169ace0, 0x3fa10a137f38c000, 0x1) wasm.js:50:14
	/home/finnb/git/finnbear/mazean/src/client/renderer/renderer.go:711 +0x23a fp=0x1472b38 sp=0x1471c48 pc=0x1b6f023a wasm.js:50:14
mazean/client/renderer.renderScene(0xd580150673af7, 0xd580150673af7, 0xf4f835b5e2d6261, 0x166b700, 0x166b680, 0x1473c10, 0x3fa10a137f38c000, 0x0) wasm.js:50:14
	/home/finnb/git/finnbear/mazean/src/client/renderer/renderer.go:646 +0x193 fp=0x1473a28 sp=0x1472b38 pc=0x1b6f0193 wasm.js:50:14
mazean/client/renderer.Render(0xd580150673af7, 0xf4f835b5e2d6261, 0xf4f835b5e2d0000, 0x3ff0000000000000, 0x4063e5aaa3ad18d2, 0x3fa10a137f38c000, 0x6e320) wasm.js:50:14
	/home/finnb/git/finnbear/mazean/src/client/renderer/renderer.go:302 +0x4f fp=0x1474468 sp=0x1473a28 pc=0x1b6d004f wasm.js:50:14
main.main.func4(0x7ff800040000000d, 0x1697430, 0x1699c70, 0x1, 0x1, 0x1697438, 0x40001475f00) wasm.js:50:14
	/home/finnb/git/finnbear/mazean/src/client/main.go:304 +0xed fp=0x1475ec0 sp=0x1474468 pc=0x1c0d00ed wasm.js:50:14
syscall/js.handleEvent() wasm.js:50:14
	/home/finnb/sdk/go1.15.2/src/syscall/js/func.go:96 +0x24 fp=0x1475f90 sp=0x1475ec0 pc=0x16c20024 wasm.js:50:14
runtime.handleEvent() wasm.js:50:14
	/home/finnb/sdk/go1.15.2/src/runtime/lock_js.go:238 +0xa fp=0x1475fe0 sp=0x1475f90 pc=0x1091000a wasm.js:50:14
runtime.goexit() wasm.js:50:14
	/home/finnb/sdk/go1.15.2/src/runtime/asm_wasm.s:428 +0x1 fp=0x1475fe8 sp=0x1475fe0 pc=0x13c70001 wasm.js:50:14
created by runtime.beforeIdle wasm.js:50:14
	/home/finnb/sdk/go1.15.2/src/runtime/lock_js.go:194 +0x11 wasm.js:50:14
 wasm.js:50:14
goroutine 1 [semacquire, 2 minutes]: wasm.js:50:14
sync.runtime_Semacquire(0x574a98) wasm.js:50:14
	/home/finnb/sdk/go1.15.2/src/runtime/sema.go:56 +0x2 wasm.js:50:14
sync.(*WaitGroup).Wait(0x574a90) wasm.js:50:14
	/home/finnb/sdk/go1.15.2/src/sync/waitgroup.go:130 +0x10 wasm.js:50:14
main.main() wasm.js:50:14
	/home/finnb/git/finnbear/mazean/src/client/main.go:352 +0x1b
```
second time (console log + malloc deadlock stack trace)
Script terminated by timeout at:
runtime.heapBitsSetType@https://mazean.com/client/wasm/client.wasm:wasm-function[243]:0x30c26
runtime.mallocgc@https://mazean.com/client/wasm/client.wasm:wasm-function[177]:0x1b717
runtime.makeslice@https://mazean.com/client/wasm/client.wasm:wasm-function[665]:0x95cb2
syscall_js.makeArgs@https://mazean.com/client/wasm/client.wasm:wasm-function[1766]:0x145d52
syscall_js.Value.Invoke@https://mazean.com/client/wasm/client.wasm:wasm-function[1769]:0x146905
mazean_client_renderer.renderScene@https://mazean.com/client/wasm/client.wasm:wasm-function[2950]:0x2c0ee0
mazean_client_renderer.renderScene@https://mazean.com/client/wasm/client.wasm:wasm-function[2950]:0x2befeb
mazean_client_renderer.Render@https://mazean.com/client/wasm/client.wasm:wasm-function[2948]:0x2b8fd9
main.main.func4@https://mazean.com/client/wasm/client.wasm:wasm-function[3108]:0x336861
syscall_js.handleEvent@https://mazean.com/client/wasm/client.wasm:wasm-function[1753]:0x142f11
runtime.handleEvent@https://mazean.com/client/wasm/client.wasm:wasm-function[168]:0x183da
wasm_export_resume@https://mazean.com/client/wasm/client.wasm:wasm-function[997]:0xcc9c0
_resume@https://mazean.com/client/js/lib/wasm.js:574:23
_makeFuncWrapper/<@https://mazean.com/client/js/lib/wasm.js:586:9
animationFrame@https://mazean.com/client/js/client.min.js:1476:67
FrameRequestCallback*animationFrame@https://mazean.com/client/js/client.min.js:1476:205
FrameRequestCallback*animationFrame@https://mazean.com/client/js/client.min.js:1476:205
FrameRequestCallback*animationFrame@https://mazean.com/client/js/client.min.js:1476:205
FrameRequestCallback*animationFrame@https://mazean.com/client/js/client.min.js:1476:205
FrameRequestCallback*animationFrame@https://mazean.com/client/js/client.min.js:1476:205
FrameRequestCallback*animationFrame@https://mazean.com/client/js/client.min.js:1476:205
FrameRequestCallback*animationFrame@https://mazean.com/client/js/client.min.js:1476:205
FrameRequestCallback*animationFrame@https://mazean.com/client/js/client.min.js:1476:205
FrameRequestCallback*animationFrame@https://mazean.com/client/js/client.min.js:1476:205
FrameRequestCallback*animationFrame@https://mazean.com/client/js/client.min.js:1476:205
FrameRequestCallback*animationFrame@https://mazean.com/client/js/client.min.js:1476:205
FrameRequestCallback*animationFrame@https://mazean.com/client/js/client.min.js:1476:205
FrameRequestCallback*animationFrame@https://mazean.com/client/js/client.min.js:1476:205
FrameRequestCallback*animationFrame@https://mazean.com/client/js/client.min.js:1476:205
FrameRequestCallback*animationFrame@https://mazean.com/client/js/client.min.js:1476:205
FrameRequestCallback*animationFrame@https://mazean.com/client/js/client.min.js:1476:205
FrameRequestCallback*animationFrame@https://mazean.com/client/js/client.min.js:1476:205
FrameRequestCallback*animationFrame@https://mazean.com/client/js/client.min.js:1476:205
FrameRequestCallback*animationFrame@https://mazean.com/client/js/client.min.js:1476:205
FrameRequestCallback*animationFrame@https://mazean.com/client/js/client.min.js:1476:205
FrameRequestCallback*animationFrame@https://mazean.com/client/js/client.min.js:1476:205
FrameRequestCallback*animationFrame@https://mazean.com/client/js/client.min.js:1476:205
FrameRequestCallback*animationFrame@https://mazean.com/client/js/client.min.js:1476:205
FrameRequestCallback*animationFrame@https://mazean.com/client/js/client.min.js:1476:205
client.wasm:199718:1
fatal error: malloc deadlock wasm.js:50:14
 wasm.js:50:14
goroutine 6 [running]: wasm.js:50:14
runtime.throw(0x5dd0f, 0xf) wasm.js:50:14
	/home/finnb/sdk/go1.15.2/src/runtime/panic.go:1116 +0x7 fp=0x455900 sp=0x4558d8 pc=0x11df0007 wasm.js:50:14
runtime.mallocgc(0x10, 0x37420, 0x10710001, 0x26cce0) wasm.js:50:14
	/home/finnb/sdk/go1.15.2/src/runtime/malloc.go:959 +0xd3 fp=0x4559a0 sp=0x455900 pc=0x109a00d3 wasm.js:50:14
runtime.newobject(0x37420, 0xb75858) wasm.js:50:14
	/home/finnb/sdk/go1.15.2/src/runtime/malloc.go:1195 +0x4 fp=0x4559c8 sp=0x4559a0 pc=0x109c0004 wasm.js:50:14
runtime.handleEvent() wasm.js:50:14
	/home/finnb/sdk/go1.15.2/src/runtime/lock_js.go:232 +0x2 fp=0x455a18 sp=0x4559c8 pc=0x10910002 wasm.js:50:14
runtime.mallocgc(0x6d94d0, 0x30, 0x30, 0x53d20) wasm.js:50:14
	/home/finnb/sdk/go1.15.2/src/runtime/malloc.go:903 +0x1 fp=0x455ab8 sp=0x455a18 pc=0x109a0001 wasm.js:50:14
runtime.mallocgc(0x30, 0x53d20, 0x1, 0x6e4b60) wasm.js:50:14
	/home/finnb/sdk/go1.15.2/src/runtime/malloc.go:1090 +0x7e fp=0x455b58 sp=0x455ab8 pc=0x109a007e wasm.js:50:14
runtime.makeslice(0x53d20, 0x3, 0x3, 0x0) wasm.js:50:14
	/home/finnb/sdk/go1.15.2/src/runtime/slice.go:98 +0xd fp=0x455b80 sp=0x455b58 pc=0x1282000d wasm.js:50:14
syscall/js.makeArgs(0x456a30, 0x3, 0x3, 0x0, 0x8, 0x4f3310, 0xb7f130, 0x279680, 0x3) wasm.js:50:14
	/home/finnb/sdk/go1.15.2/src/syscall/js/js.go:362 +0x2 fp=0x455bc8 sp=0x455b80 pc=0x16cf0002 wasm.js:50:14
syscall/js.Value.Invoke(0x7ff8000400000056, 0x41aaf0, 0x456a30, 0x3, 0x3, 0x0, 0x0) wasm.js:50:14
	/home/finnb/sdk/go1.15.2/src/syscall/js/js.go:411 +0x2 fp=0x455c78 sp=0x455bc8 pc=0x16d20002 wasm.js:50:14
mazean/client/renderer/gl.StencilOp(...) wasm.js:50:14
	/home/finnb/git/finnbear/mazean/src/client/renderer/gl/gl.go:1021 wasm.js:50:14
mazean/client/renderer.renderScene(0x178d10aa59ee35, 0x178d10aa59ee35, 0x93704aee0040b6f, 0x6d2500, 0x6d2580, 0x6e4660, 0x3fa9c8c9320d9a00, 0x1) wasm.js:50:14
	/home/finnb/git/finnbear/mazean/src/client/renderer/renderer.go:688 +0x25a fp=0x456b68 sp=0x455c78 pc=0x1b6f025a wasm.js:50:14
mazean/client/renderer.renderScene(0x178d10aa59ee35, 0x178d10aa59ee35, 0x93704aee0040b6f, 0x6d2200, 0x6d2180, 0x457c40, 0x3fa9c8c9320d9a00, 0x0) wasm.js:50:14
	/home/finnb/git/finnbear/mazean/src/client/renderer/renderer.go:646 +0x193 fp=0x457a58 sp=0x456b68 pc=0x1b6f0193 wasm.js:50:14
mazean/client/renderer.Render(0x178d10aa59ee35, 0x93704aee0040b6f, 0x93704aee0040000, 0x3ff0000000000000, 0x403769b280f12c28, 0x3fa9c8c9320d9a00, 0x6e2f8) wasm.js:50:14
	/home/finnb/git/finnbear/mazean/src/client/renderer/renderer.go:302 +0x4f fp=0x458498 sp=0x457a58 pc=0x1b6d004f wasm.js:50:14
main.main.func4(0x7ff800040000000d, 0x41bc08, 0x6bdf30, 0x1, 0x1, 0x41bc10, 0x40000459f00) wasm.js:50:14
	/home/finnb/git/finnbear/mazean/src/client/main.go:303 +0xed fp=0x459ec0 sp=0x458498 pc=0x1c0d00ed wasm.js:50:14
syscall/js.handleEvent() wasm.js:50:14
	/home/finnb/sdk/go1.15.2/src/syscall/js/func.go:96 +0x24 fp=0x459f90 sp=0x459ec0 pc=0x16c20024 wasm.js:50:14
runtime.handleEvent() wasm.js:50:14
	/home/finnb/sdk/go1.15.2/src/runtime/lock_js.go:238 +0xa fp=0x459fe0 sp=0x459f90 pc=0x1091000a wasm.js:50:14
runtime.goexit() wasm.js:50:14
	/home/finnb/sdk/go1.15.2/src/runtime/asm_wasm.s:428 +0x1 fp=0x459fe8 sp=0x459fe0 pc=0x13c70001 wasm.js:50:14
created by runtime.beforeIdle wasm.js:50:14
	/home/finnb/sdk/go1.15.2/src/runtime/lock_js.go:194 +0x11 wasm.js:50:14
 wasm.js:50:14
goroutine 1 [semacquire]: wasm.js:50:14
sync.runtime_Semacquire(0x574a98) wasm.js:50:14
	/home/finnb/sdk/go1.15.2/src/runtime/sema.go:56 +0x2 wasm.js:50:14
sync.(*WaitGroup).Wait(0x574a90) wasm.js:50:14
	/home/finnb/sdk/go1.15.2/src/sync/waitgroup.go:130 +0x10 wasm.js:50:14
main.main() wasm.js:50:14
	/home/finnb/git/finnbear/mazean/src/client/main.go:351 +0x1b wasm.js:50:14
exit code: 2

I'm not sure whether these logs were from the new (post-browser-refresh) instance of the app or the dying (pre-browser-refresh) instance of the app (both logs were from when I refreshed the page). However, my app was completely unresponsive the first time and totally responsive after the second time, implying that the first logs were from the new instance and the second logs were from the dying instance.

The key issue is that runtime.handleEvent() appears twice in the stack trace, which should be impossible as JS is single threaded, but an exception to that rule may occur when JS is terminating synchronous tasks.

It is important to emphacize that this is a very rare, not easily-reproducible issue. I have been developing this particular app for around 5 months and this is the first time I have experienced an error of this nature. Today is the first time I have seen the issue, and it has happened twice so far. The second time, the console had additional info.

The source code of my project is currently private but I would be willing to grant access to any go developers who are curious.

@finnbear finnbear changed the title js/wasm: Memory deadlock (rare, not reproducible) js/wasm: memory deadlock (rare, not reproducible) Oct 4, 2020
@finnbear finnbear changed the title js/wasm: memory deadlock (rare, not reproducible) js/wasm: malloc deadlock (rare, not reproducible) Oct 4, 2020
@finnbear finnbear changed the title js/wasm: malloc deadlock (rare, not reproducible) js/wasm: malloc deadlock when "script terminated by timeout" Oct 4, 2020
@agnivade
Copy link
Contributor

agnivade commented Oct 4, 2020

Interesting. The 2 stack traces are slightly different, but they both stem from the calling of nested mallocgc.

Even more surprising is this:

runtime.mallocgc(0x6d94d0, 0x30, 0x30, 0x53d20) wasm.js:50:14
	/home/finnb/sdk/go1.15.2/src/runtime/malloc.go:903 +0x1 fp=0x455ab8 sp=0x455a18 pc=0x109a0001 wasm.js:50:14
runtime.mallocgc(0x30, 0x53d20, 0x1, 0x6e4b60) wasm.js:50:14
	/home/finnb/sdk/go1.15.2/src/runtime/malloc.go:1090 +0x7e fp=0x455b58 sp=0x455ab8 pc=0x109a007e wasm.js:50:14

/cc @neelance

@agnivade agnivade changed the title js/wasm: malloc deadlock when "script terminated by timeout" runtime : fatal error: malloc deadlock Oct 4, 2020
@agnivade agnivade added arch-wasm WebAssembly issues NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. labels Oct 4, 2020
@agnivade agnivade added this to the Backlog milestone Oct 4, 2020
@neelance
Copy link
Member

In both traces the call to runtime.handleEvent is bad, because neither runtime.(*mheap).alloc nor runtime.mallocgc can call this function. This can only happen if JS calls into Go code at a point when it is not supposed to.

And it seems like this is exactly what happened in the second trace. It first says:

Script terminated by timeout at:
runtime.heapBitsSetType@https://mazean.com/client/wasm/client.wasm:wasm-function[243]:0x30c26
runtime.mallocgc@https://mazean.com/client/wasm/client.wasm:wasm-function[177]:0x1b717

It seems like the WebAssebly host decided to forcefully terminate the WebAssembly binary and mallocgc was almost at the top of the stack. This left Go's stack in a state that is not safe for returning execution to JS. Afterwards your JS code again invokes a Go callback, which triggers handleEvent, but it now gets executed on top of a broken Go stack. 💥

@neelance
Copy link
Member

@finnbear You gave a 👍 . Does that mean that we can close this issue?

@finnbear
Copy link
Author

finnbear commented Oct 22, 2020

@finnbear You gave a +1 . Does that mean that we can close this issue?

My thought is that Go should attempt to predict forceful termination (using the browser's window.onbeforeunload event) and 1) notify the user's program using a standard mechanism such as signal.Notify 2) terminate gracefully.

However, as this issue absolutely does not effect my use case (WebGL game), because I don't currently have any tasks that need to be done by Go on page exit, I'm fine with it being closed.

@neelance

@neelance
Copy link
Member

I tried to reproduce this on Firefox. With an infinite loop I get this message after a few seconds:
image
If I select "Stop It", then I get the Script terminated by timeout at: in the JS console. It stops all code though, even event callbacks do not trigger any more, so I can not make WebAssembly continue to run to reproduce the crash due to the broken Go stack. @finnbear Any ideas?

@finnbear
Copy link
Author

@neelance Thanks!

  1. As I mentioned, the issue is extremely rare and difficult to reproduce (Only twice, albeit in the same 10 minutes, in 6 months). My game does not contain any infinite loops, though. Just a requestAnimationFrame event loop where go runs 1-8ms per frame at 60fps. The requirement to observe the issue is memory allocations or some other critical process that panics if it is entered multiple times concurrently. Also, the more CPU time WASM claims, the more likely the browser is to display a "stop it" option and, theoretically, the more likely the original issue is to occur when the page is closed.

With this go script:

package main

import (
	"time"
)

var m = make(map[int]*int)

func main() {
	println("Hello from Go")

	for {
		for k := 0; k < 1000000; k++ { // spend plenty of time in Go (only necessary to get the "a web page is slowing down your browser message, not necessary for problems when closing the tab)
			j := k
			m[k] = &j // allocate some memory to force a critical, mutex-locked process to occur
        	}

		time.Sleep(time.Millisecond) // return to JS every so often, just so the page is semi responsive
		println("loop")
	}
}

I was able to get this to appear after pressing the "stop it button" but I didn't actually get to see a panic.

Stack trace
Script terminated by timeout at:
runtime.memhash64@http://localhost:8192/test.wasm:wasm-function[853]:0xb9243
runtime.evacuate_fast64@http://localhost:8192/test.wasm:wasm-function[184]:0x226b9
runtime.growWork_fast64@http://localhost:8192/test.wasm:wasm-function[183]:0x21f63
runtime.mapassign_fast64@http://localhost:8192/test.wasm:wasm-function[180]:0x20bd5
main.main@http://localhost:8192/test.wasm:wasm-function[1047]:0xcd947
wasm_pc_f_loop@http://localhost:8192/test.wasm:wasm-function[896]:0xbbb12
wasm_export_resume@http://localhost:8192/test.wasm:wasm-function[895]:0xbbaf3
_resume@http://localhost:8192/wasm_exec.js:550:23
runtime.scheduleTimeoutEvent/<@http://localhost:8192/wasm_exec.js:307:14
setTimeout handler*runtime.scheduleTimeoutEvent@http://localhost:8192/wasm_exec.js:305:39
runtime.scheduleTimeoutEvent@http://localhost:8192/test.wasm:wasm-function[915]:0xbbda3
runtime.beforeIdle@http://localhost:8192/test.wasm:wasm-function[139]:0x134e9
runtime.findrunnable@http://localhost:8192/test.wasm:wasm-function[540]:0x76612
runtime.schedule@http://localhost:8192/test.wasm:wasm-function[545]:0x78f4a
runtime.park_m@http://localhost:8192/test.wasm:wasm-function[548]:0x79dc6
runtime.mcall@http://localhost:8192/test.wasm:wasm-function[847]:0xb90ab
runtime.gopark@http://localhost:8192/test.wasm:wasm-function[492]:0x6bd41
time.Sleep@http://localhost:8192/test.wasm:wasm-function[840]:0xb8ac1
main.main@http://localhost:8192/test.wasm:wasm-function[1047]:0xcd9ea
wasm_pc_f_loop@http://localhost:8192/test.wasm:wasm-function[896]:0xbbb12
wasm_export_resume@http://localhost:8192/test.wasm:wasm-function[895]:0xbbaf3
_resume@http://localhost:8192/wasm_exec.js:550:23
runtime.scheduleTimeoutEvent/<@http://localhost:8192/wasm_exec.js:307:14
setTimeout handler*runtime.scheduleTimeoutEvent@http://localhost:8192/wasm_exec.js:305:39
runtime.scheduleTimeoutEvent@http://localhost:8192/test.wasm:wasm-function[915]:0xbbda3
runtime.beforeIdle@http://localhost:8192/test.wasm:wasm-function[139]:0x134e9
runtime.findrunnable@http://localhost:8192/test.wasm:wasm-function[540]:0x76612
runtime.schedule@http://localhost:8192/test.wasm:wasm-function[545]:0x78f4a
runtime.park_m@http://localhost:8192/test.wasm:wasm-function[548]:0x79dc6
runtime.mcall@http://localhost:8192/test.wasm:wasm-function[847]:0xb90ab
runtime.gopark@http://localhost:8192/test.wasm:wasm-function[492]:0x6bd41
time.Sleep@http://localhost:8192/test.wasm:wasm-function[840]:0xb8ac1
main.main@http://localhost:8192/test.wasm:wasm-function[1047]:0xcd9ea
wasm_pc_f_loop@http://localhost:8192/test.wasm:wasm-function[896]:0xbbb12
wasm_export_resume@http://localhost:8192/test.wasm:wasm-function[895]:0xbbaf3
_resume@http://localhost:8192/wasm_exec.js:550:23
runtime.scheduleTimeoutEvent/<@http://localhost:8192/wasm_exec.js:307:14
setTimeout handler*runtime.scheduleTimeoutEvent@http://localhost:8192/wasm_exec.js:305:39
runtime.scheduleTimeoutEvent@http://localhost:8192/test.wasm:wasm-function[915]:0xbbda3
runtime.beforeIdle@http://localhost:8192/test.wasm:wasm-function[139]:0x134e9
runtime.findrunnable@http://localhost:8192/test.wasm:wasm-function[540]:0x76612
runtime.schedule@http://localhost:8192/test.wasm:wasm-function[545]:0x78f4a
runtime.park_m@http://localhost:8192/test.wasm:wasm-function[548]:0x79dc6
runtime.mcall@http://localhost:8192/test.wasm:wasm-function[847]:0xb90ab
runtime.gopark@http://localhost:8192/test.wasm:wasm-function[492]:0x6bd41
time.Sleep@http://localhost:8192/test.wasm:wasm-function[840]:0xb8ac1
main.main@http://localhost:8192/test.wasm:wasm-function[1047]:0xcd9ea
wasm_pc_f_loop@http://localhost:8192/test.wasm:wasm-function[896]:0xbbb12
wasm_export_resume@http://localhost:8192/test.wasm:wasm-function[895]:0xbbaf3
_resume@http://localhost:8192/wasm_exec.js:550:23
runtime.scheduleTimeoutEvent/<@http://localhost:8192/wasm_exec.js:307:14
setTimeout handler*runtime.scheduleTimeoutEvent@http://localhost:8192/wasm_exec.js:305:39
runtime.scheduleTimeoutEvent@http://localhost:8192/test.wasm:wasm-function[915]:0xbbda3
runtime.beforeIdle@http://localhost:8192/test.wasm:wasm-function[139]:0x134e9
runtime.findrunnable@http://localhost:8192/test.wasm:wasm-function[540]:0x76612
runtime.schedule@http://localhost:8192/test.wasm:wasm-function[545]:0x78f4a
runtime.park_m@http://localhost:8192/test.wasm:wasm-function[548]:0x79dc6
runtime.mcall@http://localhost:8192/test.wasm:wasm-function[847]:0xb90ab
runtime.gopark@http://localhost:8192/test.wasm:wasm-function[492]:0x6bd41
time.Sleep@http://localhost:8192/test.wasm:wasm-function[840]:0xb8ac1
main.main@http://localhost:8192/test.wasm:wasm-function[1047]:0xcd9ea
wasm_pc_f_loop@http://localhost:8192/test.wasm:wasm-function[896]:0xbbb12
wasm_export_resume@http://localhost:8192/test.wasm:wasm-function[895]:0xbbaf3
_resume@http://localhost:8192/wasm_exec.js:550:23
runtime.scheduleTimeoutEvent/<@http://localhost:8192/wasm_exec.js:307:14
setTimeout handler*runtime.scheduleTimeoutEvent@http://localhost:8192/wasm_exec.js:305:39
runtime.scheduleTimeoutEvent@http://localhost:8192/test.wasm:wasm-function[915]:0xbbda3
runtime.beforeIdle@http://localhost:8192/test.wasm:wasm-function[139]:0x134e9
runtime.findrunnable@http://localhost:8192/test.wasm:wasm-function[540]:0x76612
runtime.schedule@http://localhost:8192/test.wasm:wasm-function[545]:0x78f4a
runtime.park_m@http://localhost:8192/test.wasm:wasm-function[548]:0x79dc6
runtime.mcall@http://localhost:8192/test.wasm:wasm-function[847]:0xb90ab
runtime.gopark@http://localhost:8192/test.wasm:wasm-function[492]:0x6bd41
time.Sleep@http://localhost:8192/test.wasm:wasm-function[840]:0xb8ac1
main.main@http://localhost:8192/test.wasm:wasm-function[1047]:0xcd9ea
wasm_pc_f_loop@http://localhost:8192/test.wasm:wasm-function[896]:0xbbb12
wasm_export_resume@http://localhost:8192/test.wasm:wasm-function[895]:0xbbaf3
_resume@http://localhost:8192/wasm_exec.js:550:23
runtime.scheduleTimeoutEvent/<@http://localhost:8192/wasm_exec.js:307:14
setTimeout handler*runtime.scheduleTimeoutEvent@http://localhost:8192/wasm_exec.js:305:39
runtime.scheduleTimeoutEvent@http://localhost:8192/test.wasm:wasm-function[915]:0xbbda3
  1. Remember to enable "persist/preserve logs" in console, to keep the logs when refreshing the page
  2. The best thing might be to close this issue as 1) it's almost impossible to reproduce 2) it could just be a Firefox bug 3) there are more pressing areas for improvement like syscall/js: increase performance of Call, Invoke, and New by not allowing new slices to escape onto the heap #39740. But I wont close the issue, just in case you want to keep it open and attempt to fix it.

@neelance
Copy link
Member

Okay. It does not really seem to be a bug on Go's end, since "Script terminated by timeout" is clearly a failure condition in the first place. All we could do is to make the subsequent crash "fatal error: malloc deadlock" nicer by detecting the situation. However, it is impossible to write such detection without reproducing the issue. So overall I'd also opt for closing the issue.

@golang golang locked and limited conversation to collaborators Oct 23, 2021
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
arch-wasm WebAssembly issues FrozenDueToAge NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one.
Projects
None yet
Development

No branches or pull requests

4 participants