tinygo-org / tinygo

Go compiler for small places. Microcontrollers, WebAssembly (WASM/WASI), and command-line tools. Based on LLVM.
https://tinygo.org
Other
15.48k stars 913 forks source link

fix(wasip2): fix environment initialization in reactors #4482

Closed rvolosatovs closed 1 month ago

rvolosatovs commented 1 month ago

Using init() to initialize stdio or environment is prone to race conditions for reactor-style components, e.g. wasi:http/incoming-handler interface implementations due to the fact that init() is normally used to "register" the export implementation

In result, using e.g. fmt.Println may cause a runtime panic as follows:

ERROR wasmtime_cli::commands::serve: [125] :: Error {
    context: "error while executing at wasm backtrace:\n    0: 0x548e9 - wit-component:shim!indirect-wasi:io/streams@0.2.0-[method]output-stream.blocking-write-and-flush\n    1: 0x4d56 - main!(internal/wasi/io/v0.2.0/streams.OutputStream).BlockingWriteAndFlush\n    2: 0x99f0 - main!syscall.writeStream\n    3: 0x96a0 - main!write\n    4: 0x4623 - main!(os.unixFileHandle).Write\n    5: 0x3cf5 - main!wasi:http/incoming-handler@0.2.0#handle\nnote: using the `WASMTIME_BACKTRACE_DETAILS=1` environment variable may show more debugging information",
    source: "unknown handle index 0",
}
error: hyper::Error(User(Service), guest never invoked `response-outparam::set` method: error while executing at wasm backtrace:
    0: 0x548e9 - wit-component:shim!indirect-wasi:io/streams@0.2.0-[method]output-stream.blocking-write-and-flush
    1: 0x4d56 - main!(internal/wasi/io/v0.2.0/streams.OutputStream).BlockingWriteAndFlush
    2: 0x99f0 - main!syscall.writeStream
    3: 0x96a0 - main!write
    4: 0x4623 - main!(os.unixFileHandle).Write
    5: 0x3cf5 - main!wasi:http/incoming-handler@0.2.0#handle
note: using the `WASMTIME_BACKTRACE_DETAILS=1` environment variable may show more debugging information

Caused by:
    unknown handle index 0)

~using sync.OnceValue to lazily initialize the environment instead of init() ensures correctness and should improve cold start times as a nice side effect (especially for applications not utilizing this functionality)~ I had to preserve the "eager" initialization approach in init(), to allow tests to pass but not exactly sure why

This issue can be reproduced using a wasi:http/incoming-handler implementation run in wasmtime 24

For example, I used https://github.com/Mossaka/hello-wasi-http-tinygo, to which I've added a fmt.Println line at the top

rvolosatovs commented 1 month ago

Not exactly sure why, but looks like https://github.com/tinygo-org/tinygo/pull/4482/commits/1d20c3138d24cf22b2606d7ef2cc9bcdb255ec86 is required to make the tests pass 🤔

aykevl commented 1 month ago

I don't really understand the problem yet, because race conditions aren't really a thing in init() functions (package initializers are all run one by one in _initialize, no parallelism involved). I can see a few ways this could maybe happen:

Can you explain what's going on here?

rvolosatovs commented 1 month ago

There are no dependencies here except for standard library and generated bindings using https://github.com/bytecodealliance/wasm-tools-go

Writing to stdio in wasi:http/incoming-handler.handle export implementation (registered in the init()) causes a trap, due to the runtime receiving an invalid resource handle when run with wasmtime serve -Scommon

By some reason the initializers for stdio do not run before stdio is used. This PR is a quickfix, which fixes that. It may indeed be the case that wasmtime does not run _initialize (perhaps for reactor components), which would explain why the stdio is left uninitialized, bet that would also be surprising if that's the case since Wasmtime runtime is pretty well tested with various languages at this point. Another option that comes to mind would be incorrect init() function ordering for dependencies.

I will investigate the _initialize specification and Wasmtime implementation and report back next week

rvolosatovs commented 1 month ago

https://github.com/bytecodealliance/wasmtime/issues/7592

Seems relevant

aykevl commented 1 month ago

If _initialize isn't being called, that would be a much bigger problem as it also doesn't initialize the runtime (and therefore the heap is not initialized yet, for example). This PR would not fix that problem.

I'd like to understand what's going on here before merging, to make sure we're fixing the right bug.

You can maybe try putting a println statement in a init function to see whether it is being called?

rvolosatovs commented 1 month ago

If _initialize isn't being called, that would be a much bigger problem as it also doesn't initialize the runtime (and therefore the heap is not initialized yet, for example). This PR would not fix that problem.

I'd like to understand what's going on here before merging, to make sure we're fixing the right bug.

You can maybe try putting a println statement in a init function to see whether it is being called?

This PR is meant to address the immediate symptoms of what appears to be a bigger problem indeed.

I can try calling a function from init next week, but do note that the export handler is registered in init https://github.com/Mossaka/hello-wasi-http-tinygo/blob/main/main.go#L10 (and it is active)

So unless variable assignments in init are handled in some different way, it does appear that init(), at least in main package, is called

aykevl commented 1 month ago

So unless variable assignments in init are handled in some different way,

They are. Many variables are already initialized by a compiler pass as an optimization. Which variables are initialized like this is unspecified, but simple assignments like this one are typically done at compile time. You wouldn't notice the difference however as long as _initialize is being called. Which it appears is not the case here.

A function like println (which does I/O) cannot be done at compile time and using it is a good way to test whether _initialize is being called.

rvolosatovs commented 1 month ago

So unless variable assignments in init are handled in some different way,

They are. Many variables are already initialized by a compiler pass as an optimization. Which variables are initialized like this is unspecified, but simple assignments like this one are typically done at compile time. You wouldn't notice the difference however as long as _initialize is being called. Which it appears is not the case here.

A function like println (which does I/O) cannot be done at compile time and using it is a good way to test whether _initialize is being called.

I tried calling fmt.Println in init() and indeed it had no effect. It seems that either lazy initialization should be used for reactors or some other way to trigger init() is required (which would probably be expected by users)

lxfontes commented 1 month ago

(sharing experience, not sure how much it helps)

This can be replicated in a regular wasip2 component. Combinations:

type holder struct {
    str    string
    ptr    *string
    mapStr map[string]string
    mapPtr map[string]*string
}

var (
    varHolder = holder{
        str:    "top",
        ptr:    ptrFunc(),
        mapStr: map[string]string{"a": "b"},
        mapPtr: map[string]*string{"c": ptrFunc()},
    }
    ptrHolder *holder
)

func init() {
    ptrHolder = &holder{
        str:    "top",
        ptr:    ptrFunc(),
        mapStr: map[string]string{"a": "b"},
        mapPtr: map[string]*string{"c": ptrFunc()},
    }
    caller.Exports.Call = callHandler
}

func ptrFunc() *string {
    s := time.Now().String()
    return &s
}

func callHandler() string {
    callHolder := holder{
        str:    "top",
        ptr:    ptrFunc(),
        mapStr: map[string]string{"a": "b"},
        mapPtr: map[string]*string{"c": ptrFunc()},
    }
    ret := fmt.Sprintf("varHolder: %+v\nptrHolder: %+v\ncallHolder: %+v\n", varHolder, ptrHolder, callHolder)

    return ret
}

yields

varHolder: {str:top ptr:0x15b30 mapStr:map[] mapPtr:map[]}
ptrHolder: &{str:top ptr:0x15b40 mapStr:map[] mapPtr:map[]}
callHolder: {str:top ptr:0x15df0 mapStr:map[a:b] mapPtr:map[c:0x16140]}

looks like symbols & pointers work fine, but things that require make don't.

aykevl commented 1 month ago

Ok, clearly the bug here is that package initializers are not being run. I don't know what the exact problem is, but the proposed fix here doesn't fix the root cause (it only hides some symptoms of the bug).

Closing, since this is the wrong way to fix this bug.

I am pretty sure you should adjust your wasm VM to call _initialize on startup.