Stream: git-wasmtime

Topic: wasmtime / PR #2452 Provide filename/line number informat...

Wasmtime GitHub notifications bot (Nov 25 2020 at 21:18):

alexcrichton opened PR #2452 from wasm-dwarf to main:

This commit extends the Trap type and Store to retain DWARF debug
information found in a wasm file unconditionally, if it's present. This
then enables us to print filenames and line numbers which point back to
actual source code when a trap backtrace is printed. Additionally the
FrameInfo type has been souped up to return filename/line number
information as well.

The implementation here is pretty simplistic currently. The meat of all
the work happens in gimli and addr2line, and otherwise wasmtime is
just schlepping around bytes of dwarf debuginfo here and there!

The general goal here is to assist with debugging when using wasmtime
because filenames and line numbers are generally orders of magnitude
better even when you already have a stack trace. Another nicety here is
that backtraces will display inlined frames (learned through debug
information), improving the experience in release mode as well.

An example of this is that with this file:

fn main() {
    panic!("hello");
}

we get this stack trace:

$ rustc foo.rs --target wasm32-wasi -g
$ cargo run foo.wasm
    Finished dev [unoptimized + debuginfo] target(s) in 0.16s
     Running `target/debug/wasmtime foo.wasm`
thread 'main' panicked at 'hello', foo.rs:2:5
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace
Error: failed to run main module `foo.wasm`

Caused by:
    0: failed to invoke command default
    1: wasm trap: unreachable
       wasm backtrace:
           0: 0x6c1c - panic_abort::__rust_start_panic::abort::h2d60298621b1ccbf
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/panic_abort/src/lib.rs:77:17
                     - __rust_start_panic
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/panic_abort/src/lib.rs:32:5
           1: 0x68c7 - rust_panic
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/panicking.rs:626:9
           2: 0x65a1 - std::panicking::rust_panic_with_hook::h2345fb0909b53e12
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/panicking.rs:596:5
           3: 0x1436 - std::panicking::begin_panic::{{closure}}::h106f151a6db8c8fb
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/panicking.rs:506:9
           4:  0xda8 - std::sys_common::backtrace::__rust_end_short_backtrace::he55aa13f22782798
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/sys_common/backtrace.rs:153:18
           5: 0x1324 - std::panicking::begin_panic::h1727e7d1d719c76f
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/panicking.rs:505:12
           6:  0xfde - foo::main::h2db1313a64510850
                           at /Users/acrichton/code/wasmtime/foo.rs:2:5
           7: 0x11d5 - core::ops::function::FnOnce::call_once::h20ee1cc04aeff1fc
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/core/src/ops/function.rs:227:5
           8:  0xddf - std::sys_common::backtrace::__rust_begin_short_backtrace::h054493e41e27e69c
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/sys_common/backtrace.rs:137:18
           9: 0x1d5a - std::rt::lang_start::{{closure}}::hd83784448d3fcb42
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/rt.rs:66:18
          10: 0x69d8 - core::ops::function::impls::<impl core::ops::function::FnOnce<A> for &F>::call_once::h564d3dad35014917
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/core/src/ops/function.rs:259:13
                     - std::panicking::try::do_call::hdca4832ace5a8603
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/panicking.rs:381:40
                     - std::panicking::try::ha8624a1a6854b456
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/panicking.rs:345:19
                     - std::panic::catch_unwind::h71421f57cf2bc688
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/panic.rs:382:14
                     - std::rt::lang_start_internal::h260050c92cd470af
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/rt.rs:51:25
          11: 0x1d0c - std::rt::lang_start::h0b4bcf3c5e498224
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/rt.rs:65:5
          12:  0xffc - <unknown>!__original_main
          13:  0x393 - __muloti4
                           at /cargo/registry/src/github.com-1ecc6299db9ec823/compiler_builtins-0.1.35/src/macros.rs:269

This is relatively noisy by default but there's filenames and line
numbers! Additionally frame 10 can be seen to have lots of frames
inlined into it. All information is always available to the embedder but
we could try to handle the __rust_begin_short_backtrace and
__rust_end_short_backtrace markers to trim the backtrace by default as
well.

The only gotcha here is that it looks like __muloti4 is out of place.
That's because the libc that Rust ships with doesn't have dwarf
information, although I'm not sure why we land in that function for
symbolizing it...

Wasmtime GitHub notifications bot (Nov 25 2020 at 21:42):

fitzgen submitted PR Review.

Wasmtime GitHub notifications bot (Nov 30 2020 at 17:04):

alexcrichton updated PR #2452 from wasm-dwarf to main:

This commit extends the Trap type and Store to retain DWARF debug
information found in a wasm file unconditionally, if it's present. This
then enables us to print filenames and line numbers which point back to
actual source code when a trap backtrace is printed. Additionally the
FrameInfo type has been souped up to return filename/line number
information as well.

The implementation here is pretty simplistic currently. The meat of all
the work happens in gimli and addr2line, and otherwise wasmtime is
just schlepping around bytes of dwarf debuginfo here and there!

The general goal here is to assist with debugging when using wasmtime
because filenames and line numbers are generally orders of magnitude
better even when you already have a stack trace. Another nicety here is
that backtraces will display inlined frames (learned through debug
information), improving the experience in release mode as well.

An example of this is that with this file:

fn main() {
    panic!("hello");
}

we get this stack trace:

$ rustc foo.rs --target wasm32-wasi -g
$ cargo run foo.wasm
    Finished dev [unoptimized + debuginfo] target(s) in 0.16s
     Running `target/debug/wasmtime foo.wasm`
thread 'main' panicked at 'hello', foo.rs:2:5
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace
Error: failed to run main module `foo.wasm`

Caused by:
    0: failed to invoke command default
    1: wasm trap: unreachable
       wasm backtrace:
           0: 0x6c1c - panic_abort::__rust_start_panic::abort::h2d60298621b1ccbf
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/panic_abort/src/lib.rs:77:17
                     - __rust_start_panic
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/panic_abort/src/lib.rs:32:5
           1: 0x68c7 - rust_panic
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/panicking.rs:626:9
           2: 0x65a1 - std::panicking::rust_panic_with_hook::h2345fb0909b53e12
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/panicking.rs:596:5
           3: 0x1436 - std::panicking::begin_panic::{{closure}}::h106f151a6db8c8fb
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/panicking.rs:506:9
           4:  0xda8 - std::sys_common::backtrace::__rust_end_short_backtrace::he55aa13f22782798
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/sys_common/backtrace.rs:153:18
           5: 0x1324 - std::panicking::begin_panic::h1727e7d1d719c76f
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/panicking.rs:505:12
           6:  0xfde - foo::main::h2db1313a64510850
                           at /Users/acrichton/code/wasmtime/foo.rs:2:5
           7: 0x11d5 - core::ops::function::FnOnce::call_once::h20ee1cc04aeff1fc
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/core/src/ops/function.rs:227:5
           8:  0xddf - std::sys_common::backtrace::__rust_begin_short_backtrace::h054493e41e27e69c
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/sys_common/backtrace.rs:137:18
           9: 0x1d5a - std::rt::lang_start::{{closure}}::hd83784448d3fcb42
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/rt.rs:66:18
          10: 0x69d8 - core::ops::function::impls::<impl core::ops::function::FnOnce<A> for &F>::call_once::h564d3dad35014917
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/core/src/ops/function.rs:259:13
                     - std::panicking::try::do_call::hdca4832ace5a8603
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/panicking.rs:381:40
                     - std::panicking::try::ha8624a1a6854b456
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/panicking.rs:345:19
                     - std::panic::catch_unwind::h71421f57cf2bc688
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/panic.rs:382:14
                     - std::rt::lang_start_internal::h260050c92cd470af
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/rt.rs:51:25
          11: 0x1d0c - std::rt::lang_start::h0b4bcf3c5e498224
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/rt.rs:65:5
          12:  0xffc - <unknown>!__original_main
          13:  0x393 - __muloti4
                           at /cargo/registry/src/github.com-1ecc6299db9ec823/compiler_builtins-0.1.35/src/macros.rs:269

This is relatively noisy by default but there's filenames and line
numbers! Additionally frame 10 can be seen to have lots of frames
inlined into it. All information is always available to the embedder but
we could try to handle the __rust_begin_short_backtrace and
__rust_end_short_backtrace markers to trim the backtrace by default as
well.

The only gotcha here is that it looks like __muloti4 is out of place.
That's because the libc that Rust ships with doesn't have dwarf
information, although I'm not sure why we land in that function for
symbolizing it...

Wasmtime GitHub notifications bot (Nov 30 2020 at 17:16):

alexcrichton updated PR #2452 from wasm-dwarf to main:

This commit extends the Trap type and Store to retain DWARF debug
information found in a wasm file unconditionally, if it's present. This
then enables us to print filenames and line numbers which point back to
actual source code when a trap backtrace is printed. Additionally the
FrameInfo type has been souped up to return filename/line number
information as well.

The implementation here is pretty simplistic currently. The meat of all
the work happens in gimli and addr2line, and otherwise wasmtime is
just schlepping around bytes of dwarf debuginfo here and there!

The general goal here is to assist with debugging when using wasmtime
because filenames and line numbers are generally orders of magnitude
better even when you already have a stack trace. Another nicety here is
that backtraces will display inlined frames (learned through debug
information), improving the experience in release mode as well.

An example of this is that with this file:

fn main() {
    panic!("hello");
}

we get this stack trace:

$ rustc foo.rs --target wasm32-wasi -g
$ cargo run foo.wasm
    Finished dev [unoptimized + debuginfo] target(s) in 0.16s
     Running `target/debug/wasmtime foo.wasm`
thread 'main' panicked at 'hello', foo.rs:2:5
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace
Error: failed to run main module `foo.wasm`

Caused by:
    0: failed to invoke command default
    1: wasm trap: unreachable
       wasm backtrace:
           0: 0x6c1c - panic_abort::__rust_start_panic::abort::h2d60298621b1ccbf
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/panic_abort/src/lib.rs:77:17
                     - __rust_start_panic
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/panic_abort/src/lib.rs:32:5
           1: 0x68c7 - rust_panic
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/panicking.rs:626:9
           2: 0x65a1 - std::panicking::rust_panic_with_hook::h2345fb0909b53e12
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/panicking.rs:596:5
           3: 0x1436 - std::panicking::begin_panic::{{closure}}::h106f151a6db8c8fb
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/panicking.rs:506:9
           4:  0xda8 - std::sys_common::backtrace::__rust_end_short_backtrace::he55aa13f22782798
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/sys_common/backtrace.rs:153:18
           5: 0x1324 - std::panicking::begin_panic::h1727e7d1d719c76f
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/panicking.rs:505:12
           6:  0xfde - foo::main::h2db1313a64510850
                           at /Users/acrichton/code/wasmtime/foo.rs:2:5
           7: 0x11d5 - core::ops::function::FnOnce::call_once::h20ee1cc04aeff1fc
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/core/src/ops/function.rs:227:5
           8:  0xddf - std::sys_common::backtrace::__rust_begin_short_backtrace::h054493e41e27e69c
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/sys_common/backtrace.rs:137:18
           9: 0x1d5a - std::rt::lang_start::{{closure}}::hd83784448d3fcb42
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/rt.rs:66:18
          10: 0x69d8 - core::ops::function::impls::<impl core::ops::function::FnOnce<A> for &F>::call_once::h564d3dad35014917
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/core/src/ops/function.rs:259:13
                     - std::panicking::try::do_call::hdca4832ace5a8603
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/panicking.rs:381:40
                     - std::panicking::try::ha8624a1a6854b456
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/panicking.rs:345:19
                     - std::panic::catch_unwind::h71421f57cf2bc688
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/panic.rs:382:14
                     - std::rt::lang_start_internal::h260050c92cd470af
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/rt.rs:51:25
          11: 0x1d0c - std::rt::lang_start::h0b4bcf3c5e498224
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/rt.rs:65:5
          12:  0xffc - <unknown>!__original_main
          13:  0x393 - __muloti4
                           at /cargo/registry/src/github.com-1ecc6299db9ec823/compiler_builtins-0.1.35/src/macros.rs:269

This is relatively noisy by default but there's filenames and line
numbers! Additionally frame 10 can be seen to have lots of frames
inlined into it. All information is always available to the embedder but
we could try to handle the __rust_begin_short_backtrace and
__rust_end_short_backtrace markers to trim the backtrace by default as
well.

The only gotcha here is that it looks like __muloti4 is out of place.
That's because the libc that Rust ships with doesn't have dwarf
information, although I'm not sure why we land in that function for
symbolizing it...

Wasmtime GitHub notifications bot (Dec 01 2020 at 18:52):

alexcrichton updated PR #2452 from wasm-dwarf to main:

This commit extends the Trap type and Store to retain DWARF debug
information found in a wasm file unconditionally, if it's present. This
then enables us to print filenames and line numbers which point back to
actual source code when a trap backtrace is printed. Additionally the
FrameInfo type has been souped up to return filename/line number
information as well.

The implementation here is pretty simplistic currently. The meat of all
the work happens in gimli and addr2line, and otherwise wasmtime is
just schlepping around bytes of dwarf debuginfo here and there!

The general goal here is to assist with debugging when using wasmtime
because filenames and line numbers are generally orders of magnitude
better even when you already have a stack trace. Another nicety here is
that backtraces will display inlined frames (learned through debug
information), improving the experience in release mode as well.

An example of this is that with this file:

fn main() {
    panic!("hello");
}

we get this stack trace:

$ rustc foo.rs --target wasm32-wasi -g
$ cargo run foo.wasm
    Finished dev [unoptimized + debuginfo] target(s) in 0.16s
     Running `target/debug/wasmtime foo.wasm`
thread 'main' panicked at 'hello', foo.rs:2:5
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace
Error: failed to run main module `foo.wasm`

Caused by:
    0: failed to invoke command default
    1: wasm trap: unreachable
       wasm backtrace:
           0: 0x6c1c - panic_abort::__rust_start_panic::abort::h2d60298621b1ccbf
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/panic_abort/src/lib.rs:77:17
                     - __rust_start_panic
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/panic_abort/src/lib.rs:32:5
           1: 0x68c7 - rust_panic
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/panicking.rs:626:9
           2: 0x65a1 - std::panicking::rust_panic_with_hook::h2345fb0909b53e12
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/panicking.rs:596:5
           3: 0x1436 - std::panicking::begin_panic::{{closure}}::h106f151a6db8c8fb
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/panicking.rs:506:9
           4:  0xda8 - std::sys_common::backtrace::__rust_end_short_backtrace::he55aa13f22782798
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/sys_common/backtrace.rs:153:18
           5: 0x1324 - std::panicking::begin_panic::h1727e7d1d719c76f
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/panicking.rs:505:12
           6:  0xfde - foo::main::h2db1313a64510850
                           at /Users/acrichton/code/wasmtime/foo.rs:2:5
           7: 0x11d5 - core::ops::function::FnOnce::call_once::h20ee1cc04aeff1fc
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/core/src/ops/function.rs:227:5
           8:  0xddf - std::sys_common::backtrace::__rust_begin_short_backtrace::h054493e41e27e69c
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/sys_common/backtrace.rs:137:18
           9: 0x1d5a - std::rt::lang_start::{{closure}}::hd83784448d3fcb42
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/rt.rs:66:18
          10: 0x69d8 - core::ops::function::impls::<impl core::ops::function::FnOnce<A> for &F>::call_once::h564d3dad35014917
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/core/src/ops/function.rs:259:13
                     - std::panicking::try::do_call::hdca4832ace5a8603
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/panicking.rs:381:40
                     - std::panicking::try::ha8624a1a6854b456
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/panicking.rs:345:19
                     - std::panic::catch_unwind::h71421f57cf2bc688
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/panic.rs:382:14
                     - std::rt::lang_start_internal::h260050c92cd470af
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/rt.rs:51:25
          11: 0x1d0c - std::rt::lang_start::h0b4bcf3c5e498224
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/rt.rs:65:5
          12:  0xffc - <unknown>!__original_main
          13:  0x393 - __muloti4
                           at /cargo/registry/src/github.com-1ecc6299db9ec823/compiler_builtins-0.1.35/src/macros.rs:269

This is relatively noisy by default but there's filenames and line
numbers! Additionally frame 10 can be seen to have lots of frames
inlined into it. All information is always available to the embedder but
we could try to handle the __rust_begin_short_backtrace and
__rust_end_short_backtrace markers to trim the backtrace by default as
well.

The only gotcha here is that it looks like __muloti4 is out of place.
That's because the libc that Rust ships with doesn't have dwarf
information, although I'm not sure why we land in that function for
symbolizing it...

Wasmtime GitHub notifications bot (Dec 01 2020 at 19:34):

fitzgen submitted PR Review.

Wasmtime GitHub notifications bot (Dec 01 2020 at 19:34):

fitzgen submitted PR Review.

Wasmtime GitHub notifications bot (Dec 01 2020 at 19:34):

fitzgen created PR Review Comment:

Does the '_ here end up as the same lifetime that &self has? I know it would if the lifetime was completely elided, but I don't think I've ever actually seen '_ in a result type.

Wasmtime GitHub notifications bot (Dec 01 2020 at 19:34):

fitzgen created PR Review Comment:

Want to throw a cpp_demangle fallback in here too?

Wasmtime GitHub notifications bot (Dec 01 2020 at 19:36):

peterhuene submitted PR Review.

Wasmtime GitHub notifications bot (Dec 01 2020 at 19:36):

peterhuene created PR Review Comment:

:bike: shed nit: as this is a Wasmtime-specific environment variable, perhaps it should be WASMTIME_BACKTRACE_DETAILS?

Wasmtime GitHub notifications bot (Dec 01 2020 at 21:15):

alexcrichton created PR Review Comment:

It does yeah, it basically stands for "compiler fill something in here" and elision means that in method position with &self it's filled in with that lifetime.

Wasmtime GitHub notifications bot (Dec 01 2020 at 21:15):

alexcrichton submitted PR Review.

Wasmtime GitHub notifications bot (Dec 01 2020 at 21:15):

alexcrichton submitted PR Review.

Wasmtime GitHub notifications bot (Dec 01 2020 at 21:15):

alexcrichton created PR Review Comment:

Sure!

Wasmtime GitHub notifications bot (Dec 01 2020 at 21:20):

alexcrichton submitted PR Review.

Wasmtime GitHub notifications bot (Dec 01 2020 at 21:20):

alexcrichton created PR Review Comment:

Seems reasonable to me!

Wasmtime GitHub notifications bot (Dec 01 2020 at 21:21):

alexcrichton updated PR #2452 from wasm-dwarf to main:

This commit extends the Trap type and Store to retain DWARF debug
information found in a wasm file unconditionally, if it's present. This
then enables us to print filenames and line numbers which point back to
actual source code when a trap backtrace is printed. Additionally the
FrameInfo type has been souped up to return filename/line number
information as well.

The implementation here is pretty simplistic currently. The meat of all
the work happens in gimli and addr2line, and otherwise wasmtime is
just schlepping around bytes of dwarf debuginfo here and there!

The general goal here is to assist with debugging when using wasmtime
because filenames and line numbers are generally orders of magnitude
better even when you already have a stack trace. Another nicety here is
that backtraces will display inlined frames (learned through debug
information), improving the experience in release mode as well.

An example of this is that with this file:

fn main() {
    panic!("hello");
}

we get this stack trace:

$ rustc foo.rs --target wasm32-wasi -g
$ cargo run foo.wasm
    Finished dev [unoptimized + debuginfo] target(s) in 0.16s
     Running `target/debug/wasmtime foo.wasm`
thread 'main' panicked at 'hello', foo.rs:2:5
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace
Error: failed to run main module `foo.wasm`

Caused by:
    0: failed to invoke command default
    1: wasm trap: unreachable
       wasm backtrace:
           0: 0x6c1c - panic_abort::__rust_start_panic::abort::h2d60298621b1ccbf
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/panic_abort/src/lib.rs:77:17
                     - __rust_start_panic
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/panic_abort/src/lib.rs:32:5
           1: 0x68c7 - rust_panic
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/panicking.rs:626:9
           2: 0x65a1 - std::panicking::rust_panic_with_hook::h2345fb0909b53e12
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/panicking.rs:596:5
           3: 0x1436 - std::panicking::begin_panic::{{closure}}::h106f151a6db8c8fb
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/panicking.rs:506:9
           4:  0xda8 - std::sys_common::backtrace::__rust_end_short_backtrace::he55aa13f22782798
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/sys_common/backtrace.rs:153:18
           5: 0x1324 - std::panicking::begin_panic::h1727e7d1d719c76f
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/panicking.rs:505:12
           6:  0xfde - foo::main::h2db1313a64510850
                           at /Users/acrichton/code/wasmtime/foo.rs:2:5
           7: 0x11d5 - core::ops::function::FnOnce::call_once::h20ee1cc04aeff1fc
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/core/src/ops/function.rs:227:5
           8:  0xddf - std::sys_common::backtrace::__rust_begin_short_backtrace::h054493e41e27e69c
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/sys_common/backtrace.rs:137:18
           9: 0x1d5a - std::rt::lang_start::{{closure}}::hd83784448d3fcb42
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/rt.rs:66:18
          10: 0x69d8 - core::ops::function::impls::<impl core::ops::function::FnOnce<A> for &F>::call_once::h564d3dad35014917
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/core/src/ops/function.rs:259:13
                     - std::panicking::try::do_call::hdca4832ace5a8603
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/panicking.rs:381:40
                     - std::panicking::try::ha8624a1a6854b456
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/panicking.rs:345:19
                     - std::panic::catch_unwind::h71421f57cf2bc688
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/panic.rs:382:14
                     - std::rt::lang_start_internal::h260050c92cd470af
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/rt.rs:51:25
          11: 0x1d0c - std::rt::lang_start::h0b4bcf3c5e498224
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/rt.rs:65:5
          12:  0xffc - <unknown>!__original_main
          13:  0x393 - __muloti4
                           at /cargo/registry/src/github.com-1ecc6299db9ec823/compiler_builtins-0.1.35/src/macros.rs:269

This is relatively noisy by default but there's filenames and line
numbers! Additionally frame 10 can be seen to have lots of frames
inlined into it. All information is always available to the embedder but
we could try to handle the __rust_begin_short_backtrace and
__rust_end_short_backtrace markers to trim the backtrace by default as
well.

The only gotcha here is that it looks like __muloti4 is out of place.
That's because the libc that Rust ships with doesn't have dwarf
information, although I'm not sure why we land in that function for
symbolizing it...

Wasmtime GitHub notifications bot (Dec 01 2020 at 22:13):

alexcrichton updated PR #2452 from wasm-dwarf to main:

This commit extends the Trap type and Store to retain DWARF debug
information found in a wasm file unconditionally, if it's present. This
then enables us to print filenames and line numbers which point back to
actual source code when a trap backtrace is printed. Additionally the
FrameInfo type has been souped up to return filename/line number
information as well.

The implementation here is pretty simplistic currently. The meat of all
the work happens in gimli and addr2line, and otherwise wasmtime is
just schlepping around bytes of dwarf debuginfo here and there!

The general goal here is to assist with debugging when using wasmtime
because filenames and line numbers are generally orders of magnitude
better even when you already have a stack trace. Another nicety here is
that backtraces will display inlined frames (learned through debug
information), improving the experience in release mode as well.

An example of this is that with this file:

fn main() {
    panic!("hello");
}

we get this stack trace:

$ rustc foo.rs --target wasm32-wasi -g
$ cargo run foo.wasm
    Finished dev [unoptimized + debuginfo] target(s) in 0.16s
     Running `target/debug/wasmtime foo.wasm`
thread 'main' panicked at 'hello', foo.rs:2:5
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace
Error: failed to run main module `foo.wasm`

Caused by:
    0: failed to invoke command default
    1: wasm trap: unreachable
       wasm backtrace:
           0: 0x6c1c - panic_abort::__rust_start_panic::abort::h2d60298621b1ccbf
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/panic_abort/src/lib.rs:77:17
                     - __rust_start_panic
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/panic_abort/src/lib.rs:32:5
           1: 0x68c7 - rust_panic
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/panicking.rs:626:9
           2: 0x65a1 - std::panicking::rust_panic_with_hook::h2345fb0909b53e12
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/panicking.rs:596:5
           3: 0x1436 - std::panicking::begin_panic::{{closure}}::h106f151a6db8c8fb
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/panicking.rs:506:9
           4:  0xda8 - std::sys_common::backtrace::__rust_end_short_backtrace::he55aa13f22782798
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/sys_common/backtrace.rs:153:18
           5: 0x1324 - std::panicking::begin_panic::h1727e7d1d719c76f
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/panicking.rs:505:12
           6:  0xfde - foo::main::h2db1313a64510850
                           at /Users/acrichton/code/wasmtime/foo.rs:2:5
           7: 0x11d5 - core::ops::function::FnOnce::call_once::h20ee1cc04aeff1fc
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/core/src/ops/function.rs:227:5
           8:  0xddf - std::sys_common::backtrace::__rust_begin_short_backtrace::h054493e41e27e69c
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/sys_common/backtrace.rs:137:18
           9: 0x1d5a - std::rt::lang_start::{{closure}}::hd83784448d3fcb42
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/rt.rs:66:18
          10: 0x69d8 - core::ops::function::impls::<impl core::ops::function::FnOnce<A> for &F>::call_once::h564d3dad35014917
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/core/src/ops/function.rs:259:13
                     - std::panicking::try::do_call::hdca4832ace5a8603
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/panicking.rs:381:40
                     - std::panicking::try::ha8624a1a6854b456
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/panicking.rs:345:19
                     - std::panic::catch_unwind::h71421f57cf2bc688
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/panic.rs:382:14
                     - std::rt::lang_start_internal::h260050c92cd470af
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/rt.rs:51:25
          11: 0x1d0c - std::rt::lang_start::h0b4bcf3c5e498224
                           at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/rt.rs:65:5
          12:  0xffc - <unknown>!__original_main
          13:  0x393 - __muloti4
                           at /cargo/registry/src/github.com-1ecc6299db9ec823/compiler_builtins-0.1.35/src/macros.rs:269

This is relatively noisy by default but there's filenames and line
numbers! Additionally frame 10 can be seen to have lots of frames
inlined into it. All information is always available to the embedder but
we could try to handle the __rust_begin_short_backtrace and
__rust_end_short_backtrace markers to trim the backtrace by default as
well.

The only gotcha here is that it looks like __muloti4 is out of place.
That's because the libc that Rust ships with doesn't have dwarf
information, although I'm not sure why we land in that function for
symbolizing it...

Wasmtime GitHub notifications bot (Dec 01 2020 at 22:56):

alexcrichton merged PR #2452.

Last updated: Dec 23 2024 at 12:05 UTC