Tinygo: log.Printf blocks indefinitely under wasm when called from JS

[bradleypeabody]

log.Printf seems to work correctly when used directly in main() but when called from a function which is wrapped with js.FuncOf and in a callback from a browser event it appears to block the first time and then panic the second time. Using fmt.Printf does not appear to have the same issue.

I'm using TinyGo compiled from this commit https://github.com/tinygo-org/tinygo/pull/1080/commits/257248371224fbdc6124090a12d03d02ae7b95f6

A simple example that reproduces is here: https://github.com/bradleypeabody/tgtesta and the most relevant bits are:

main_wasm.go

func main() {

    log.Printf("main() function here\n")

    fn := js.FuncOf(func(this js.Value, args []js.Value) interface{} {
        fmt.Printf("got into the function\n")
        log.Printf("a log.Printf statement 1\n")
        return nil
    })
    js.Global().Get("window").Call("setCallback", fn)

}

index.html

// setCallback is called from main.wasm once it is run
function setCallback(f) {
    document.getElementById('cbbtn').addEventListener('click', function(e) {
        f.call(null, myUint8Array);
    });
}

Clicking the button the first time gets to the fmt.Printf (you can see the output in the browser console), but appears to hang at the log.Printf. Clicking again gives:

panic: todo: block on locked mutex
main.wasm:1 Uncaught RuntimeError: unreachable
    at runtime._panic (wasm-function[24]:0x18c9)
    at (*sync.Mutex).Lock (wasm-function[137]:0xb35c)
    at (*log.Logger).Output (wasm-function[167]:0xcfec)
    at log.Printf (wasm-function[145]:0xbe59)
    at syscall/js.handleEvent (wasm-function[94]:0x5db1)
    at runtime.resume$1 (wasm-function[91]:0x55db)
    at resume (wasm-function[90]:0x5535)
    at global.Go._resume (http://localhost:8844/wasm_exec.js:481:23)
    at http://localhost:8844/wasm_exec.js:492:8
    at HTMLButtonElement.<anonymous> (http://localhost:8844/:20:5)

If the issue is that there are internal locking things preventing the log package from working correctly, it would be better to panic nice and early upon first use with a clear error message.

[niaow]

The panic part should be fixed by #881. I am not entirely sure why this is blocking.

[aykevl]

I've merged #881, @bradleypeabody can you test whether the dev branch now works?

[bradleypeabody]

I just tried using TinyGo built from the latest on dev (https://github.com/tinygo-org/tinygo/commit/01f5c1d455c77670040408bccc1ca4c81b73603d) and it's having a different issue - it seems like the function indicated by js.FuncOf is not being called at all. I updated the example with some more output and a JS alert() to clearly to show this. My guess is this would be caused by some (possibly unrelated) regression.

Specifically the JS code does f.call... but this does not appear to result in any entry back into the Go code since I do not get any output (I tried fmt.Printf, log.Printf and js.Global().Call("alert", "x") and none of these result in any output)

[deadprogram]

@bradleypeabody does the current dev now also address this issue?

[bradleypeabody]

@deadprogram Yup, on the latest dev this is all fixed now and everything works as expected. See PR #1131 for test.

[deadprogram]

This was released with v0.14.0 so now closing. Please reopen if needed. Thanks!