Wasmtime GitHub notifications bot (Nov 09 2020 at 17:27): Wasmtime GitHub notifications bot (Nov 09 2020 at 17:27):bkolobara opened Issue #2386:
I recently run into a flaky issue running a WASM app using Externrefs under Wasmtime.
Sadly, I can't share any code related to it. Either way it's a lot of code and I'm looking more at pointers how I could debug this further by myself.Sometimes (8 out of 10 runs) the app would panic with the following error:
thread '<unnamed>' panicked at 'every on-stack externref inside a Wasm frame should have an entry in the VMExternRefActivationsTable', wasmtime/crates/runtime/src/externref.rs:1070:21 stack backtrace: 0: std::panicking::begin_panic at /Users/bkolobara/.rustup/toolchains/nightly-x86_64-apple-darwin/lib/rustlib/src/rust/library/std/src/panicking.rs:505:12 1: wasmtime_runtime::externref::gc::{{closure}} at ./wasmtime/crates/runtime/src/externref.rs:1070:21 2: core::ops::function::impls::<impl core::ops::function::FnMut<A> for &mut F>::call_mut at /Users/bkolobara/.rustup/toolchains/nightly-x86_64-apple-darwin/lib/rustlib/src/rust/library/core/src/ops/function.rs:269:13 3: backtrace::backtrace::libunwind::trace::trace_fn at /Users/bkolobara/.cargo/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.50/src/backtrace/libunwind.rs:107:26 4: __Unwind_Backtrace 5: backtrace::backtrace::libunwind::trace at /Users/bkolobara/.cargo/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.50/src/backtrace/libunwind.rs:95:5 6: backtrace::backtrace::trace_unsynchronized at /Users/bkolobara/.cargo/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.50/src/backtrace/mod.rs:66:5 7: backtrace::backtrace::trace at /Users/bkolobara/.cargo/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.50/src/backtrace/mod.rs:53:14 8: wasmtime_runtime::externref::gc at ./wasmtime/crates/runtime/src/externref.rs:1054:5 9: wasmtime_runtime::externref::VMExternRefActivationsTable::gc_and_insert_slow at ./wasmtime/crates/runtime/src/externref.rs:585:9 10: wasmtime_runtime::externref::VMExternRefActivationsTable::insert_with_gc at ./wasmtime/crates/runtime/src/externref.rs:575:13 11: <core::option::Option<wasmtime::ref::ExternRef> as wasmtime::func::WasmTy>::into_abi_for_arg at ./wasmtime/crates/wasmtime/src/func.rs:1238:17 12: <T as wasmtime::func::WasmRet>::into_abi_for_ret at ./wasmtime/crates/wasmtime/src/func.rs:1350:9 13: <F as wasmtime::func::IntoFunc<(wasmtime::func::Caller,A1,A2,A3),R>>::into_func::wasm_to_host_shim at ./wasmtime/crates/wasmtime/src/func.rs:1624:29 14: <unknown> 15: <unknown> 16: <unknown> 17: <unknown> 18: <unknown> 19: <unknown> 20: <unknown> 21: <unknown> 22: <F as wasmtime::func::IntoFunc<(wasmtime::func::Caller,),R>>::into_func::host_trampoline at ./wasmtime/crates/wasmtime/src/func.rs:1657:31 23: wasmtime::func::Func::call::{{closure}} at ./wasmtime/crates/wasmtime/src/func.rs:620:17 24: wasmtime_runtime::traphandlers::catch_traps::call_closure at ./wasmtime/crates/runtime/src/traphandlers.rs:397:18 25: RegisterSetjmp at ./wasmtime/crates/runtime/src/helpers.c:12:3 26: wasmtime_runtime::traphandlers::catch_traps::{{closure}} at ./wasmtime/crates/runtime/src/traphandlers.rs:386:9 27: wasmtime_runtime::traphandlers::CallThreadState::with::{{closure}} at ./wasmtime/crates/runtime/src/traphandlers.rs:442:38 28: wasmtime_runtime::traphandlers::tls::set::{{closure}} at ./wasmtime/crates/runtime/src/traphandlers.rs:682:13 29: std::thread::local::LocalKey<T>::try_with at /Users/bkolobara/.rustup/toolchains/nightly-x86_64-apple-darwin/lib/rustlib/src/rust/library/std/src/thread/local.rs:272:16 30: std::thread::local::LocalKey<T>::with at /Users/bkolobara/.rustup/toolchains/nightly-x86_64-apple-darwin/lib/rustlib/src/rust/library/std/src/thread/local.rs:248:9 31: wasmtime_runtime::traphandlers::tls::set at ./wasmtime/crates/runtime/src/traphandlers.rs:674:9 32: wasmtime_runtime::traphandlers::CallThreadState::with at ./wasmtime/crates/runtime/src/traphandlers.rs:442:19 33: wasmtime_runtime::traphandlers::catch_traps at ./wasmtime/crates/runtime/src/traphandlers.rs:385:12 34: wasmtime::func::invoke_wasm_and_catch_traps at ./wasmtime/crates/wasmtime/src/func.rs:829:9 35: wasmtime::func::Func::call at ./wasmtime/crates/wasmtime/src/func.rs:619:13 36: lunatic_vm::process::Process::spawn::{{closure}} at ./src/process/mod.rs:160:25 ....The code path taken by the app should always be the same and first of all I can't figure out why it only fails sometimes. Any pointers would be appreciated.
Wasmtime GitHub notifications bot (Nov 09 2020 at 17:27):bkolobara labeled Issue #2386:
I recently run into a flaky issue running a WASM app using Externrefs under Wasmtime.
Sadly, I can't share any code related to it. Either way it's a lot of code and I'm looking more at pointers how I could debug this further by myself.Sometimes (8 out of 10 runs) the app would panic with the following error:
thread '<unnamed>' panicked at 'every on-stack externref inside a Wasm frame should have an entry in the VMExternRefActivationsTable', wasmtime/crates/runtime/src/externref.rs:1070:21 stack backtrace: 0: std::panicking::begin_panic at /Users/bkolobara/.rustup/toolchains/nightly-x86_64-apple-darwin/lib/rustlib/src/rust/library/std/src/panicking.rs:505:12 1: wasmtime_runtime::externref::gc::{{closure}} at ./wasmtime/crates/runtime/src/externref.rs:1070:21 2: core::ops::function::impls::<impl core::ops::function::FnMut<A> for &mut F>::call_mut at /Users/bkolobara/.rustup/toolchains/nightly-x86_64-apple-darwin/lib/rustlib/src/rust/library/core/src/ops/function.rs:269:13 3: backtrace::backtrace::libunwind::trace::trace_fn at /Users/bkolobara/.cargo/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.50/src/backtrace/libunwind.rs:107:26 4: __Unwind_Backtrace 5: backtrace::backtrace::libunwind::trace at /Users/bkolobara/.cargo/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.50/src/backtrace/libunwind.rs:95:5 6: backtrace::backtrace::trace_unsynchronized at /Users/bkolobara/.cargo/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.50/src/backtrace/mod.rs:66:5 7: backtrace::backtrace::trace at /Users/bkolobara/.cargo/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.50/src/backtrace/mod.rs:53:14 8: wasmtime_runtime::externref::gc at ./wasmtime/crates/runtime/src/externref.rs:1054:5 9: wasmtime_runtime::externref::VMExternRefActivationsTable::gc_and_insert_slow at ./wasmtime/crates/runtime/src/externref.rs:585:9 10: wasmtime_runtime::externref::VMExternRefActivationsTable::insert_with_gc at ./wasmtime/crates/runtime/src/externref.rs:575:13 11: <core::option::Option<wasmtime::ref::ExternRef> as wasmtime::func::WasmTy>::into_abi_for_arg at ./wasmtime/crates/wasmtime/src/func.rs:1238:17 12: <T as wasmtime::func::WasmRet>::into_abi_for_ret at ./wasmtime/crates/wasmtime/src/func.rs:1350:9 13: <F as wasmtime::func::IntoFunc<(wasmtime::func::Caller,A1,A2,A3),R>>::into_func::wasm_to_host_shim at ./wasmtime/crates/wasmtime/src/func.rs:1624:29 14: <unknown> 15: <unknown> 16: <unknown> 17: <unknown> 18: <unknown> 19: <unknown> 20: <unknown> 21: <unknown> 22: <F as wasmtime::func::IntoFunc<(wasmtime::func::Caller,),R>>::into_func::host_trampoline at ./wasmtime/crates/wasmtime/src/func.rs:1657:31 23: wasmtime::func::Func::call::{{closure}} at ./wasmtime/crates/wasmtime/src/func.rs:620:17 24: wasmtime_runtime::traphandlers::catch_traps::call_closure at ./wasmtime/crates/runtime/src/traphandlers.rs:397:18 25: RegisterSetjmp at ./wasmtime/crates/runtime/src/helpers.c:12:3 26: wasmtime_runtime::traphandlers::catch_traps::{{closure}} at ./wasmtime/crates/runtime/src/traphandlers.rs:386:9 27: wasmtime_runtime::traphandlers::CallThreadState::with::{{closure}} at ./wasmtime/crates/runtime/src/traphandlers.rs:442:38 28: wasmtime_runtime::traphandlers::tls::set::{{closure}} at ./wasmtime/crates/runtime/src/traphandlers.rs:682:13 29: std::thread::local::LocalKey<T>::try_with at /Users/bkolobara/.rustup/toolchains/nightly-x86_64-apple-darwin/lib/rustlib/src/rust/library/std/src/thread/local.rs:272:16 30: std::thread::local::LocalKey<T>::with at /Users/bkolobara/.rustup/toolchains/nightly-x86_64-apple-darwin/lib/rustlib/src/rust/library/std/src/thread/local.rs:248:9 31: wasmtime_runtime::traphandlers::tls::set at ./wasmtime/crates/runtime/src/traphandlers.rs:674:9 32: wasmtime_runtime::traphandlers::CallThreadState::with at ./wasmtime/crates/runtime/src/traphandlers.rs:442:19 33: wasmtime_runtime::traphandlers::catch_traps at ./wasmtime/crates/runtime/src/traphandlers.rs:385:12 34: wasmtime::func::invoke_wasm_and_catch_traps at ./wasmtime/crates/wasmtime/src/func.rs:829:9 35: wasmtime::func::Func::call at ./wasmtime/crates/wasmtime/src/func.rs:619:13 36: lunatic_vm::process::Process::spawn::{{closure}} at ./src/process/mod.rs:160:25 ....The code path taken by the app should always be the same and first of all I can't figure out why it only fails sometimes. Any pointers would be appreciated.
Wasmtime GitHub notifications bot (Nov 09 2020 at 17:33):bjorn3 commented on Issue #2386:
Can you share the wasm file? That may help with debugging this problem.
Wasmtime GitHub notifications bot (Nov 09 2020 at 17:38):bkolobara commented on Issue #2386:
Yes. This is the file.
wasm-experiment.wasm.zip
Wasmtime GitHub notifications bot (Nov 09 2020 at 17:39):bkolobara edited a comment on Issue #2386:
Yes. This is the file.
wasm-experiment.wasm.zipthis is the
--releasebuild. I can also provide a debug one if it helps.
Wasmtime GitHub notifications bot (Nov 09 2020 at 17:58):alexcrichton commented on Issue #2386:
@bkolobara to confirm, that wasm file has no
externrefin it. Is that the one you're using? It may be that we're not returning an error when you useexternrefwhen we otherwise should!
Wasmtime GitHub notifications bot (Nov 09 2020 at 19:06):bkolobara commented on Issue #2386:
Sorry, I forgot that there are wrapper functions created and injected in the wasm file before it's executed. This wrapper functions save the Externref in a table and return just an index. Now that I think more about it they, didn't get much of testing and could be the issue.
The transformation looks somewhat like this:
;; Input (module (import "lunatic" "spawn" (func (;0;) (param i32 i32 i64) (result i32))) (func $test (result i32) i32.const 0 i32.const 0 i64.const 0 call 0) ) ;; Transformation: (module (type (;0;) (func)) (type (;1;) (func (result i32))) (type (;2;) (func (param i32))) (type (;3;) (func (param i32 i32 i64) (result i32))) (type (;4;) (func (param i32 i32 i64) (result externref))) (type (;5;) (func (param externref) (result i32))) (import "lunatic" "yield" (func (;0;) (type 0))) (import "lunatic" "get_externref_free_slot" (func (;1;) (type 1))) (import "lunatic" "set_externref_free_slot" (func (;2;) (type 2))) (import "lunatic" "spawn" (func (;3;) (type 4))) (func $test (type 1) (result i32) block ;; label = @1 global.get 0 i32.const 1 i32.add global.set 0 global.get 0 i32.const 10000 i32.gt_s if ;; label = @2 call 0 i32.const 0 global.set 0 else end end i32.const 0 i32.const 0 i64.const 0 call 6) ;; Save externref (func (;5;) (type 5) (param externref) (result i32) (local i32) call 1 local.tee 1 table.size 0 i32.eq if ;; label = @1, ref.null extern table.size 0 table.grow 0 drop else end local.get 1 local.get 0 table.set 0 local.get 1) ;; Swap import wrapper (func (;6;) (type 3) (param i32 i32 i64) (result i32) local.get 0 local.get 1 local.get 2 call 3 call 5) ;; Drop externref (func (;7;) (type 2) (param i32) local.get 0 ref.null extern table.set 0 local.get 0 call 2) (table (;0;) 4 externref) (global (;0;) (mut i32) (i32.const 0)) (export "__lunatic_externref_resource_table" (table 0)) (export "_lunatic_externref_save" (func 5)) (export "_lunatic_externref_drop" (func 7)))The
Save externreffunction is the one that preserves the externref in the table. There is also the part on the host side (get_externref_free_slot, set_externref_free_slot) that keeps track of free slots in the externref table.
Wasmtime GitHub notifications bot (Nov 09 2020 at 19:08):bkolobara edited a comment on Issue #2386:
Sorry, I forgot that there are wrapper functions created and injected in the wasm file before it's executed. This wrapper functions save the Externref in a table and return just an index. Now that I think more about it they, didn't get much of testing and could be the issue.
The transformation looks somewhat like this:
;; Input (module (import "lunatic" "spawn" (func (;0;) (param i32 i32 i64) (result i32))) (func $test (result i32) i32.const 0 i32.const 0 i64.const 0 call 0) ) ;; Transformation: (module (type (;0;) (func)) (type (;1;) (func (result i32))) (type (;2;) (func (param i32))) (type (;3;) (func (param i32 i32 i64) (result i32))) (type (;4;) (func (param i32 i32 i64) (result externref))) (type (;5;) (func (param externref) (result i32))) (import "lunatic" "yield" (func (;0;) (type 0))) (import "lunatic" "get_externref_free_slot" (func (;1;) (type 1))) (import "lunatic" "set_externref_free_slot" (func (;2;) (type 2))) (import "lunatic" "spawn" (func (;3;) (type 4))) (func $test (type 1) (result i32) i32.const 0 i32.const 0 i64.const 0 call 6) ;; Save externref (func (;5;) (type 5) (param externref) (result i32) (local i32) call 1 local.tee 1 table.size 0 i32.eq if ;; label = @1, ref.null extern table.size 0 table.grow 0 drop else end local.get 1 local.get 0 table.set 0 local.get 1) ;; Spawn import wrapper (func (;6;) (type 3) (param i32 i32 i64) (result i32) local.get 0 local.get 1 local.get 2 call 3 call 5) ;; Drop externref (func (;7;) (type 2) (param i32) local.get 0 ref.null extern table.set 0 local.get 0 call 2) (table (;0;) 4 externref) (global (;0;) (mut i32) (i32.const 0)) (export "__lunatic_externref_resource_table" (table 0)) (export "_lunatic_externref_save" (func 5)) (export "_lunatic_externref_drop" (func 7)))The
Save externreffunction is the one that preserves the externref in the table. There is also the part on the host side (get_externref_free_slot, set_externref_free_slot) that keeps track of free slots in the externref table.
Wasmtime GitHub notifications bot (Nov 09 2020 at 19:23):bkolobara commented on Issue #2386:
I have published the code here: https://github.com/lunatic-lang/lunatic. You should be able to run the .wasm file with:
cargo run -- wasm-experiment.wasm.I just didn't test it on different operating systems and it may not work on Windows.
Wasmtime GitHub notifications bot (Nov 09 2020 at 19:25):bkolobara edited a comment on Issue #2386:
I have published the code here: https://github.com/lunatic-lang/lunatic. You should be able to run the .wasm file with:
cargo run -- wasm-experiment.wasm.I just didn't test it on different operating systems and it may not work on Windows. Also, my usage of Wasmtime is a bit unconventional :). This could also be a source of issues.
Wasmtime GitHub notifications bot (Nov 09 2020 at 20:58):alexcrichton commented on Issue #2386:
Ok thanks for the repo! It looks like there's a number of
unsafeblocks and it also looks like you're reaching into wasmtime internals (thewasmtime-runtimecrate), so that may be what's going wrong here? Would it be possible to try to cut that back and see if it works better?
Wasmtime GitHub notifications bot (Nov 09 2020 at 21:24):fitzgen commented on Issue #2386:
Thanks for filing a bug report @bkolobara.
If you could create a wasm file such that running
$ wasmtime test.wasmexhibits the issue, I could take it from there and reduce the test case myself.
But yeah, as @alexcrichton pointed out, using Wasmtime internals is super unsafe since we maintain all the safety invariants in the
wasmtimecrate, especially with reference types.
Wasmtime GitHub notifications bot (Nov 09 2020 at 21:26):bkolobara commented on Issue #2386:
Yes, there is a lot going on in the codebase. It will take some time to trim back on the unsafe code. If I manage to construct a minimal reproducible example I will post an update. Thanks everyone for taking the time and looking into this!
Wasmtime GitHub notifications bot (Nov 10 2020 at 12:05):bkolobara commented on Issue #2386:
@alexcrichton @fitzgen thanks again for helping me out with this. I have managed to extract just the problematic part without any unsafe code:
use wasmtime::{Config, Engine, ExternRef, Linker, Module, Store,}; fn main() { let mut config = Config::new(); config.wasm_reference_types(true); let engine = Engine::new(&config); let module = Module::new(&engine, " (module (type (;0;) (func (result i32))) (type (;1;) (func (param i32 i32 i64) (result externref))) (type (;2;) (func (param i32 i32 i64) (result i32))) (type (;3;) (func (param externref) (result i32))) (type (;4;) (func)) (import \"test\" \"spawn\" (func $spawn (type 1))) (func $_start (type 4) (local i32) i32.const 10000 local.set 0 loop ;; label = @1 i32.const 4 i32.const 0 i64.const 0 call $externref_wrapper_for_spawn drop local.get 0 i32.const -1 i32.add local.tee 0 br_if 0 (;@1;) end) (func $preserve_externref_in_table (type 3) (param externref) (result i32) (local i32) i32.const 0 local.tee 1 table.size $externref_table i32.eq if (result i32) ;; label = @1 ref.null extern table.size $externref_table table.grow $externref_table else local.get 1 end local.get 0 table.set $externref_table local.get 1) (func $externref_wrapper_for_spawn (type 2) (param i32 i32 i64) (result i32) local.get 0 local.get 1 local.get 2 call $spawn call $preserve_externref_in_table) (table $externref_table 4 externref) (export \"_start\" (func $_start)) )").unwrap(); let store = Store::new(&engine.clone()); let mut linker = Linker::new(&store); linker.func( "test", "spawn", move |index: i32, argument1: i32, argument2: i64| -> Option<ExternRef> { Some(ExternRef::new((index, argument1, argument2))) }, ).unwrap(); let instance = linker.instantiate(&module.clone()).unwrap(); let start = instance.get_func("_start").unwrap(); start.call(&[]).unwrap(); }This fails on
wasmtime = "0.21"on my Macbook withthread 'main' panicked at 'every on-stack externref inside a Wasm frame should have an entry in the VMExternRefActivationsTable', /Users/bkolobara/.cargo/registry/src/github.com-1ecc6299db9ec823/wasmtime-runtime-0.21.0/src/externref.rs:1070:21 stack backtrace: 0: 0x10d76a664 - std::backtrace_rs::backtrace::libunwind::trace::hb4ff9014ec5817b3 at /rustc/ffa2e7ae8fbf9badc035740db949b9dae271c29f/library/std/src/../../backtrace/src/backtrace/libunwind.rs:100:5 1: 0x10d76a664 - std::backtrace_rs::backtrace::trace_unsynchronized::h0d03cf0f7c5d8d01 at /rustc/ffa2e7ae8fbf9badc035740db949b9dae271c29f/library/std/src/../../backtrace/src/backtrace/mod.rs:66:5 2: 0x10d76a664 - std::sys_common::backtrace::_print_fmt::h5b2bf2921eea85ae at /rustc/ffa2e7ae8fbf9badc035740db949b9dae271c29f/library/std/src/sys_common/backtrace.rs:67:5 3: 0x10d76a664 - <std::sys_common::backtrace::_print::DisplayBacktrace as core::fmt::Display>::fmt::h808cc0fc691f5922 at /rustc/ffa2e7ae8fbf9badc035740db949b9dae271c29f/library/std/src/sys_common/backtrace.rs:46:22 4: 0x10d789660 - core::fmt::write::h0ce880d33cd2a300 at /rustc/ffa2e7ae8fbf9badc035740db949b9dae271c29f/library/core/src/fmt/mod.rs:1076:17 5: 0x10d767906 - std::io::Write::write_fmt::h057e6b5365b25cdb at /rustc/ffa2e7ae8fbf9badc035740db949b9dae271c29f/library/std/src/io/mod.rs:1516:15 6: 0x10d76c459 - std::sys_common::backtrace::_print::ha1932a5f36d2b146 at /rustc/ffa2e7ae8fbf9badc035740db949b9dae271c29f/library/std/src/sys_common/backtrace.rs:49:5 7: 0x10d76c459 - std::sys_common::backtrace::print::had07999cb13bdf77 at /rustc/ffa2e7ae8fbf9badc035740db949b9dae271c29f/library/std/src/sys_common/backtrace.rs:36:9 8: 0x10d76c459 - std::panicking::default_hook::{{closure}}::hcbe1ecfff77305a1 at /rustc/ffa2e7ae8fbf9badc035740db949b9dae271c29f/library/std/src/panicking.rs:208:50 9: 0x10d76c11d - std::panicking::default_hook::h8422621c02c35b35 at /rustc/ffa2e7ae8fbf9badc035740db949b9dae271c29f/library/std/src/panicking.rs:227:9 10: 0x10d76ca2b - std::panicking::rust_panic_with_hook::h82b76d3adf4cbc3a at /rustc/ffa2e7ae8fbf9badc035740db949b9dae271c29f/library/std/src/panicking.rs:577:17 11: 0x10d6da1e7 - std::panicking::begin_panic::{{closure}}::h610cb27706798e28 at /Users/bkolobara/.rustup/toolchains/nightly-x86_64-apple-darwin/lib/rustlib/src/rust/library/std/src/panicking.rs:506:9 12: 0x10d6dcfb8 - std::sys_common::backtrace::__rust_end_short_backtrace::h02cad55c8fedcf0f at /Users/bkolobara/.rustup/toolchains/nightly-x86_64-apple-darwin/lib/rustlib/src/rust/library/std/src/sys_common/backtrace.rs:141:18 13: 0x10d79ea57 - std::panicking::begin_panic::h00999f2b800d5901 at /Users/bkolobara/.rustup/toolchains/nightly-x86_64-apple-darwin/lib/rustlib/src/rust/library/std/src/panicking.rs:505:12 14: 0x10d258ab0 - wasmtime_runtime::externref::gc::{{closure}}::hb874548da7bd3130 at /Users/bkolobara/.cargo/registry/src/github.com-1ecc6299db9ec823/wasmtime-runtime-0.21.0/src/externref.rs:1070:21 15: 0x10d293797 - core::ops::function::impls::<impl core::ops::function::FnMut<A> for &mut F>::call_mut::h49b4b17374a4fb04 at /Users/bkolobara/.rustup/toolchains/nightly-x86_64-apple-darwin/lib/rustlib/src/rust/library/core/src/ops/function.rs:269:13 16: 0x10d29356e - backtrace::backtrace::libunwind::trace::trace_fn::h5adea0a7301c455e at /Users/bkolobara/.cargo/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.51/src/backtrace/libunwind.rs:112:26 17: 0x7fff67d3313f - __Unwind_Backtrace 18: 0x10d269d1d - backtrace::backtrace::libunwind::trace::hb7d773b2da24a258 at /Users/bkolobara/.cargo/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.51/src/backtrace/libunwind.rs:100:5 19: 0x10d269d1d - backtrace::backtrace::trace_unsynchronized::h51fd14a962d6e2bc at /Users/bkolobara/.cargo/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.51/src/backtrace/mod.rs:66:5 20: 0x10d269de0 - backtrace::backtrace::trace::h87a228ab8df6eb34 at /Users/bkolobara/.cargo/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.51/src/backtrace/mod.rs:53:14 21: 0x10d258340 - wasmtime_runtime::externref::gc::he8a9e6a7fbc383cf at /Users/bkolobara/.cargo/registry/src/github.com-1ecc6299db9ec823/wasmtime-runtime-0.21.0/src/externref.rs:1054:5 22: 0x10d256eec - wasmtime_runtime::externref::VMExternRefActivationsTable::gc_and_insert_slow::h9889192c254632da at /Users/bkolobara/.cargo/registry/src/github.com-1ecc6299db9ec823/wasmtime-runtime-0.21.0/src/externref.rs:585:9 23: 0x10cba3d13 - wasmtime_runtime::externref::VMExternRefActivationsTable::insert_with_gc::hd1333067f4a1dc90 at /Users/bkolobara/.cargo/registry/src/github.com-1ecc6299db9ec823/wasmtime-runtime-0.21.0/src/externref.rs:575:13 24: 0x10cba38fb - <core::option::Option<wasmtime::ref::ExternRef> as wasmtime::func::WasmTy>::into_abi_for_arg::hf23e691b1199274e at /Users/bkolobara/.cargo/registry/src/github.com-1ecc6299db9ec823/wasmtime-0.21.0/src/func.rs:1238:17 25: 0x10cba5175 - <T as wasmtime::func::WasmRet>::into_abi_for_ret::hb931fe5db644ccb7 at /Users/bkolobara/.cargo/registry/src/github.com-1ecc6299db9ec823/wasmtime-0.21.0/src/func.rs:1350:9 26: 0x10cba9d80 - <F as wasmtime::func::IntoFunc<(wasmtime::func::Caller,A1,A2,A3),R>>::into_func::wasm_to_host_shim::h933e81e93c4f6514 at /Users/bkolobara/.cargo/registry/src/github.com-1ecc6299db9ec823/wasmtime-0.21.0/src/func.rs:1624:29 27: 0x10ec1a22e - <unknown> 28: 0x10ec1a0b1 - <unknown> 29: 0x10ec1a357 - <unknown> 30: 0x10cbeaaac - wasmtime::func::Func::call::{{closure}}::h0b827b767c43434d at /Users/bkolobara/.cargo/registry/src/github.com-1ecc6299db9ec823/wasmtime-0.21.0/src/func.rs:620:17 31: 0x10cc272c1 - wasmtime_runtime::traphandlers::catch_traps::call_closure::h0433cee3ab91db78 at /Users/bkolobara/.cargo/registry/src/github.com-1ecc6299db9ec823/wasmtime-runtime-0.21.0/src/traphandlers.rs:397:18 32: 0x10d28f276 - RegisterSetjmp at /Users/b [message truncated]
Wasmtime GitHub notifications bot (Nov 10 2020 at 14:36):bkolobara edited a comment on Issue #2386:
@alexcrichton @fitzgen thanks again for helping me out with this. I have managed to extract just the problematic part without any unsafe code:
use wasmtime::{Config, Engine, ExternRef, Linker, Module, Store,}; fn main() { let mut config = Config::new(); config.wasm_reference_types(true); let engine = Engine::new(&config); let module = Module::new(&engine, " (module (type (;0;) (func (result i32))) (type (;1;) (func (param i32 i32 i64) (result externref))) (type (;2;) (func (param i32 i32 i64) (result i32))) (type (;3;) (func (param externref) (result i32))) (type (;4;) (func)) (import \"test\" \"spawn\" (func $spawn (type 1))) (func $_start (type 4) (local i32) i32.const 10000 local.set 0 loop ;; label = @1 i32.const 4 i32.const 0 i64.const 0 call $externref_wrapper_for_spawn drop local.get 0 i32.const -1 i32.add local.tee 0 br_if 0 (;@1;) end) (func $preserve_externref_in_table (type 3) (param externref) (result i32) (local i32) i32.const 0 local.tee 1 table.size $externref_table i32.eq if (result i32) ;; label = @1 ref.null extern table.size $externref_table table.grow $externref_table else local.get 1 end local.get 0 table.set $externref_table local.get 1) (func $externref_wrapper_for_spawn (type 2) (param i32 i32 i64) (result i32) local.get 0 local.get 1 local.get 2 call $spawn call $preserve_externref_in_table) (table $externref_table 4 externref) (export \"_start\" (func $_start)) )").unwrap(); let store = Store::new(&engine.clone()); let mut linker = Linker::new(&store); linker.func( "test", "spawn", move |index: i32, argument1: i32, argument2: i64| -> Option<ExternRef> { Some(ExternRef::new((index, argument1, argument2))) }, ).unwrap(); let instance = linker.instantiate(&module.clone()).unwrap(); let start = instance.get_func("_start").unwrap(); start.call(&[]).unwrap(); }This fails on
wasmtime = "0.21"on my Macbook with:<details><summary>Expend stacktrace</summary>
thread 'main' panicked at 'every on-stack externref inside a Wasm frame should have an entry in the VMExternRefActivationsTable', /Users/bkolobara/.cargo/registry/src/github.com-1ecc6299db9ec823/wasmtime-runtime-0.21.0/src/externref.rs:1070:21 stack backtrace: 0: 0x10d76a664 - std::backtrace_rs::backtrace::libunwind::trace::hb4ff9014ec5817b3 at /rustc/ffa2e7ae8fbf9badc035740db949b9dae271c29f/library/std/src/../../backtrace/src/backtrace/libunwind.rs:100:5 1: 0x10d76a664 - std::backtrace_rs::backtrace::trace_unsynchronized::h0d03cf0f7c5d8d01 at /rustc/ffa2e7ae8fbf9badc035740db949b9dae271c29f/library/std/src/../../backtrace/src/backtrace/mod.rs:66:5 2: 0x10d76a664 - std::sys_common::backtrace::_print_fmt::h5b2bf2921eea85ae at /rustc/ffa2e7ae8fbf9badc035740db949b9dae271c29f/library/std/src/sys_common/backtrace.rs:67:5 3: 0x10d76a664 - <std::sys_common::backtrace::_print::DisplayBacktrace as core::fmt::Display>::fmt::h808cc0fc691f5922 at /rustc/ffa2e7ae8fbf9badc035740db949b9dae271c29f/library/std/src/sys_common/backtrace.rs:46:22 4: 0x10d789660 - core::fmt::write::h0ce880d33cd2a300 at /rustc/ffa2e7ae8fbf9badc035740db949b9dae271c29f/library/core/src/fmt/mod.rs:1076:17 5: 0x10d767906 - std::io::Write::write_fmt::h057e6b5365b25cdb at /rustc/ffa2e7ae8fbf9badc035740db949b9dae271c29f/library/std/src/io/mod.rs:1516:15 6: 0x10d76c459 - std::sys_common::backtrace::_print::ha1932a5f36d2b146 at /rustc/ffa2e7ae8fbf9badc035740db949b9dae271c29f/library/std/src/sys_common/backtrace.rs:49:5 7: 0x10d76c459 - std::sys_common::backtrace::print::had07999cb13bdf77 at /rustc/ffa2e7ae8fbf9badc035740db949b9dae271c29f/library/std/src/sys_common/backtrace.rs:36:9 8: 0x10d76c459 - std::panicking::default_hook::{{closure}}::hcbe1ecfff77305a1 at /rustc/ffa2e7ae8fbf9badc035740db949b9dae271c29f/library/std/src/panicking.rs:208:50 9: 0x10d76c11d - std::panicking::default_hook::h8422621c02c35b35 at /rustc/ffa2e7ae8fbf9badc035740db949b9dae271c29f/library/std/src/panicking.rs:227:9 10: 0x10d76ca2b - std::panicking::rust_panic_with_hook::h82b76d3adf4cbc3a at /rustc/ffa2e7ae8fbf9badc035740db949b9dae271c29f/library/std/src/panicking.rs:577:17 11: 0x10d6da1e7 - std::panicking::begin_panic::{{closure}}::h610cb27706798e28 at /Users/bkolobara/.rustup/toolchains/nightly-x86_64-apple-darwin/lib/rustlib/src/rust/library/std/src/panicking.rs:506:9 12: 0x10d6dcfb8 - std::sys_common::backtrace::__rust_end_short_backtrace::h02cad55c8fedcf0f at /Users/bkolobara/.rustup/toolchains/nightly-x86_64-apple-darwin/lib/rustlib/src/rust/library/std/src/sys_common/backtrace.rs:141:18 13: 0x10d79ea57 - std::panicking::begin_panic::h00999f2b800d5901 at /Users/bkolobara/.rustup/toolchains/nightly-x86_64-apple-darwin/lib/rustlib/src/rust/library/std/src/panicking.rs:505:12 14: 0x10d258ab0 - wasmtime_runtime::externref::gc::{{closure}}::hb874548da7bd3130 at /Users/bkolobara/.cargo/registry/src/github.com-1ecc6299db9ec823/wasmtime-runtime-0.21.0/src/externref.rs:1070:21 15: 0x10d293797 - core::ops::function::impls::<impl core::ops::function::FnMut<A> for &mut F>::call_mut::h49b4b17374a4fb04 at /Users/bkolobara/.rustup/toolchains/nightly-x86_64-apple-darwin/lib/rustlib/src/rust/library/core/src/ops/function.rs:269:13 16: 0x10d29356e - backtrace::backtrace::libunwind::trace::trace_fn::h5adea0a7301c455e at /Users/bkolobara/.cargo/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.51/src/backtrace/libunwind.rs:112:26 17: 0x7fff67d3313f - __Unwind_Backtrace 18: 0x10d269d1d - backtrace::backtrace::libunwind::trace::hb7d773b2da24a258 at /Users/bkolobara/.cargo/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.51/src/backtrace/libunwind.rs:100:5 19: 0x10d269d1d - backtrace::backtrace::trace_unsynchronized::h51fd14a962d6e2bc at /Users/bkolobara/.cargo/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.51/src/backtrace/mod.rs:66:5 20: 0x10d269de0 - backtrace::backtrace::trace::h87a228ab8df6eb34 at /Users/bkolobara/.cargo/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.51/src/backtrace/mod.rs:53:14 21: 0x10d258340 - wasmtime_runtime::externref::gc::he8a9e6a7fbc383cf at /Users/bkolobara/.cargo/registry/src/github.com-1ecc6299db9ec823/wasmtime-runtime-0.21.0/src/externref.rs:1054:5 22: 0x10d256eec - wasmtime_runtime::externref::VMExternRefActivationsTable::gc_and_insert_slow::h9889192c254632da at /Users/bkolobara/.cargo/registry/src/github.com-1ecc6299db9ec823/wasmtime-runtime-0.21.0/src/externref.rs:585:9 23: 0x10cba3d13 - wasmtime_runtime::externref::VMExternRefActivationsTable::insert_with_gc::hd1333067f4a1dc90 at /Users/bkolobara/.cargo/registry/src/github.com-1ecc6299db9ec823/wasmtime-runtime-0.21.0/src/externref.rs:575:13 24: 0x10cba38fb - <core::option::Option<wasmtime::ref::ExternRef> as wasmtime::func::WasmTy>::into_abi_for_arg::hf23e691b1199274e at /Users/bkolobara/.cargo/registry/src/github.com-1ecc6299db9ec823/wasmtime-0.21.0/src/func.rs:1238:17 25: 0x10cba5175 - <T as wasmtime::func::WasmRet>::into_abi_for_ret::hb931fe5db644ccb7 at /Users/bkolobara/.cargo/registry/src/github.com-1ecc6299db9ec823/wasmtime-0.21.0/src/func.rs:1350:9 26: 0x10cba9d80 - <F as wasmtime::func::IntoFunc<(wasmtime::func::Caller,A1,A2,A3),R>>::into_func::wasm_to_host_shim::h933e81e93c4f6514 at /Users/bkolobara/.cargo/registry/src/github.com-1ecc6299db9ec823/wasmtime-0.21.0/src/func.rs:1624:29 27: 0x10ec1a22e - <unknown> 28: 0x10ec1a0b1 - <unknown> 29: 0x10ec1a357 - <unknown> 30: 0x10cbeaaac - wasmtime::func::Func::call::{{closure}}::h0b827b767c43434d at /Users/bkolobara/.cargo/registry/src/github.com-1ecc6299db9ec823/wasmtime-0.21.0/src/func.rs:620:17 31: 0x10cc272c1 - wasmtime_runtime::traphandlers::catch_traps::call_closure::h0433cee3ab91db78 at /Users/bkolobara/.cargo/registry/src/github.com-1ecc6299db9ec823/wasmtime-runtime-0.21.0/src/traphandlers.rs:397:18 32: 0x10d28f276 - Re [message truncated]
Wasmtime GitHub notifications bot (Nov 10 2020 at 15:20):alexcrichton commented on Issue #2386:
Perfect, thanks!
Wasmtime GitHub notifications bot (Nov 11 2020 at 22:50):alexcrichton commented on Issue #2386:
Thanks again for the clear test case! This should be fixed in https://github.com/bytecodealliance/wasmtime/pull/2396
Wasmtime GitHub notifications bot (Nov 12 2020 at 19:24):alexcrichton closed Issue #2386:
I recently run into a flaky issue running a WASM app using Externrefs under Wasmtime.
Sadly, I can't share any code related to it. Either way it's a lot of code and I'm looking more at pointers how I could debug this further by myself.Sometimes (8 out of 10 runs) the app would panic with the following error:
thread '<unnamed>' panicked at 'every on-stack externref inside a Wasm frame should have an entry in the VMExternRefActivationsTable', wasmtime/crates/runtime/src/externref.rs:1070:21 stack backtrace: 0: std::panicking::begin_panic at /Users/bkolobara/.rustup/toolchains/nightly-x86_64-apple-darwin/lib/rustlib/src/rust/library/std/src/panicking.rs:505:12 1: wasmtime_runtime::externref::gc::{{closure}} at ./wasmtime/crates/runtime/src/externref.rs:1070:21 2: core::ops::function::impls::<impl core::ops::function::FnMut<A> for &mut F>::call_mut at /Users/bkolobara/.rustup/toolchains/nightly-x86_64-apple-darwin/lib/rustlib/src/rust/library/core/src/ops/function.rs:269:13 3: backtrace::backtrace::libunwind::trace::trace_fn at /Users/bkolobara/.cargo/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.50/src/backtrace/libunwind.rs:107:26 4: __Unwind_Backtrace 5: backtrace::backtrace::libunwind::trace at /Users/bkolobara/.cargo/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.50/src/backtrace/libunwind.rs:95:5 6: backtrace::backtrace::trace_unsynchronized at /Users/bkolobara/.cargo/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.50/src/backtrace/mod.rs:66:5 7: backtrace::backtrace::trace at /Users/bkolobara/.cargo/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.50/src/backtrace/mod.rs:53:14 8: wasmtime_runtime::externref::gc at ./wasmtime/crates/runtime/src/externref.rs:1054:5 9: wasmtime_runtime::externref::VMExternRefActivationsTable::gc_and_insert_slow at ./wasmtime/crates/runtime/src/externref.rs:585:9 10: wasmtime_runtime::externref::VMExternRefActivationsTable::insert_with_gc at ./wasmtime/crates/runtime/src/externref.rs:575:13 11: <core::option::Option<wasmtime::ref::ExternRef> as wasmtime::func::WasmTy>::into_abi_for_arg at ./wasmtime/crates/wasmtime/src/func.rs:1238:17 12: <T as wasmtime::func::WasmRet>::into_abi_for_ret at ./wasmtime/crates/wasmtime/src/func.rs:1350:9 13: <F as wasmtime::func::IntoFunc<(wasmtime::func::Caller,A1,A2,A3),R>>::into_func::wasm_to_host_shim at ./wasmtime/crates/wasmtime/src/func.rs:1624:29 14: <unknown> 15: <unknown> 16: <unknown> 17: <unknown> 18: <unknown> 19: <unknown> 20: <unknown> 21: <unknown> 22: <F as wasmtime::func::IntoFunc<(wasmtime::func::Caller,),R>>::into_func::host_trampoline at ./wasmtime/crates/wasmtime/src/func.rs:1657:31 23: wasmtime::func::Func::call::{{closure}} at ./wasmtime/crates/wasmtime/src/func.rs:620:17 24: wasmtime_runtime::traphandlers::catch_traps::call_closure at ./wasmtime/crates/runtime/src/traphandlers.rs:397:18 25: RegisterSetjmp at ./wasmtime/crates/runtime/src/helpers.c:12:3 26: wasmtime_runtime::traphandlers::catch_traps::{{closure}} at ./wasmtime/crates/runtime/src/traphandlers.rs:386:9 27: wasmtime_runtime::traphandlers::CallThreadState::with::{{closure}} at ./wasmtime/crates/runtime/src/traphandlers.rs:442:38 28: wasmtime_runtime::traphandlers::tls::set::{{closure}} at ./wasmtime/crates/runtime/src/traphandlers.rs:682:13 29: std::thread::local::LocalKey<T>::try_with at /Users/bkolobara/.rustup/toolchains/nightly-x86_64-apple-darwin/lib/rustlib/src/rust/library/std/src/thread/local.rs:272:16 30: std::thread::local::LocalKey<T>::with at /Users/bkolobara/.rustup/toolchains/nightly-x86_64-apple-darwin/lib/rustlib/src/rust/library/std/src/thread/local.rs:248:9 31: wasmtime_runtime::traphandlers::tls::set at ./wasmtime/crates/runtime/src/traphandlers.rs:674:9 32: wasmtime_runtime::traphandlers::CallThreadState::with at ./wasmtime/crates/runtime/src/traphandlers.rs:442:19 33: wasmtime_runtime::traphandlers::catch_traps at ./wasmtime/crates/runtime/src/traphandlers.rs:385:12 34: wasmtime::func::invoke_wasm_and_catch_traps at ./wasmtime/crates/wasmtime/src/func.rs:829:9 35: wasmtime::func::Func::call at ./wasmtime/crates/wasmtime/src/func.rs:619:13 36: lunatic_vm::process::Process::spawn::{{closure}} at ./src/process/mod.rs:160:25 ....The code path taken by the app should always be the same and first of all I can't figure out why it only fails sometimes. Any pointers would be appreciated.
Last updated: Dec 23 2024 at 12:05 UTC