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

Failed to instantiate a deserialized Module compiled with the Dylib engine #2434

Closed
vavrusa opened this issue Jun 18, 2021 · 18 comments · Fixed by #2806
Closed

Failed to instantiate a deserialized Module compiled with the Dylib engine #2434

vavrusa opened this issue Jun 18, 2021 · 18 comments · Fixed by #2806
Assignees
Labels
bug Something isn't working 📦 lib-engine-dylib About wasmer-engine-dylib 🕵️ needs investigation The issue/PR needs further investigation priority-high High priority issue project-terra
Milestone

Comments

@vavrusa
Copy link
Contributor

vavrusa commented Jun 18, 2021

Describe the bug

Instance::new panics when the module is deserialized from FileSystemCache and engine is native.

wasmer-2.0.0 | rustc 1.52.1 (9bc8c42bb 2021-05-09) | x86_64

Steps to reproduce

Test wasm:

$ cat main.rs
fn main() {}
$ cargo build --release --target wasm32-unknown-unknown

Reproducer:

use wasmer_cache::Cache;

let path = test_root_path();
let wasm_bin = '...';

// Write a test app file
let compiler_config = wasmer::LLVM::default();
let engine = wasmer::Dylib::new(compiler_config).engine();
let store = wasmer::Store::new(&engine);
let import_object = wasmer::imports! {};
let hash = wasmer_cache::Hash::generate(&wasm_bin);
let module = wasmer::Module::new(&store, wasm_bin).unwrap();

// Instantiate from compiled
drop(wasmer::Instance::new(&module, &import_object).unwrap());

// Instantiate from cache
let mut cache = wasmer_cache::FileSystemCache::new(&path).unwrap();
cache.store(hash, &module).unwrap();
let module = unsafe { cache.load(&store, hash) }.unwrap();
drop(wasmer::Instance::new(&module, &import_object).unwrap());

Expected behavior

I would expect the Instance::new to succeed (or return an error).

Actual behavior

thread 'tokio-runtime-worker' panicked at 'assertion failed: prev.start > max', /Users/vavrusa/.cargo/registry/src/github.com-1ecc6299db9ec823/wasmer-engine-2.0.0/src/trap/frame_info.rs:232:9
stack backtrace:
   0: rust_begin_unwind
             at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/std/src/panicking.rs:493:5
   1: core::panicking::panic_fmt
             at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/core/src/panicking.rs:92:14
   2: core::panicking::panic
             at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/core/src/panicking.rs:50:5
   3: wasmer_engine::trap::frame_info::register
             at /Users/vavrusa/.cargo/registry/src/github.com-1ecc6299db9ec823/wasmer-engine-2.0.0/src/trap/frame_info.rs:232:9
   4: <wasmer_engine_dylib::artifact::DylibArtifact as wasmer_engine::artifact::Artifact>::register_frame_info
             at /Users/vavrusa/.cargo/registry/src/github.com-1ecc6299db9ec823/wasmer-engine-dylib-2.0.0/src/artifact.rs:725:17
   5: wasmer_engine::artifact::Artifact::instantiate
             at /Users/vavrusa/.cargo/registry/src/github.com-1ecc6299db9ec823/wasmer-engine-2.0.0/src/artifact.rs:137:9
   6: wasmer::module::Module::instantiate
             at /Users/vavrusa/.cargo/registry/src/github.com-1ecc6299db9ec823/wasmer-2.0.0/src/module.rs:267:35
   7: wasmer::instance::Instance::new
             at /Users/vavrusa/.cargo/registry/src/github.com-1ecc6299db9ec823/wasmer-2.0.0/src/instance.rs:117:22

Additional context

@vavrusa vavrusa added the bug Something isn't working label Jun 18, 2021
@Hywan Hywan self-assigned this Jun 25, 2021
@Hywan
Copy link
Contributor

Hywan commented Jun 25, 2021

Thank you for the bug report! We will investigate.

@Hywan
Copy link
Contributor

Hywan commented Jun 25, 2021

I can reproduce the bug. It doesn't happen with the Universal engine, it's only with the Dylib engine.

It's not related to wasmer_cache. I can reproduce the bug with:

let compiler = LLVM::default();
let store = Store::new(&Dylib::new(compiler).engine());

let module = Module::new();
let serialized_module = module.serialize()?;
let module = unsafe { Module::deserialize(&store, &serialized_module)? };
let instance = Instance::new(&module, &import_object)?;

I've changed the compiler to Cranelift, it doesn't change. It's really related to the serialization and deserialization of the Dylib engine's output.

@Hywan Hywan added the 📦 lib-engine-dylib About wasmer-engine-dylib label Jun 25, 2021
@Hywan Hywan changed the title Instance::new panics when module is deserialized from FileSystemCache Failed to instantiate a deserialized Module compiled with the Dylib engine Jun 25, 2021
@Hywan Hywan added this to 📬 Backlog in Wasmer Runtime Issue Board via automation Jul 17, 2021
@Hywan Hywan moved this from 📬 Backlog to 🏁 Ready in Wasmer Runtime Issue Board Jul 17, 2021
@zimond
Copy link

zimond commented Sep 6, 2021

Still triggering. Is there any workaround?

@syrusakbary syrusakbary added the priority-high High priority issue label Oct 20, 2021
@wchaudry wchaudry added this to the Wasmer Runtime 2.x milestone Oct 21, 2021
@Amanieu Amanieu added the 🕵️ needs investigation The issue/PR needs further investigation label Nov 3, 2021
@Amanieu Amanieu self-assigned this Nov 3, 2021
@Amanieu
Copy link
Contributor

Amanieu commented Nov 4, 2021

I cannot reproduce this with the latest master from git.

@yun-yeo
Copy link
Contributor

yun-yeo commented Nov 13, 2021

@Amanieu

This one is also happening CosmWasm@0.16.2(wasmer@2.0.0) installed software under heavy concurrent thread situation.
Here is stack trace.

The error is happening in alpine static built and linux shared library CosmWasm (both are linux).

@yun-yeo
Copy link
Contributor

yun-yeo commented Dec 31, 2021

here is detail logs.
This error happens when the wasmvm executed extensively and concurrently.
so guess, this is related with some multi-thread handing.

[90m1:57AM�[0m �[1m�[31mERR�[0m�[0m dialing failed (attempts: 1): dial tcp 18.222.188.52:26656: i/o timeout �[36maddr=�[0m{"id":"e86989c0d33670ee94bffb82aec0a17bc8c73722","ip":"18.222.188.52","port":26656} �[36mmodule=�[0mpex
thread '<unnamed>' panicked at 'assertion failed: prev.start > max', /usr/local/cargo/registry/src/github.com-1ecc6299db9ec823/wasmer-engine-2.0.0/src/trap/frame_info.rs:232:9
stack backtrace:
   0:     0x7ffff7d046e0 - std::backtrace_rs::backtrace::libunwind::trace::ha5edb8ba5c6b7a6c
                               at /rustc/53cb7b09b00cbea8754ffb78e7e3cb521cb8af4b/library/std/src/../../backtrace/src/backtrace/libunwind.rs:90:5
   1:     0x7ffff7d046e0 - std::backtrace_rs::backtrace::trace_unsynchronized::h0de86d320a827db2
                               at /rustc/53cb7b09b00cbea8754ffb78e7e3cb521cb8af4b/library/std/src/../../backtrace/src/backtrace/mod.rs:66:5
   2:     0x7ffff7d046e0 - std::sys_common::backtrace::_print_fmt::h97b9ad6f0a1380ff
                               at /rustc/53cb7b09b00cbea8754ffb78e7e3cb521cb8af4b/library/std/src/sys_common/backtrace.rs:67:5
   3:     0x7ffff7d046e0 - <std::sys_common::backtrace::_print::DisplayBacktrace as core::fmt::Display>::fmt::h14be7eb08f97fe80
                               at /rustc/53cb7b09b00cbea8754ffb78e7e3cb521cb8af4b/library/std/src/sys_common/backtrace.rs:46:22
   4:     0x7ffff7d24b9f - core::fmt::write::h2ca8877d3e0e52de
                               at /rustc/53cb7b09b00cbea8754ffb78e7e3cb521cb8af4b/library/core/src/fmt/mod.rs:1094:17
   5:     0x7ffff7d027d5 - std::io::Write::write_fmt::h64f5987220b618f4
                               at /rustc/53cb7b09b00cbea8754ffb78e7e3cb521cb8af4b/library/std/src/io/mod.rs:1584:15
   6:     0x7ffff7d0664b - std::sys_common::backtrace::_print::h7f1a4097308f2e0a
                               at /rustc/53cb7b09b00cbea8754ffb78e7e3cb521cb8af4b/library/std/src/sys_common/backtrace.rs:49:5
   7:     0x7ffff7d0664b - std::sys_common::backtrace::print::h1f799fc2ca7f5035
                               at /rustc/53cb7b09b00cbea8754ffb78e7e3cb521cb8af4b/library/std/src/sys_common/backtrace.rs:36:9
   8:     0x7ffff7d0664b - std::panicking::default_hook::{{closure}}::hf38436e8a3ce1071
                               at /rustc/53cb7b09b00cbea8754ffb78e7e3cb521cb8af4b/library/std/src/panicking.rs:208:50
   9:     0x7ffff7d0611d - std::panicking::default_hook::he2f8f3fae11ed1dd
                               at /rustc/53cb7b09b00cbea8754ffb78e7e3cb521cb8af4b/library/std/src/panicking.rs:225:9
  10:     0x7ffff7d06c5d - std::panicking::rust_panic_with_hook::h79a18548bd90c7d4
                               at /rustc/53cb7b09b00cbea8754ffb78e7e3cb521cb8af4b/library/std/src/panicking.rs:591:17
  11:     0x7ffff7d067c7 - std::panicking::begin_panic_handler::{{closure}}::h212a72cc08e25126
                               at /rustc/53cb7b09b00cbea8754ffb78e7e3cb521cb8af4b/library/std/src/panicking.rs:495:13
  12:     0x7ffff7d04b7c - std::sys_common::backtrace::__rust_end_short_backtrace::hbd6897dd42bc0fcd
                               at /rustc/53cb7b09b00cbea8754ffb78e7e3cb521cb8af4b/library/std/src/sys_common/backtrace.rs:141:18
  13:     0x7ffff7d06759 - rust_begin_unwind
                               at /rustc/53cb7b09b00cbea8754ffb78e7e3cb521cb8af4b/library/std/src/panicking.rs:493:5
  14:     0x7ffff7ac7ad1 - core::panicking::panic_fmt::h77ecd04e9b1dd84d
                               at /rustc/53cb7b09b00cbea8754ffb78e7e3cb521cb8af4b/library/core/src/panicking.rs:92:14
  15:     0x7ffff7ac7a1d - core::panicking::panic::h60569d8a39169222
                               at /rustc/53cb7b09b00cbea8754ffb78e7e3cb521cb8af4b/library/core/src/panicking.rs:50:5
  16:     0x7ffff7c5bbce - wasmer_engine::trap::frame_info::register::hfe9f67fb552d5b1a
  17:     0x7ffff7b2c645 - <wasmer_engine_universal::artifact::UniversalArtifact as wasmer_engine::artifact::Artifact>::register_frame_info::ha53475710931ffc3
  18:     0x7ffff7b25af6 - wasmer_engine::artifact::Artifact::instantiate::hd05b86e5ba918a5c
  19:     0x7ffff7b1c6a6 - wasmer::module::Module::instantiate::h45d4338a9791cf84
  20:     0x7ffff7b230a6 - wasmer::instance::Instance::new::h74d3fb4055786549
  21:     0x7ffff7ae51ac - cosmwasm_vm::instance::Instance<A,S,Q>::from_module::h240a598652e0970a
  22:     0x7ffff7ad1041 - cosmwasm_vm::cache::Cache<A,S,Q>::get_instance::h3b9e23b9ec33f458
  23:     0x7ffff7aeccfb - wasmvm::calls::do_call_2_args::h62a7af650e54a16e
  24:     0x7ffff7aec861 - wasmvm::calls::call_2_args::h6be8039159dbe364
  25:     0x7ffff7aebf9d - query
  26:          0x18757b4 - _cgo_02bf0df12a94_C2func_query
  27:           0x470450 - <unknown>

@webmaster128
Copy link
Contributor

I'm horribly unfamiliar with that code, but is it possible there is an off-by-one error in

    // First up assert that our chunk of jit functions doesn't collide with
    // any other known chunks of jit functions...
    if let Some((_, prev)) = info.ranges.range(max..).next() {
        assert!(prev.start > max);
    }

Looking at the code, max is the first pointer after all the finished_functions. After the loop, the range of "other known chunks of jit functions" is [min, max). So why can't "our chunk of jit functions" start at max?

@yun-yeo
Copy link
Contributor

yun-yeo commented Jan 3, 2022

I'm horribly unfamiliar with that code, but is it possible there is an off-by-one error in

    // First up assert that our chunk of jit functions doesn't collide with
    // any other known chunks of jit functions...
    if let Some((_, prev)) = info.ranges.range(max..).next() {
        assert!(prev.start > max);
    }

Looking at the code, max is the first pointer after all the finished_functions. After the loop, the range of "other known chunks of jit functions" is [min, max). So why can't "our chunk of jit functions" start at max?

let me make fork and do test with >= assertion condition.

@yun-yeo
Copy link
Contributor

yun-yeo commented Jan 3, 2022

^ unfortunately not helpful

@webmaster128
Copy link
Contributor

^ unfortunately not helpful

Can you output the values of prev.start and max as part of the assertion message?

@yun-yeo
Copy link
Contributor

yun-yeo commented Jan 5, 2022

^ unfortunately not helpful

Can you output the values of prev.start and max as part of the assertion message?

okay, I tried to reproduce this error but met other out of resource error like maximum thread exceed.
so requested to the reporter to get those output. so I will back with output.

@yun-yeo
Copy link
Contributor

yun-yeo commented Jan 5, 2022

here is result

tested on xeon E-2176G /64gb / ubuntu 20.04.3 machine

thread '<unnamed>' panicked at 'prev.start: 140730984521728,  max: 140730986624638', /usr/local/cargo/git/checkouts/wasmer-cd9d25bfe53061fa/cd0255e/lib/engine/src/trap/frame_info.rs:233:13
stack backtrace:
   0:     0x7ffff7cdaba0 - std::backtrace_rs::backtrace::libunwind::trace::ha5edb8ba5c6b7a6c
                               at /rustc/53cb7b09b00cbea8754ffb78e7e3cb521cb8af4b/library/std/src/../../backtrace/src/backtrace/libunwind.rs:90:5
   1:     0x7ffff7cdaba0 - std::backtrace_rs::backtrace::trace_unsynchronized::h0de86d320a827db2
                               at /rustc/53cb7b09b00cbea8754ffb78e7e3cb521cb8af4b/library/std/src/../../backtrace/src/backtrace/mod.rs:66:5
   2:     0x7ffff7cdaba0 - std::sys_common::backtrace::_print_fmt::h97b9ad6f0a1380ff
                               at /rustc/53cb7b09b00cbea8754ffb78e7e3cb521cb8af4b/library/std/src/sys_common/backtrace.rs:67:5
   3:     0x7ffff7cdaba0 - <std::sys_common::backtrace::_print::DisplayBacktrace as core::fmt::Display>::fmt::h14be7eb08f97fe80
                               at /rustc/53cb7b09b00cbea8754ffb78e7e3cb521cb8af4b/library/std/src/sys_common/backtrace.rs:46:22
   4:     0x7ffff7cfd04f - core::fmt::write::h2ca8877d3e0e52de
                               at /rustc/53cb7b09b00cbea8754ffb78e7e3cb521cb8af4b/library/core/src/fmt/mod.rs:1094:17
   5:     0x7ffff7cd8c95 - std::io::Write::write_fmt::h64f5987220b618f4
                               at /rustc/53cb7b09b00cbea8754ffb78e7e3cb521cb8af4b/library/std/src/io/mod.rs:1584:15
   6:     0x7ffff7cdcb0b - std::sys_common::backtrace::_print::h7f1a4097308f2e0a
                               at /rustc/53cb7b09b00cbea8754ffb78e7e3cb521cb8af4b/library/std/src/sys_common/backtrace.rs:49:5
   7:     0x7ffff7cdcb0b - std::sys_common::backtrace::print::h1f799fc2ca7f5035
                               at /rustc/53cb7b09b00cbea8754ffb78e7e3cb521cb8af4b/library/std/src/sys_common/backtrace.rs:36:9
   8:     0x7ffff7cdcb0b - std::panicking::default_hook::{{closure}}::hf38436e8a3ce1071
                               at /rustc/53cb7b09b00cbea8754ffb78e7e3cb521cb8af4b/library/std/src/panicking.rs:208:50
   9:     0x7ffff7cdc5dd - std::panicking::default_hook::he2f8f3fae11ed1dd
                               at /rustc/53cb7b09b00cbea8754ffb78e7e3cb521cb8af4b/library/std/src/panicking.rs:225:9
  10:     0x7ffff7cdd11d - std::panicking::rust_panic_with_hook::h79a18548bd90c7d4
                               at /rustc/53cb7b09b00cbea8754ffb78e7e3cb521cb8af4b/library/std/src/panicking.rs:591:17
  11:     0x7ffff7cdccb7 - std::panicking::begin_panic_handler::{{closure}}::h212a72cc08e25126
                               at /rustc/53cb7b09b00cbea8754ffb78e7e3cb521cb8af4b/library/std/src/panicking.rs:497:13
  12:     0x7ffff7cdb03c - std::sys_common::backtrace::__rust_end_short_backtrace::hbd6897dd42bc0fcd
                               at /rustc/53cb7b09b00cbea8754ffb78e7e3cb521cb8af4b/library/std/src/sys_common/backtrace.rs:141:18
  13:     0x7ffff7cdcc19 - rust_begin_unwind
                               at /rustc/53cb7b09b00cbea8754ffb78e7e3cb521cb8af4b/library/std/src/panicking.rs:493:5
  14:     0x7ffff79fc54b - std::panicking::begin_panic_fmt::hd15438ecd490aab7
                               at /rustc/53cb7b09b00cbea8754ffb78e7e3cb521cb8af4b/library/std/src/panicking.rs:435:5
  15:     0x7ffff7c32062 - wasmer_engine::trap::frame_info::register::ha62e850fd1ce68a6

@webmaster128
Copy link
Contributor

I just ran into this when executing cosmwasm_vm tests in the CI. This is the first time I see it without any blockchain code involved. The engine is Universal and Wasmer 2.1.1 is used. Seems like one test hits the assertion and all others are poisened after that.

start_max.txt

@yun-yeo
Copy link
Contributor

yun-yeo commented Feb 8, 2022

I can reproduce this error with updated test code of https://github.com/CosmWasm/cosmwasm/blob/be4d94a8d73ceab359226b8ea0a5b4be032a07e6/packages/vm/src/modules/in_memory_cache.rs#L123-L171

    use std::thread;
    use std::thread::JoinHandle;

    #[test]
    fn in_memory_cache_run() {
        let mut handles: Vec<JoinHandle<()>> = vec![];
        for _ in 1..10000 {
            let handle = thread::spawn(move || {
                let mut cache = InMemoryCache::new(Size::mebi(1));
                // Create module
                let wasm = wat::parse_str(
                    r#"(module
        (type $t0 (func (param i32) (result i32)))
        (func $add_one (export "add_one") (type $t0) (param $p0 i32) (result i32)
            get_local $p0
            i32.const 1
            i32.add)
        )"#,
                )
                .unwrap();
                let checksum = Checksum::generate(&wasm);
                // Module does not exist
                let cache_entry = cache.load(&checksum).unwrap();
                assert!(cache_entry.is_none());

                // Compile module
                let original = compile(&wasm, None).unwrap();

                // Store module
                let size = wasm.len() * TESTING_WASM_SIZE_FACTOR;
                cache.store(&checksum, original, size).unwrap();
                let cached = cache.load(&checksum).unwrap().unwrap();

                let instance = WasmerInstance::new(&cached.module, &imports! {}).unwrap();
                set_remaining_points(&instance, TESTING_GAS_LIMIT);
                let add_one = instance.exports.get_function("add_one").unwrap();
                let result = add_one.call(&[42.into()]).unwrap();
                assert_eq!(result[0].unwrap_i32(), 43);
            });

            handles.push(handle);
        }

        for handle in handles {
            handle.join().unwrap();
        }
    }

backtrace

thread '<unnamed>' panicked at 'assertion failed: prev.start > max', /Users/yeoyunseog/.cargo/registry/src/github.com-1ecc6299db9ec823/wasmer-engine-2.1.1/src/trap/frame_info.rs:233:9
stack backtrace:
   0:        0x107e141e4 - std::backtrace_rs::backtrace::libunwind::trace::h03e89bdd1996f493
                               at /rustc/a178d0322ce20e33eac124758e837cbd80a6f633/library/std/src/../../backtrace/src/backtrace/libunwind.rs:90:5
   1:        0x107e141e4 - std::backtrace_rs::backtrace::trace_unsynchronized::hb5af08e4de8ca785
                               at /rustc/a178d0322ce20e33eac124758e837cbd80a6f633/library/std/src/../../backtrace/src/backtrace/mod.rs:66:5
   2:        0x107e141e4 - std::sys_common::backtrace::_print_fmt::h4eafc628aec41041
                               at /rustc/a178d0322ce20e33eac124758e837cbd80a6f633/library/std/src/sys_common/backtrace.rs:67:5
   3:        0x107e141e4 - <std::sys_common::backtrace::_print::DisplayBacktrace as core::fmt::Display>::fmt::h6a8908fa3ed6f9e8
                               at /rustc/a178d0322ce20e33eac124758e837cbd80a6f633/library/std/src/sys_common/backtrace.rs:46:22
   4:        0x107e36f8c - core::fmt::write::h4be00f71c5582919
                               at /rustc/a178d0322ce20e33eac124758e837cbd80a6f633/library/core/src/fmt/mod.rs:1110:17
   5:        0x107e10afa - std::io::Write::write_fmt::h49e76926070788f1
                               at /rustc/a178d0322ce20e33eac124758e837cbd80a6f633/library/std/src/io/mod.rs:1588:15
   6:        0x107e164ef - std::sys_common::backtrace::_print::h2f7b8ad2bea4f859
                               at /rustc/a178d0322ce20e33eac124758e837cbd80a6f633/library/std/src/sys_common/backtrace.rs:49:5
   7:        0x107e164ef - std::sys_common::backtrace::print::h97402070cfceb1a3
                               at /rustc/a178d0322ce20e33eac124758e837cbd80a6f633/library/std/src/sys_common/backtrace.rs:36:9
   8:        0x107e164ef - std::panicking::default_hook::{{closure}}::h1577f0656e419c0e
                               at /rustc/a178d0322ce20e33eac124758e837cbd80a6f633/library/std/src/panicking.rs:208:50
   9:        0x107e15fed - std::panicking::default_hook::h1aef594179c4fd25
                               at /rustc/a178d0322ce20e33eac124758e837cbd80a6f633/library/std/src/panicking.rs:225:9
  10:        0x107e16bf0 - std::panicking::rust_panic_with_hook::h10bc487d002f6c42
                               at /rustc/a178d0322ce20e33eac124758e837cbd80a6f633/library/std/src/panicking.rs:622:17
  11:        0x107e16669 - std::panicking::begin_panic_handler::{{closure}}::hf4cfa78c105ce648
                               at /rustc/a178d0322ce20e33eac124758e837cbd80a6f633/library/std/src/panicking.rs:517:13
  12:        0x107e14658 - std::sys_common::backtrace::__rust_end_short_backtrace::h1df96a166e4351c4
                               at /rustc/a178d0322ce20e33eac124758e837cbd80a6f633/library/std/src/sys_common/backtrace.rs:141:18
  13:        0x107e165fa - rust_begin_unwind
                               at /rustc/a178d0322ce20e33eac124758e837cbd80a6f633/library/std/src/panicking.rs:515:5
  14:        0x107e6ef8f - core::panicking::panic_fmt::hea8fe6c9e0720810
                               at /rustc/a178d0322ce20e33eac124758e837cbd80a6f633/library/core/src/panicking.rs:92:14
  15:        0x107e6eee7 - core::panicking::panic::hbb13bbcfbaa2890b
                               at /rustc/a178d0322ce20e33eac124758e837cbd80a6f633/library/core/src/panicking.rs:50:5
  16:        0x107aabb4f - wasmer_engine::trap::frame_info::register::h6a6289a3871e5810
                               at /Users/yeoyunseog/.cargo/registry/src/github.com-1ecc6299db9ec823/wasmer-engine-2.1.1/src/trap/frame_info.rs:233:9
  17:        0x106fd738d - <wasmer_engine_universal::artifact::UniversalArtifact as wasmer_engine::artifact::Artifact>::register_frame_info::h80df081a6456a3b6
                               at /Users/yeoyunseog/.cargo/registry/src/github.com-1ecc6299db9ec823/wasmer-engine-universal-2.1.1/src/artifact.rs:301:17
  18:        0x106fc623c - wasmer_engine::artifact::Artifact::instantiate::haa0c14c648f4676d
                               at /Users/yeoyunseog/.cargo/registry/src/github.com-1ecc6299db9ec823/wasmer-engine-2.1.1/src/artifact.rs:151:9
  19:        0x106e9cca4 - wasmer::sys::module::Module::instantiate::hea4a9050c2eadd38
                               at /Users/yeoyunseog/.cargo/registry/src/github.com-1ecc6299db9ec823/wasmer-2.1.1/src/sys/module.rs:268:35
  20:        0x106e9ed39 - wasmer::sys::instance::Instance::new::h03889438a8b01660
                               at /Users/yeoyunseog/.cargo/registry/src/github.com-1ecc6299db9ec823/wasmer-2.1.1/src/sys/instance.rs:126:22
  21:        0x106b15434 - cosmwasm_vm::modules::in_memory_cache::tests::in_memory_cache_run::{{closure}}::hff8d689e9ae795cd
                               at /Users/yeoyunseog/Workspace/wasm/cosmwasm/packages/vm/src/modules/in_memory_cache.rs:155:32
thread 'modules::in_memory_cache::tests::in_memory_cache_run' panicked at 'failed to spawn thread: Os { code: 35, kind: WouldBlock, message: "Resource temporarily unavailable" }', /rustc/a178d0322ce20e33eac124758e837cbd80a6f633/library/std/src/thread/mod.rs:627:29
  22:        0x106b6bc6d - std::sys_common::backtrace::__rust_begin_short_backtrace::h5240543a23f61dc8
                               at /rustc/a178d0322ce20e33eac124758e837cbd80a6f633/library/std/src/sys_common/backtrace.rs:125:18
  23:        0x106c4b44d - std::thread::Builder::spawn_unchecked::{{closure}}::{{closure}}::h8bb2d2e8c419f21a
                               at /rustc/a178d0322ce20e33eac124758e837cbd80a6f633/library/std/src/thread/mod.rs:481:17
  24:        0x106b125ad - <std::panic::AssertUnwindSafe<F> as core::ops::function::FnOnce<()>>::call_once::h87ef2bec2d9eba55
                               at /rustc/a178d0322ce20e33eac124758e837cbd80a6f633/library/std/src/panic.rs:347:9
  25:        0x106b705fe - std::panicking::try::do_call::hbf2293fda12cdc35
                               at /rustc/a178d0322ce20e33eac124758e837cbd80a6f633/library/std/src/panicking.rs:401:40
  26:        0x106b7233b - ___rust_try
  27:        0x106b6dd93 - std::panicking::try::h849ab5f92d7b452c
                               at /rustc/a178d0322ce20e33eac124758e837cbd80a6f633/library/std/src/panicking.rs:365:19
  28:        0x106b12e8d - std::panic::catch_unwind::h5ab99904a01a99b9
                               at /rustc/a178d0322ce20e33eac124758e837cbd80a6f633/library/std/src/panic.rs:434:14
  29:        0x106c4b2c7 - std::thread::Builder::spawn_unchecked::{{closure}}::hdb07be370e3017d6
                               at /rustc/a178d0322ce20e33eac124758e837cbd80a6f633/library/std/src/thread/mod.rs:480:30
  30:        0x106b485a1 - core::ops::function::FnOnce::call_once{{vtable.shim}}::h1acdf727724e85bb
                               at /rustc/a178d0322ce20e33eac124758e837cbd80a6f633/library/core/src/ops/function.rs:227:5
  31:        0x107e1c10b - <alloc::boxed::Box<F,A> as core::ops::function::FnOnce<Args>>::call_once::hd1aaf96bb4a825cd
                               at /rustc/a178d0322ce20e33eac124758e837cbd80a6f633/library/alloc/src/boxed.rs:1575:9
  32:        0x107e1c10b - <alloc::boxed::Box<F,A> as core::ops::function::FnOnce<Args>>::call_once::h85328f151de296fc
                               at /rustc/a178d0322ce20e33eac124758e837cbd80a6f633/library/alloc/src/boxed.rs:1575:9
  33:        0x107e1c10b - std::sys::unix::thread::Thread::new::thread_start::h63f8b299c7b9d50c
                               at /rustc/a178d0322ce20e33eac124758e837cbd80a6f633/library/std/src/sys/unix/thread.rs:71:17
  34:     0x7fff204fd8fc - __pthread_start

@yun-yeo
Copy link
Contributor

yun-yeo commented Feb 8, 2022

other logs, when I change test to program main.rs

thread '<unnamed>' panicked at 'assertion failed: prev.start > max', /Users/yeoyunseog/.cargo/registry/src/github.com-1ecc6299db9ec823/wasmer-engine-2.1.1/src/trap/frame_info.rs:233:9
stack backtrace:
   0:        0x10ec99e94 - std::backtrace_rs::backtrace::libunwind::trace::h03e89bdd1996f493
                               at /rustc/a178d0322ce20e33eac124758e837cbd80a6f633/library/std/src/../../backtrace/src/backtrace/libunwind.rs:90:5
   1:        0x10ec99e94 - std::backtrace_rs::backtrace::trace_unsynchronized::hb5af08e4de8ca785
                               at /rustc/a178d0322ce20e33eac124758e837cbd80a6f633/library/std/src/../../backtrace/src/backtrace/mod.rs:66:5
   2:        0x10ec99e94 - std::sys_common::backtrace::_print_fmt::h4eafc628aec41041
                               at /rustc/a178d0322ce20e33eac124758e837cbd80a6f633/library/std/src/sys_common/backtrace.rs:67:5
   3:        0x10ec99e94 - <std::sys_common::backtrace::_print::DisplayBacktrace as core::fmt::Display>::fmt::h6a8908fa3ed6f9e8
                               at /rustc/a178d0322ce20e33eac124758e837cbd80a6f633/library/std/src/sys_common/backtrace.rs:46:22
   4:        0x10ecb856c - core::fmt::write::h4be00f71c5582919
                               at /rustc/a178d0322ce20e33eac124758e837cbd80a6f633/library/core/src/fmt/mod.rs:1110:17
   5:        0x10ec97a9a - std::io::Write::write_fmt::h49e76926070788f1
                               at /rustc/a178d0322ce20e33eac124758e837cbd80a6f633/library/std/src/io/mod.rs:1588:15
   6:        0x10ec9bc6f - std::sys_common::backtrace::_print::h2f7b8ad2bea4f859
                               at /rustc/a178d0322ce20e33eac124758e837cbd80a6f633/library/std/src/sys_common/backtrace.rs:49:5
   7:        0x10ec9bc6f - std::sys_common::backtrace::print::h97402070cfceb1a3
                               at /rustc/a178d0322ce20e33eac124758e837cbd80a6f633/library/std/src/sys_common/backtrace.rs:36:9
   8:        0x10ec9bc6f - std::panicking::default_hook::{{closure}}::h1577f0656e419c0e
                               at /rustc/a178d0322ce20e33eac124758e837cbd80a6f633/library/std/src/panicking.rs:208:50
   9:        0x10ec9b76d - std::panicking::default_hook::h1aef594179c4fd25
                               at /rustc/a178d0322ce20e33eac124758e837cbd80a6f633/library/std/src/panicking.rs:225:9
  10:        0x10ec9c370 - std::panicking::rust_panic_with_hook::h10bc487d002f6c42
                               at /rustc/a178d0322ce20e33eac124758e837cbd80a6f633/library/std/src/panicking.rs:622:17
  11:        0x10ec9bde9 - std::panicking::begin_panic_handler::{{closure}}::hf4cfa78c105ce648
                               at /rustc/a178d0322ce20e33eac124758e837cbd80a6f633/library/std/src/panicking.rs:517:13
  12:        0x10ec9a308 - std::sys_common::backtrace::__rust_end_short_backtrace::h1df96a166e4351c4
                               at /rustc/a178d0322ce20e33eac124758e837cbd80a6f633/library/std/src/sys_common/backtrace.rs:141:18
  13:        0x10ec9bd7a - rust_begin_unwind
                               at /rustc/a178d0322ce20e33eac124758e837cbd80a6f633/library/std/src/panicking.rs:515:5
  14:        0x10eccab0f - core::panicking::panic_fmt::hea8fe6c9e0720810
                               at /rustc/a178d0322ce20e33eac124758e837cbd80a6f633/library/core/src/panicking.rs:92:14
  15:        0x10eccaa67 - core::panicking::panic::hbb13bbcfbaa2890b
                               at /rustc/a178d0322ce20e33eac124758e837cbd80a6f633/library/core/src/panicking.rs:50:5
  16:        0x10ea8190f - wasmer_engine::trap::frame_info::register::h6a6289a3871e5810
                               at /Users/yeoyunseog/.cargo/registry/src/github.com-1ecc6299db9ec823/wasmer-engine-2.1.1/src/trap/frame_info.rs:233:9
  17:        0x10e7ba25d - <wasmer_engine_universal::artifact::UniversalArtifact as wasmer_engine::artifact::Artifact>::register_frame_info::h80df081a6456a3b6
                               at /Users/yeoyunseog/.cargo/registry/src/github.com-1ecc6299db9ec823/wasmer-engine-universal-2.1.1/src/artifact.rs:301:17
  18:        0x10e7a910c - wasmer_engine::artifact::Artifact::instantiate::haa0c14c648f4676d
                               at /Users/yeoyunseog/.cargo/registry/src/github.com-1ecc6299db9ec823/wasmer-engine-2.1.1/src/artifact.rs:151:9
  19:        0x10e6841e4 - wasmer::sys::module::Module::instantiate::hea4a9050c2eadd38
                               at /Users/yeoyunseog/.cargo/registry/src/github.com-1ecc6299db9ec823/wasmer-2.1.1/src/sys/module.rs:268:35
  20:        0x10e685e09 - wasmer::sys::instance::Instance::new::h03889438a8b01660
                               at /Users/yeoyunseog/.cargo/registry/src/github.com-1ecc6299db9ec823/wasmer-2.1.1/src/sys/instance.rs:126:22
  21:        0x10e4fda64 - cosmwasm_vm::modules::in_memory_cache::in_memory_program::{{closure}}::haa93f1bb60ba2e35
                               at /Users/yeoyunseog/Workspace/wasm/cosmwasm/packages/vm/src/modules/in_memory_cache.rs:129:28
  22:        0x10e506a4d - std::sys_common::backtrace::__rust_begin_short_backtrace::h6c7442133fae9d61
                               at /rustc/a178d0322ce20e33eac124758e837cbd80a6f633/library/std/src/sys_common/backtrace.rs:125:18
  23:        0x10e50782d - std::thread::Builder::spawn_unchecked::{{closure}}::{{closure}}::hcbfcabcdda4d1297
                               at /rustc/a178d0322ce20e33eac124758e837cbd80a6f633/library/std/src/thread/mod.rs:481:17
  24:        0x10e4ffddd - <std::panic::AssertUnwindSafe<F> as core::ops::function::FnOnce<()>>::call_once::hdfbf9eee4c0f13ea
                               at /rustc/a178d0322ce20e33eac124758e837cbd80a6f633/library/std/src/panic.rs:347:9
  25:        0x10e4f565e - std::panicking::try::do_call::h70b380804a4e6deb
                               at /rustc/a178d0322ce20e33eac124758e837cbd80a6f633/library/std/src/panicking.rs:401:40
  26:        0x10e4f572b - ___rust_try
  27:        0x10e4f55e3 - std::panicking::try::h585c52c27a01453a
                               at /rustc/a178d0322ce20e33eac124758e837cbd80a6f633/library/std/src/panicking.rs:365:19
  28:        0x10e4ffdfd - std::panic::catch_unwind::h9424542ae1d36f08
                               at /rustc/a178d0322ce20e33eac124758e837cbd80a6f633/library/std/src/panic.rs:434:14
  29:        0x10e5076a7 - std::thread::Builder::spawn_unchecked::{{closure}}::hcc6c713eb407a503
                               at /rustc/a178d0322ce20e33eac124758e837cbd80a6f633/library/std/src/thread/mod.rs:480:30
  30:        0x10e5151c1 - core::ops::function::FnOnce::call_once{{vtable.shim}}::h060fb3a0bd8713d3
                               at /rustc/a178d0322ce20e33eac124758e837cbd80a6f633/library/core/src/ops/function.rs:227:5
  31:        0x10ec9eecb - <alloc::boxed::Box<F,A> as core::ops::function::FnOnce<Args>>::call_once::hd1aaf96bb4a825cd
                               at /rustc/a178d0322ce20e33eac124758e837cbd80a6f633/library/alloc/src/boxed.rs:1575:9
  32:        0x10ec9eecb - <alloc::boxed::Box<F,A> as core::ops::function::FnOnce<Args>>::call_once::h85328f151de296fc
                               at /rustc/a178d0322ce20e33eac124758e837cbd80a6f633/library/alloc/src/boxed.rs:1575:9
  33:        0x10ec9eecb - std::sys::unix::thread::Thread::new::thread_start::h63f8b299c7b9d50c
                               at /rustc/a178d0322ce20e33eac124758e837cbd80a6f633/library/std/src/sys/unix/thread.rs:71:17
  34:     0x7fff204fd8fc - __pthread_start

@yun-yeo
Copy link
Contributor

yun-yeo commented Feb 8, 2022

I made new branch to let you easily reproduce error.

https://github.com/terra-money/cosmwasm/tree/bug/frame_info

cd packages/vm

# execute
RUST_BACKTRACE=full cargo run 2> output.txt

# test
RUST_BACKTRACE=1 cargo test -- --nocapture in_memory_cache_run 2> output.txt

both way will make same panic error

@Amanieu
Copy link
Contributor

Amanieu commented Feb 24, 2022

@YunSuk-Yeo Thanks for the reproducer, this was a huge help in tracking down this bug. I have a potential fix in #2806.

bors bot added a commit that referenced this issue Feb 25, 2022
2805: Enable `experimental-io-devices` by default r=Amanieu a=Amanieu

Fixes #2695

2806: Fix drop order for Module fields r=Amanieu a=Amanieu

The field ordering here is actually significant because of the drop
order: we want to drop the artifact before dropping the engine.

The reason for this is that dropping the Artifact will de-register the
trap handling metadata from the global registry. This must be done before
the code memory for the artifact is freed (which happens when the store
is dropped) since there is a chance that this memory could be reused by
another module which will try to register its own trap information.

Note that in Rust, the drop order for struct fields is from top to
bottom: the opposite of C++.

In the future, this code should be refactored to properly describe the
ownership of the code and its metadata.

Fixes #2434


Co-authored-by: Amanieu d'Antras <amanieu@gmail.com>
Co-authored-by: ptitSeb <sebastien.chev@gmail.com>
@bors bors bot closed this as completed in feaf483 Feb 25, 2022
Wasmer Runtime Issue Board automation moved this from 🏁 Ready to 🎉 Done Feb 25, 2022
yun-yeo pushed a commit to terra-money/wasmer that referenced this issue Feb 28, 2022
The field ordering here is actually significant because of the drop
order: we want to drop the artifact before dropping the engine.

The reason for this is that dropping the Artifact will de-register the
trap handling metadata from the global registry. This must be done before
the code memory for the artifact is freed (which happens when the store
is dropped) since there is a chance that this memory could be reused by
another module which will try to register its own trap information.

Note that in Rust, the drop order for struct fields is from top to
bottom: the opposite of C++.

In the future, this code should be refactored to properly describe the
ownership of the code and its metadata.

Fixes wasmerio#2434
@syrusakbary
Copy link
Member

Small update: we had a follow-up PR #2812 that was just merged into master, that solves the issue when running multiple instances in parallel. So this ticket should now be fully fixed.

Please let us know if this issue repeats in the future so we can reopen and re-investigate the issue

ptitSeb pushed a commit that referenced this issue Oct 20, 2022
The field ordering here is actually significant because of the drop
order: we want to drop the artifact before dropping the engine.

The reason for this is that dropping the Artifact will de-register the
trap handling metadata from the global registry. This must be done before
the code memory for the artifact is freed (which happens when the store
is dropped) since there is a chance that this memory could be reused by
another module which will try to register its own trap information.

Note that in Rust, the drop order for struct fields is from top to
bottom: the opposite of C++.

In the future, this code should be refactored to properly describe the
ownership of the code and its metadata.

Fixes #2434
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working 📦 lib-engine-dylib About wasmer-engine-dylib 🕵️ needs investigation The issue/PR needs further investigation priority-high High priority issue project-terra
Projects
Development

Successfully merging a pull request may close this issue.

8 participants