syscall/js: strange deadlock caused by wasm event handling callback (runtime bug?)

[atd...@gmail.com]

Hi,

I have a little concurrency problem. Seems that my Go-wasm-defined event handlers run concurrently instead of synchronously.

Basically, the event handler is called by runtime.handleEvent which calls into the syscall/js defined version of it

Link to source

// handleEvent gets invoked on a call from JavaScript into Go. It calls the event handler of the syscall/js package

// and then parks the handler goroutine to allow other goroutines to run before giving execution back to JavaScript.

// When no other goroutine is awake any more, beforeIdle resumes the handler goroutine. Now that the same goroutine

// is running as was running when the call came in from JavaScript, execution can be safely passed back to JavaScript.

func handleEvent() {

   e := &event{

       gp: getg(),

       returned: false,

   }

   events = append(events, e)

   eventHandler() // !!!!

   clearIdleID()

   // wait until all goroutines are idle

   e.returned = true

   gopark(nil, nil, waitReasonZero, traceEvNone, 1)

   events[len(events)-1] = nil

   events = events[:len(events)-1]

   // return execution to JavaScript

   pause(getcallersp() - 16)

}

In syscall/js, Link to source

func handleEvent() {

   cb := jsGo.Get("_pendingEvent")

   if cb.IsNull() {

       return

   }

   jsGo.Set("_pendingEvent", Null())

   id := uint32(cb.Get("id").Int())

   if id == 0 { // zero indicates deadlock

       select {}

   }

   funcsMu.Lock()

   f, ok := funcs[id]

   funcsMu.Unlock()

   if !ok {

       Global().Get("console").Call("error", "call to released function")

       return

   }

   this := cb.Get("this")

   argsObj := cb.Get("args")

   args := make([]Value, argsObj.Length())

   for i := range args {

       args[i] = argsObj.Index(i)

   }

   result := f(this, args) // My callback runs here

   cb.Set("result", result)

}

Basically, f causes a deadlock because it locks a mutex but never unlocks before being called again in response to another JS event.

If I remove the lock, it's fine but he program should be incorrect as event handlers should be run synchronously.

Tried to instrument the code to display the call stack. You can see toward the end that there is an attempt to take a lock while handling the focus event that has not been unlocked beforehand while processing the click event.

2022/08/05 22:24:25 focusTodo-App
wasm_exec.js:22 2022/08/05 22:24:25 LOCKING ====================================================================
wasm_exec.js:22 2022/08/05 22:24:25 LOCkED ----------------------------------------------------------------------
wasm_exec.js:22 2022/08/05 22:24:25 6
wasm_exec.js:22 runtime.Callers
wasm_exec.js:22 github.com/atdiar/particleui/drivers/js.SDEBUG
wasm_exec.js:22 github.com/atdiar/particleui/drivers/js.glob..func2.1
wasm_exec.js:22 syscall/js.handleEvent
wasm_exec.js:22 runtime.handleEvent
wasm_exec.js:22 runtime.goexit
wasm_exec.js:22 2022/08/05 22:24:25 UNLOCKING ====================================================================
wasm_exec.js:22 2022/08/05 22:24:25 7
wasm_exec.js:22 runtime.Callers
wasm_exec.js:22 github.com/atdiar/particleui/drivers/js.SDEBUG
wasm_exec.js:22 github.com/atdiar/particleui/drivers/js.freelock
wasm_exec.js:22 github.com/atdiar/particleui/drivers/js.glob..func2.1
wasm_exec.js:22 syscall/js.handleEvent
wasm_exec.js:22 runtime.handleEvent
wasm_exec.js:22 runtime.goexit
wasm_exec.js:22 2022/08/05 22:24:25 UNLOCkED ----------------------------------------------------------------------
wasm_exec.js:22 2022/08/05 22:24:32 focusTodo-App
wasm_exec.js:22 2022/08/05 22:24:32 LOCKING ====================================================================
wasm_exec.js:22 2022/08/05 22:24:32 LOCkED ----------------------------------------------------------------------
wasm_exec.js:22 2022/08/05 22:24:32 6
wasm_exec.js:22 runtime.Callers
wasm_exec.js:22 github.com/atdiar/particleui/drivers/js.SDEBUG
wasm_exec.js:22 github.com/atdiar/particleui/drivers/js.glob..func2.1
wasm_exec.js:22 syscall/js.handleEvent
wasm_exec.js:22 runtime.handleEvent
wasm_exec.js:22 runtime.goexit
wasm_exec.js:22 2022/08/05 22:24:32 UNLOCKING ====================================================================
wasm_exec.js:22 2022/08/05 22:24:32 7
wasm_exec.js:22 runtime.Callers
wasm_exec.js:22 github.com/atdiar/particleui/drivers/js.SDEBUG
wasm_exec.js:22 github.com/atdiar/particleui/drivers/js.freelock
wasm_exec.js:22 github.com/atdiar/particleui/drivers/js.glob..func2.1
wasm_exec.js:22 syscall/js.handleEvent
wasm_exec.js:22 runtime.handleEvent
wasm_exec.js:22 runtime.goexit
wasm_exec.js:22 2022/08/05 22:24:32 UNLOCkED ----------------------------------------------------------------------
wasm_exec.js:22 2022/08/05 22:24:32 clickactive-filter-anchor
wasm_exec.js:22 2022/08/05 22:24:32 LOCKING ====================================================================
wasm_exec.js:22 2022/08/05 22:24:32 LOCkED ----------------------------------------------------------------------
wasm_exec.js:22 2022/08/05 22:24:32 6
wasm_exec.js:22 runtime.Callers
wasm_exec.js:22 github.com/atdiar/particleui/drivers/js.SDEBUG
wasm_exec.js:22 github.com/atdiar/particleui/drivers/js.glob..func2.1
wasm_exec.js:22 syscall/js.handleEvent
wasm_exec.js:22 runtime.handleEvent
wasm_exec.js:22 runtime.goexit
wasm_exec.js:22 2022/08/05 22:24:32 focusTodo-App
wasm_exec.js:22 2022/08/05 22:24:32 LOCKING ====================================================================
wasm_exec.js:22 fatal error: all goroutines are asleep - deadlock!
wasm_exec.js:22
wasm_exec.js:22 goroutine 1 [chan receive]:
wasm_exec.js:22 github.com/atdiar/particleui.(*Router).ListenAndServe(0x103d940, {0x4d820, 0x8}, 0x4c6300, 0x61028)
wasm_exec.js:22     /home/atd/Desktop/Projects/particleui/router.go:467 +0x3a
wasm_exec.js:22 main.main()
wasm_exec.js:22     /home/atd/Desktop/Projects/todomvc/main.go:228 +0x1db
wasm_exec.js:22
wasm_exec.js:22 goroutine 7 [semacquire]:
wasm_exec.js:22 sync.runtime_SemacquireMutex(0x2602c4, 0x0, 0x1)
wasm_exec.js:22     /usr/local/go/src/runtime/sema.go:71 +0x2
wasm_exec.js:22 sync.(*Mutex).lockSlow(0x2602c0)
wasm_exec.js:22     /usr/local/go/src/sync/mutex.go:162 +0x26
wasm_exec.js:22 sync.(*Mutex).Lock(0x2602c0)
wasm_exec.js:22     /usr/local/go/src/sync/mutex.go:81 +0x7
wasm_exec.js:22 github.com/atdiar/particleui/drivers/js.glob..func2.1({{}, 0x7ff8000100000018, 0x11d3848}, {0x121b1e0, 0x1, 0x1})
wasm_exec.js:22     /home/atd/Desktop/Projects/particleui/drivers/js/events.go:106 +0x21
wasm_exec.js:22 syscall/js.handleEvent()
wasm_exec.js:22     /usr/local/go/src/syscall/js/func.go:94 +0x26
wasm_exec.js:22 syscall/js.Value.Call({{}, 0x7ff800010000003e, 0x410740}, {0x4ab3f, 0x5}, {0x0, 0x0, 0x0})
wasm_exec.js:22     /usr/local/go/src/syscall/js/js.go:379 +0x3
wasm_exec.js:22 github.com/atdiar/particleui/drivers/js.glob..func10.7.2({0x8e540, 0x1206aa0})
wasm_exec.js:22     /home/atd/Desktop/Projects/particleui/drivers/js/javascript.go:873 +0x57
wasm_exec.js:22 github.com/atdiar/particleui.(*MutationHandler).Handle(...)
wasm_exec.js:22     /home/atd/Desktop/Projects/particleui/mutation.go:113
wasm_exec.js:22 github.com/atdiar/particleui.(*mutationHandlers).Handle(...)
wasm_exec.js:22     /home/atd/Desktop/Projects/particleui/mutation.go:95
wasm_exec.js:22 github.com/atdiar/particleui.(*MutationCallbacks).DispatchEvent(0x40c148, {0x8e540, 0x1206aa0})
wasm_exec.js:22     /home/atd/Desktop/Projects/particleui/mutation.go:62 +0x3c
wasm_exec.js:22 github.com/atdiar/particleui.(*Element).Set(0x4c6240, {0x4ab21, 0x5}, {0x4ff87, 0xd}, {0x8e258, 0x121b1c0}, {0x0, 0x0, 0x0})
wasm_exec.js:22     /home/atd/Desktop/Projects/particleui/uielement.go:1317 +0x7f
wasm_exec.js:22 github.com/atdiar/particleui.(*Router).GoTo(0x103d940, {0x745dd0, 0x7})
wasm_exec.js:22     /home/atd/Desktop/Projects/particleui/router.go:177 +0x4b
wasm_exec.js:22 github.com/atdiar/particleui.(*Router).NewLink.func4({0x8e540, 0x1206960})
wasm_exec.js:22     /home/atd/Desktop/Projects/particleui/router.go:859 +0xf
wasm_exec.js:22 github.com/atdiar/particleui.(*MutationHandler).Handle(...)
wasm_exec.js:22     /home/atd/Desktop/Projects/particleui/mutation.go:113
wasm_exec.js:22 github.com/atdiar/particleui.(*mutationHandlers).Handle(...)
wasm_exec.js:22     /home/atd/Desktop/Projects/particleui/mutation.go:95
wasm_exec.js:22 github.com/atdiar/particleui.(*MutationCallbacks).DispatchEvent(0x40c708, {0x8e540, 0x1206960})
wasm_exec.js:22     /home/atd/Desktop/Projects/particleui/mutation.go:62 +0x3c
wasm_exec.js:22 github.com/atdiar/particleui.(*Element).Set(0x7852c0, {0x4ab21, 0x5}, {0x4d3e8, 0x8}, {0x8e198, 0x213128}, {0x0, 0x0, 0x0})
wasm_exec.js:22     /home/atd/Desktop/Projects/particleui/uielement.go:1317 +0x7f
wasm_exec.js:22 github.com/atdiar/particleui.Link.Activate({0x7852c0}, {0x1210be0, 0x1, 0x1})
wasm_exec.js:22     /home/atd/Desktop/Projects/particleui/router.go:742 +0x7
wasm_exec.js:22 github.com/atdiar/particleui/drivers/js.Anchor.FromLink.func3({0x8e6d0, 0x1206910})
wasm_exec.js:22     /home/atd/Desktop/Projects/particleui/drivers/js/javascript.go:1842 +0xf
wasm_exec.js:22 github.com/atdiar/particleui.EventHandler.Handle(...)
wasm_exec.js:22     /home/atd/Desktop/Projects/particleui/event.go:198
wasm_exec.js:22 github.com/atdiar/particleui.EventListeners.Handle({0x563b90}, {0x8e6d0, 0x1206910})
wasm_exec.js:22     /home/atd/Desktop/Projects/particleui/event.go:129 +0x69
wasm_exec.js:22 github.com/atdiar/particleui.(*Element).Handle(0x785740, {0x8e6d0, 0x1206910})
wasm_exec.js:22     /home/atd/Desktop/Projects/particleui/uielement.go:449 +0x7
wasm_exec.js:22 github.com/atdiar/particleui.(*Element).DispatchEvent(0x785740, {0x8e6d0, 0x1206910})
wasm_exec.js:22     /home/atd/Desktop/Projects/particleui/uielement.go:482 +0x11
wasm_exec.js:22 github.com/atdiar/particleui/drivers/js.glob..func2.1({{}, 0x7ff8000100000133, 0x11d2e10}, {0x11f1fb0, 0x1, 0x1})
wasm_exec.js:22     /home/atd/Desktop/Projects/particleui/drivers/js/events.go:177 +0xe3
wasm_exec.js:22 syscall/js.handleEvent()
wasm_exec.js:22     /usr/local/go/src/syscall/js/func.go:94 +0x26

Any idea?

[at diar]

Doesn't seem that this is a known issue. I will try and write a short reproducer and file an issue. 

--
You received this message because you are subscribed to a topic in the Google Groups "golang-nuts" group.
To unsubscribe from this topic, visit https://groups.google.com/d/topic/golang-nuts/a2PQjh4D6rw/unsubscribe.
To unsubscribe from this group and all its topics, send an email to golang-nuts...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/golang-nuts/274b9c4c-f79b-4d62-8f36-e84a377eb482n%40googlegroups.com.

[atd...@gmail.com]

Filed an issue with a reproducer ;  https://github.com/golang/go/issues/54328