Stream: git-wasmtime

Topic: wasmtime / issue #7418 wasmtime panic when using log-to-f...

Wasmtime GitHub notifications bot (Oct 31 2023 at 09:51):

cimacmillan added the bug label to Issue #7418.

Wasmtime GitHub notifications bot (Oct 31 2023 at 09:51):

cimacmillan opened issue #7418:

Thanks for filing a bug report! Please fill out the TODOs below.

Note: if you want to report a security issue, please read our security policy!

Test Case

Attached reproducing.zip which contains the WASM file, when ran with WASM time with log-to-files, causes panic

Steps to Reproduce

• Download the reproducing.zip and decompress
• Run RUST_LOG=wasi_common=trace wasmtime --wasm threads --wasi threads -D log-to-files reproducing.wasm

Expected Results

Program should run (although shouldn't exit, due to another issue see).

Actual Results

thread 'wasi-thread-949396201' panicked at 'call the logger's initialize() function first', /home/runner/work/wasmtime/wasmtime/vendor/file-per-thread-logger/src/lib.rs:164:22
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace
wasi-thread-949396201 panicked: Any { .. }

With backtrace,

thread 'wasi-thread-1053380974' panicked at 'call the logger's initialize() function first', /home/runner/work/wasmtime/wasmtime/vendor/file-per-thread-logger/src/lib.rs:164:22
stack backtrace:
   0: rust_begin_unwind
             at /rustc/5680fa18feaa87f3ff04063800aec256c3d4b4be/library/std/src/panicking.rs:593:5
   1: core::panicking::panic_fmt
             at /rustc/5680fa18feaa87f3ff04063800aec256c3d4b4be/library/core/src/panicking.rs:67:14
   2: core::panicking::panic_display
             at /rustc/5680fa18feaa87f3ff04063800aec256c3d4b4be/library/core/src/panicking.rs:150:5
   3: core::panicking::panic_str
             at /rustc/5680fa18feaa87f3ff04063800aec256c3d4b4be/library/core/src/panicking.rs:134:5
   4: core::option::expect_failed
             at /rustc/5680fa18feaa87f3ff04063800aec256c3d4b4be/library/core/src/option.rs:1952:5
   5: <file_per_thread_logger::FilePerThreadLogger as log::Log>::log
   6: tracing::span::Span::log
   7: tracing::span::Span::record_all
   8: wasi_common::snapshots::preview_1::wasi_snapshot_preview1::sched_yield
   9: wiggle::run_in_dummy_executor
  10: <core::panic::unwind_safe::AssertUnwindSafe<F> as core::ops::function::FnOnce<()>>::call_once
  11: wasmtime_runtime::instance::Instance::from_vmctx
  12: <F as wasmtime::func::IntoFunc<T,(wasmtime::func::Caller<T>,),R>>::into_func::native_call_shim
  13: <unknown>
  14: <unknown>
  15: <unknown>
  16: <unknown>
  17: <unknown>
  18: <unknown>
  19: <unknown>
  20: <unknown>
  21: <unknown>
  22: <unknown>
  23: <unknown>
  24: <unknown>
  25: <unknown>
  26: <unknown>
  27: <unknown>
  28: <unknown>
  29: <unknown>
  30: <unknown>
  31: <unknown>
  32: <unknown>
  33: <unknown>
  34: <unknown>
  35: <unknown>
  36: <unknown>
  37: <unknown>
  38: wasmtime_runtime::traphandlers::catch_traps::call_closure
  39: wasmtime_setjmp_14_0_2
  40: wasmtime_runtime::traphandlers::<impl wasmtime_runtime::traphandlers::call_thread_state::CallThreadState>::with
  41: wasmtime::func::typed::TypedFunc<Params,Results>::call
  42: <core::panic::unwind_safe::AssertUnwindSafe<F> as core::ops::function::FnOnce<()>>::call_once
note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.
wasi-thread-1053380974 panicked: Any { .. }

Versions and Environment

Wasmtime version or commit: Reproduced on 1d46c2d589d97cd5a13c17c88c8d288f643bdaff, and current release

Operating system: Ubuntu 22

Architecture: x86-64

Extra Info

Anything else you'd like to add?

The backtrace is showing wasi_common::snapshots::preview_1::wasi_snapshot_preview1::sched_yield which could be related to the bug in wasi-threads I am investigating, which is likely an issue in rust std library as it can be reproduced in both wasmtime and wamr. However, I don't think it should result in a crash in wasmtime either way, so thought to open this report.

reproducing.zip

Wasmtime GitHub notifications bot (Oct 31 2023 at 17:16):

fitzgen closed issue #7418:

Thanks for filing a bug report! Please fill out the TODOs below.

Note: if you want to report a security issue, please read our security policy!

Test Case

Attached reproducing.zip which contains the WASM file, when ran with WASM time with log-to-files, causes panic

Steps to Reproduce

• Download the reproducing.zip and decompress
• Run RUST_LOG=wasi_common=trace wasmtime --wasm threads --wasi threads -D log-to-files reproducing.wasm

Expected Results

Program should run (although shouldn't exit, due to another issue see).

Actual Results

thread 'wasi-thread-949396201' panicked at 'call the logger's initialize() function first', /home/runner/work/wasmtime/wasmtime/vendor/file-per-thread-logger/src/lib.rs:164:22
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace
wasi-thread-949396201 panicked: Any { .. }

With backtrace,

thread 'wasi-thread-1053380974' panicked at 'call the logger's initialize() function first', /home/runner/work/wasmtime/wasmtime/vendor/file-per-thread-logger/src/lib.rs:164:22
stack backtrace:
   0: rust_begin_unwind
             at /rustc/5680fa18feaa87f3ff04063800aec256c3d4b4be/library/std/src/panicking.rs:593:5
   1: core::panicking::panic_fmt
             at /rustc/5680fa18feaa87f3ff04063800aec256c3d4b4be/library/core/src/panicking.rs:67:14
   2: core::panicking::panic_display
             at /rustc/5680fa18feaa87f3ff04063800aec256c3d4b4be/library/core/src/panicking.rs:150:5
   3: core::panicking::panic_str
             at /rustc/5680fa18feaa87f3ff04063800aec256c3d4b4be/library/core/src/panicking.rs:134:5
   4: core::option::expect_failed
             at /rustc/5680fa18feaa87f3ff04063800aec256c3d4b4be/library/core/src/option.rs:1952:5
   5: <file_per_thread_logger::FilePerThreadLogger as log::Log>::log
   6: tracing::span::Span::log
   7: tracing::span::Span::record_all
   8: wasi_common::snapshots::preview_1::wasi_snapshot_preview1::sched_yield
   9: wiggle::run_in_dummy_executor
  10: <core::panic::unwind_safe::AssertUnwindSafe<F> as core::ops::function::FnOnce<()>>::call_once
  11: wasmtime_runtime::instance::Instance::from_vmctx
  12: <F as wasmtime::func::IntoFunc<T,(wasmtime::func::Caller<T>,),R>>::into_func::native_call_shim
  13: <unknown>
  14: <unknown>
  15: <unknown>
  16: <unknown>
  17: <unknown>
  18: <unknown>
  19: <unknown>
  20: <unknown>
  21: <unknown>
  22: <unknown>
  23: <unknown>
  24: <unknown>
  25: <unknown>
  26: <unknown>
  27: <unknown>
  28: <unknown>
  29: <unknown>
  30: <unknown>
  31: <unknown>
  32: <unknown>
  33: <unknown>
  34: <unknown>
  35: <unknown>
  36: <unknown>
  37: <unknown>
  38: wasmtime_runtime::traphandlers::catch_traps::call_closure
  39: wasmtime_setjmp_14_0_2
  40: wasmtime_runtime::traphandlers::<impl wasmtime_runtime::traphandlers::call_thread_state::CallThreadState>::with
  41: wasmtime::func::typed::TypedFunc<Params,Results>::call
  42: <core::panic::unwind_safe::AssertUnwindSafe<F> as core::ops::function::FnOnce<()>>::call_once
note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.
wasi-thread-1053380974 panicked: Any { .. }

Versions and Environment

Wasmtime version or commit: Reproduced on 1d46c2d589d97cd5a13c17c88c8d288f643bdaff, and current release

Operating system: Ubuntu 22

Architecture: x86-64

Extra Info

Anything else you'd like to add?

The backtrace is showing wasi_common::snapshots::preview_1::wasi_snapshot_preview1::sched_yield which could be related to the bug in wasi-threads I am investigating, which is likely an issue in rust std library as it can be reproduced in both wasmtime and wamr. However, I don't think it should result in a crash in wasmtime either way, so thought to open this report.

reproducing.zip

Last updated: Oct 23 2024 at 20:03 UTC