wasmtime icon indicating copy to clipboard operation
wasmtime copied to clipboard

Demangle symbol names in guest-profiler output

Open jameysharp opened this issue 8 months ago • 4 comments

Feature

The GuestProfiler, as invoked by its Rust API or with the Wasmtime CLI's --profile=guest flag, should try to demangle C++ and Rust function names before emitting them in the generated profile.

Benefit

It'd be nicer to see names like std::rt::lang_start::{{closure}}::ha2ad3bd729827662 than like _ZN3std2rt10lang_start28_$u7b$$u7b$closure$u7d$$u7d$17ha2ad3bd729827662E.llvm.16041094552022133104.

Implementation

There's existing code in Wasmtime for demangling names in stack traces, in crates/wasmtime/src/trap.rs. But that's bypassed by the low-level way that the guest profiler collects stack traces. Instead, the guest profiler gets all the function names up front, in the module_symbols function in crates/wasmtime/src/profiling.rs, and it should demangle the names there.

Alternatives

There might be support in the https://profiler.firefox.com/ frontend for demangling names.

jameysharp avatar Dec 08 '23 22:12 jameysharp

Hi @jameysharp, I'd like to pick this up.

high-cloud avatar Jan 19 '24 15:01 high-cloud

Awesome!

After I wrote this I've noticed that some people are already getting demangled names in guest-profiler output, which is confusing me. That makes me think that there may have been a Rust toolchain change to how symbol names are emitted in WebAssembly target builds. So it might not be necessary to do this if toolchain developers are doing it for us. But I haven't looked into that yet to find out if this is a trend or something.

So there are two ways you could help here:

  • One is to go ahead and implement the change I described. At worst, it's convenient when dealing with wasm modules built by older toolchains, even if new ones make it unnecessary.
  • The other is to look into what Rust, Clang, LLVM, etc are doing and see whether they're changing how they emit symbol names. It would be nice to know how important this change is for usability.

I'd appreciate your help with either or both of these things!

jameysharp avatar Jan 19 '24 17:01 jameysharp

Hi @jameysharp , I have finished the first thing you memtioned. Can you help review the pr?

high-cloud avatar Jan 24 '24 15:01 high-cloud

Hi,

I'm seeing an unexpected behaviour that seems related to this issue.

After upgrading from 14.0.3 to 15.0.0 I've noticed that wasm_trap_message, part of Wasmtime C API, returns the backtrace with mangled symbols:

error while executing at wasm backtrace:
    0: 0x2dbfa - <unknown>!__rust_start_panic
    1: 0x2d9e5 - <unknown>!rust_panic
    2: 0x2d918 - <unknown>!_ZN3std9panicking20rust_panic_with_hook17h9c783872fdb901ccE
    3: 0x13149 - <unknown>!_ZN3std9panicking11begin_panic28_$u7b$$u7b$closure$u7d$$u7d$17h4ffa6a1c8cae16aaE
    4: 0x1310c - <unknown>!_ZN3std10sys_common9backtrace26__rust_end_short_backtrace17ha3be793022377ab5E
    5: 0x13180 - <unknown>!_ZN3std9panicking11begin_panic17hc5e246abf4e1b013E
    6: 0xd47b - <unknown>!_ZN9hostcalls5types9test_http8TestHttp10exec_tests17he514b18df9efbbb3E
    7: 0xc7db - <unknown>!_ZN9hostcalls6filter99_$LT$impl$u20$proxy_wasm..traits..HttpContext$u20$for$u20$hostcalls..types..test_http..TestHttp$GT$23on_http_request_headers17h457bb152f4d611a0E
    8: 0x1f3d5 - <unknown>!_ZN10proxy_wasm10dispatcher10Dispatcher23on_http_request_headers17hcfdb13beb69bb128E
    9: 0x25775 - <unknown>!proxy_on_request_headers
note: using the `WASMTIME_BACKTRACE_DETAILS=1` environment variable may show more debugging information

Before the upgrade wasm_trap_message returned the stack trace like this:

error while executing at wasm backtrace:
    0: 0x2dbfa - <unknown>!__rust_start_panic
    1: 0x2d9e5 - <unknown>!rust_panic
    2: 0x2d918 - <unknown>!std::panicking::rust_panic_with_hook::h9c783872fdb901cc
    3: 0x13149 - <unknown>!std::panicking::begin_panic::{{closure}}::h4ffa6a1c8cae16aa
    4: 0x1310c - <unknown>!std::sys_common::backtrace::__rust_end_short_backtrace::ha3be793022377ab5
    5: 0x13180 - <unknown>!std::panicking::begin_panic::hc5e246abf4e1b013
    6: 0xd47b - <unknown>!hostcalls::types::test_http::TestHttp::exec_tests::he514b18df9efbbb3
    7: 0xc7db - <unknown>!hostcalls::filter::<impl proxy_wasm::traits::HttpContext for hostcalls::types::test_http::TestHttp>::on_http_request_headers::h457bb152f4d611a0
    8: 0x1f3d5 - <unknown>!proxy_wasm::dispatcher::Dispatcher::on_http_request_headers::hcfdb13beb69bb128
    9: 0x25775 - <unknown>!proxy_on_request_headers
note: using the `WASMTIME_BACKTRACE_DETAILS=1` environment variable may show more debugging information

Should I open a new issue for this case?

casimiro avatar Feb 19 '24 11:02 casimiro

@casimiro yes if you can open a new issue for that, that'd be appreciated! (this one's about the guest profiler not the C API).

That being said around that time we moved the demangling bits behind a Cargo feature and I suspect we forgot to turn that on for the C API, so I proposed https://github.com/bytecodealliance/wasmtime/pull/7962 to enable it by default again.

alexcrichton avatar Feb 20 '24 15:02 alexcrichton