wasmtime / issue #9716 Debugging example from the docs wi... · git-wasmtime

Stream: git-wasmtime

Topic: wasmtime / issue #9716 Debugging example from the docs wi...

Wasmtime GitHub notifications bot (Dec 03 2024 at 16:38):

bkolobara added the bug label to Issue #9716.

Wasmtime GitHub notifications bot (Dec 03 2024 at 16:38):

bkolobara opened issue #9716:

I'm trying to get the following example working inside of a debugger: https://docs.wasmtime.dev/examples-rust-debugging.html, but lldb can't read any of the local variables when a break point is triggered.

Test Case

The wasm file and executable are compiled directly from wasmtime examples.

> cargo build -p example-fib-debug-wasm --target wasm32-unknown-unknown
> cargo build --example fib-debug

Steps to Reproduce

Run the fib-debug executable inside lldb with the jit plugin enabled.

> lldb -- ./target/debug/examples/fib-debug
(lldb) target create "./target/debug/examples/fib-debug"
Current executable set to '/Users/bkolobara/dev/wasmtime/target/debug/examples/fib-debug' (arm64).
(lldb) settings set plugin.jit-loader.gdb.enable on
(lldb) b fib.rs:6
Breakpoint 1: no locations (pending).
WARNING:  Unable to resolve breakpoint to any actual locations.
(lldb) r
Process 87206 launched: '/Users/bkolobara/dev/wasmtime/target/debug/examples/fib-debug' (arm64)
1 location added to breakpoint 1
Process 87206 stopped

* thread #1, name = 'main', queue = 'com.apple.main-thread', stop reason = breakpoint 1.1
    frame #0: 0x00000001041381c4 JIT(0x1381c8000)`fib(n=<unavailable>) at fib.rs:6:17
   3        let mut a = 1;
   4        let mut b = 1;
   5        for _ in 0..n {
-> 6            let t = a;
   7            a = b;
   8            b += t;
   9        }
Target 0: (fib-debug) stopped.
warning: This version of LLDB has no plugin for the language "rust". Inspection of frame variables will be limited.
(lldb) fr v
(WasmtimeVMContext *) __vmctx = <variable not available>

(unsigned int) n = <read memory from 0xffff8 failed (0 of 4 bytes read)>

(unsigned int) a = <no location, value may have been optimized out>

(unsigned int) b = <no location, value may have been optimized out>

(core::ops::range::Range<unsigned int>) iter = <no location, value may have been optimized out>

Expected Results

Running fr v in lldb in this context should display the values of the variables:

(unsigned int) a = 1

(unsigned int) b = 1

Actual Results

(unsigned int) a = <no location, value may have been optimized out>

(unsigned int) b = <no location, value may have been optimized out>

Versions and Environment

Wasmtime version or commit: 27.0

Operating system: macOs Sequoia 15.1.1

Architecture: Apple M1 Pro

Extra Info

> lldb --version
lldb-1600.0.39.3
Apple Swift version 6.0.2 (swiftlang-6.0.2.1.2 clang-1600.0.26.4)

There was a similar issue #3884, but it was closed as fixed 2 years ago.

I'm also aware that there is some work being done on improving the debug info translation in #5537.

Wasmtime GitHub notifications bot (Dec 04 2024 at 15:34):

alexcrichton commented on issue #9716:

cc @SingleAccretion since you've been looking at the DWARF stuff recently would you happen to recognize this?

Wasmtime GitHub notifications bot (Dec 04 2024 at 15:47):

SingleAccretion commented on issue #9716:

would you happen to recognize this?

Hmm, not immediately, considering this is trivial code at -Oopt-level=0. What is the Rust->WASM optimization level here?

Generically, non-trivial examples do fall apart very easily because SSA+RA do not preserve everything, and Cranelift preservation of variable ranges is quite poor.

The way to self-diagnose this is to look at the DWARF produced for WASM, check if a and b in it have reasonable ranges, then in LLDB do:
(lldb) image lookup -n fib --verbose
And check the coverage of the ranges that will be dumped.

Wasmtime GitHub notifications bot (Dec 04 2024 at 15:48):

SingleAccretion edited a comment on issue #9716:

would you happen to recognize this?

Hmm, not immediately, considering this is trivial code at -Oopt-level=0. What is the Rust->WASM optimization level here?

Generically, non-trivial examples do fall apart very easily because SSA+RA do not preserve everything, and Cranelift preservation of variable ranges is quite poor.

The way to self-diagnose this is to look at the DWARF produced for WASM, check if a and b in it have reasonable ranges, then in LLDB do:
(lldb) image lookup -r -n fib --verbose
And check the coverage for ranges that will be dumped.

Wasmtime GitHub notifications bot (Dec 04 2024 at 15:54):

SingleAccretion edited a comment on issue #9716:

would you happen to recognize this?

Hmm, not immediately, considering this is trivial code at -Oopt-level=0. What is the Rust->WASM optimization level here?

Generically, non-trivial examples do fall apart very easily because SSA+RA do not preserve everything, and so Cranelift's preservation of variable ranges is quite poor.

The way to self-diagnose this is to look at the DWARF produced for WASM, check if a and b in it have reasonable ranges, then in LLDB do:
(lldb) image lookup -r -n fib --verbose
And check the coverage for ranges that will be dumped.

Wasmtime GitHub notifications bot (Dec 04 2024 at 21:02):

bkolobara commented on issue #9716:

What is the Rust->WASM optimization level here?

This uses a debug build of the fib.rs file, so opt-level = 0, with debug info included.

Wasmtime GitHub notifications bot (Mar 14 2025 at 19:31):

SingleAccretion commented on issue #9716:

Using the recently added logging, we see:

=== Begin DIE at 0x00000056 (depth = 4):
DW_TAG_variable
  DW_AT_location (<TODO: exprloc dump>)
  DW_AT_name ("a")
  DW_AT_decl_file (0x00000001)
  DW_AT_decl_line (3)
  DW_AT_type (0x000000a3)

Building ranges for values in scope: [72..214) [239..343)
L#0   : %rdx@[39..60) %r8@[60..100)
L#1   : %rbx@[39..42)
L#3   : %rbx@[42..215) %rbx@[240..324)
L#6   : %rcx@[89..100)
L#8   : %rdx@[91..100)
L#9   : %rdi@[109..133)
L#10  : %rax@[117..125)
L#12  : %rcx@[137..149)
L#13  : %r8@[158..184)
L#14  : %r9@[167..175)
L#15  : %r10@[193..198)
L#16  : %rax@[211..222)
L#18  : %rsi@[215..218)
L#19  : %rcx@[244..282)
L#20  : %rdx@[260..268)
L#21  : %r9@[277..286)
L#22  : %r8@[282..314)
L#23  : %r9@[293..297)
L#25  : %r9@[297..301)
L#26  : %rdx@[324..335)
VMCTX : %rdi@[39..80) %rsi@[80..100) %r15@[100..222) %r15@[240..335)
Intersecting with L#3
Intersecting with VMCTX
Built ranges:
[L#3:%rbx, VMCTX:%rdi]@[72..80)
[L#3:%rbx, VMCTX:%rsi]@[80..100)
[L#3:%rbx, VMCTX:%r15]@[100..214)
[VMCTX:%r15, L#3:%rbx]@[240..324)

In turn, in LLDB:

(lldb) v
(WasmtimeVMContext *) __vmctx = <variable not available>
(unsigned int) n = <variable not available>
(unsigned int) a = <variable not available>
(unsigned int) b = <variable not available>

(lldb) dis
JIT(0x1787ebc3040)`fib:
    0x1787e0a10d9 <+217>: mov    dword ptr [r15 + 0x70], esi
    0x1787e0a10dd <+221>: mov    rbx, qword ptr [rsp]
    0x1787e0a10e1 <+225>: mov    r15, qword ptr [rsp + 0x8]
    0x1787e0a10e6 <+230>: add    rsp, 0x10
    0x1787e0a10ea <+234>: mov    rsp, rbp
    0x1787e0a10ed <+237>: pop    rbp
    0x1787e0a10ee <+238>: ret
->  0x1787e0a10ef <+239>: mov    rcx, qword ptr [r15 + 0x50]
    0x1787e0a10f3 <+243>: mov    ecx, dword ptr [rcx + rbx + 0x10]
    0x1787e0a10f7 <+247>: mov    rdx, qword ptr [r15 + 0x50]
    0x1787e0a10fb <+251>: mov    dword ptr [rdx + rbx + 0x2c], ecx
    0x1787e0a10ff <+255>: mov    rdx, qword ptr [r15 + 0x50]
    0x1787e0a1103 <+259>: mov    edx, dword ptr [rdx + rbx + 0x14]
    0x1787e0a1107 <+263>: mov    r8, qword ptr [r15 + 0x50]
    0x1787e0a110b <+267>: mov    dword ptr [r8 + rbx + 0x10], edx
    0x1787e0a1110 <+272>: mov    r8, qword ptr [r15 + 0x50]

This is an interesting problem with how the cranelift liveness ranges are reported. Before doing so, the PCs for both start and end are adjusted forward by one (see here).

In this case, that means the position of +239 is erroneously reported as outside the live range of VMCTX (%r15@[240..335)), which in turn causes the unavailability of a.

Wasmtime GitHub notifications bot (Mar 16 2025 at 19:16):

SingleAccretion commented on issue #9716:

The reason these ranges are adjusted is because in emit we have "before PCs", while the RA (in regalloc.debug_locations) uses "after PC"s:
...][Inst][...
    |     |
    |     | PC after
    |
    | PC before
In other words, if we have the following instruction stream:
Inst0 0x00 ...
Inst1 0x04 mov rax, <...> ; L#1 = ...
Inst2 0x08 use rax ; last use
Inst3 0x12 ...
The RA will give us L#1: %rax@[Inst1, Inst2), equivalent to [0x08, 0x12), equivalent to [0x08], equivalent to [0x05, 0x09) (how emit renders it).

Considering this, the bug is due to how the RA-supplied range excludes <+239>: mov rcx, qword ptr [r15 + 0x50]. For the mov example above, it is correct to exclude PC: 0x04, since at that point rax isn't defined yet. In our case, r15 already has the right value.

Possible fixes:
1) Make the RA report ranges such as the one for r15, where the start is not a def, as [ret, ...) - advancing one instruction before.
2) Change how the RA ranges are defined to be in terms of "PC before", and exclude the defining instructions from those ranges.

I think in principle it would make for a "less surprising" contract to go with 2, but that may be too intrusive a change (I haven't yet checked what the situation is like on the "input" side of RA for this).

Separately, there should be a test verifying the start-adjust. If you just remove that +1 today, all of the tests pass.

Wasmtime GitHub notifications bot (Mar 16 2025 at 20:23):

SingleAccretion edited a comment on issue #9716:

The reason these ranges are adjusted is because in emit we have "before PCs", while the RA/CL (in debug_locations) uses "after PC"s:
...][Inst][...
    |     |
    |     | PC after
    |
    | PC before
In other words, if we have the following instruction stream:
Inst0 0x00 ...
Inst1 0x04 mov rax, <...> ; L#1 = ...
Inst2 0x08 use rax ; last use
Inst3 0x12 ...
RA/CL will give us L#1: %rax@[Inst1, Inst2), equivalent to [0x08, 0x12), equivalent to [0x08], equivalent to [0x05, 0x09) (how emit renders it).

Considering this, the bug is due to how the RA/CL-supplied range excludes <+239>: mov rcx, qword ptr [r15 + 0x50]. For the mov example above, it is correct to exclude PC: 0x04, since at that point rax isn't defined yet. In our case, r15 already has the right value.

Possible fixes:
1) Make RA/CL report ranges such as the one for r15, where the start is not a def, as [ret, ...) - advancing one instruction before.
2) Change how RA/CL ranges are defined to be in terms of "PC before", and exclude the defining instructions from those ranges.

In fact, there seems to be a good amount of confusion going on between the RA and CL. If you look at ranges are definitely RA-produces, they _exclude_ the def (are so are in effect using the "PC before" convention).

Separately, there should be a test verifying the start-adjust. If you just remove that +1 today, all of the tests pass.

Wasmtime GitHub notifications bot (Mar 16 2025 at 20:24):

SingleAccretion edited a comment on issue #9716:

The reason these ranges are adjusted is because in emit we have "before PCs", while the RA/CL (in debug_locations) uses "after PC"s:
...][Inst][...
    |     |
    |     | PC after
    |
    | PC before
In other words, if we have the following instruction stream:
Inst0 0x00 ...
Inst1 0x04 mov rax, <...> ; L#1 = ...
Inst2 0x08 use rax ; last use
Inst3 0x12 ...
RA/CL will give us L#1: %rax@[Inst1, Inst2), equivalent to [0x08, 0x12), equivalent to [0x08], equivalent to [0x05, 0x09) (how emit renders it).

Considering this, the bug is due to how the RA/CL-supplied range excludes <+239>: mov rcx, qword ptr [r15 + 0x50]. For the mov example above, it is correct to exclude PC: 0x04, since at that point rax isn't defined yet. In our case, r15 already has the right value.

Possible fixes:
1) Make RA/CL report ranges such as the one for r15, where the start is not a def, as [ret, ...) - advancing one instruction before.
2) Change how RA/CL ranges are defined to be in terms of "PC before", and exclude the defining instructions from those ranges.

In fact, there seems to be a good amount of confusion going on between the RA and CL. If you look at the ranges that are definitely RA-produces, they _exclude_ the def (are so are in effect using the "PC before" convention).

Separately, there should be a test verifying the start-adjust. If you just remove that +1 today, all of the tests pass.

Wasmtime GitHub notifications bot (Mar 16 2025 at 20:24):

SingleAccretion edited a comment on issue #9716:

The reason these ranges are adjusted is because in emit we have "before PCs", while the RA/CL (in debug_locations) uses "after PC"s:
...][Inst][...
    |     |
    |     | PC after
    |
    | PC before
In other words, if we have the following instruction stream:
Inst0 0x00 ...
Inst1 0x04 mov rax, <...> ; L#1 = ...
Inst2 0x08 use rax ; last use
Inst3 0x12 ...
RA/CL will give us L#1: %rax@[Inst1, Inst2), equivalent to [0x08, 0x12), equivalent to [0x08], equivalent to [0x05, 0x09) (how emit renders it).

Considering this, the bug is due to how the RA/CL-supplied range excludes <+239>: mov rcx, qword ptr [r15 + 0x50]. For the mov example above, it is correct to exclude PC: 0x04, since at that point rax isn't defined yet. In our case, r15 already has the right value.

In fact, there seems to be a good amount of confusion going on between the RA and CL. If you look at the ranges that are definitely RA-produces, they _exclude_ the def (are so are in effect using the "PC before" convention).

Separately, there should be a test verifying the start-adjust. If you just remove that +1 today, all of the tests pass.

Wasmtime GitHub notifications bot (Mar 16 2025 at 20:25):

SingleAccretion edited a comment on issue #9716:

The reason these ranges are adjusted is because in emit we have "before PCs", while the RA/CL (in debug_locations) uses "after PC"s:
...][Inst][...
    |     |
    |     | PC after
    |
    | PC before
In other words, if we have the following instruction stream:
Inst0 0x00 ...
Inst1 0x04 mov rax, <...> ; L#1 = ...
Inst2 0x08 use rax ; last use
Inst3 0x12 ...
RA/CL will give us L#1: %rax@[Inst1, Inst2), equivalent to [0x08, 0x12), equivalent to [0x08], equivalent to [0x05, 0x09) (how emit renders it).

Considering this, the bug is due to how the RA/CL-supplied range excludes <+239>: mov rcx, qword ptr [r15 + 0x50]. For the mov example above, it is correct to exclude PC: 0x04, since at that point rax isn't defined yet. In our case, r15 already has the right value.

In fact, there seems to be a good amount of confusion going on between the RA and CL. If you look at the ranges that are definitely RA-produced, they _exclude_ the def (are so are in effect using the "PC before" convention).

Separately, there should be a test verifying the start-adjust. If you just remove that +1 today, all of the tests pass.

Wasmtime GitHub notifications bot (Mar 19 2025 at 21:02):

SingleAccretion edited a comment on issue #9716:

The reason these ranges are adjusted is because in emit we have "before PCs", while the RA/CL (in debug_locations) uses "after PC"s:
...][Inst][...
    |     |
    |     | PC after
    |
    | PC before
In other words, if we have the following instruction stream:
Inst0 0x00 ...
Inst1 0x04 mov rax, <...> ; L#1 = ...
Inst2 0x08 use rax ; last use
Inst3 0x12 ...
RA/CL will give us L#1: %rax@[Inst1, Inst2), equivalent to [0x08, 0x12), equivalent to [0x08], equivalent to [0x05, 0x09) (how emit renders it).

Considering this, the bug is due to how the RA/CL-supplied range excludes <+239>: mov rcx, qword ptr [r15 + 0x50]. For the mov example above, it is correct to exclude PC: 0x04, since at that point rax isn't defined yet. In our case, r15 already has the right value.

In fact, there seems to be a good amount of confusion going on between the RA and CL. If you look at the ranges that are definitely RA-produced, they _exclude_ the def (are so are in effect using the "PC before" convention).

Separately, there should be a test verifying the start-adjust. If you just remove that +1 today, all of the tests pass.

Another edit follows...

I am becoming more and more convinced that the way value label ranges are tracked during emission (bound to the def, producing [def...)) is just not the right way to do this, they should be bound to the next instruction instead. It should be an easy enough change to make.

Wasmtime GitHub notifications bot (Mar 20 2025 at 19:31):

SingleAccretion edited a comment on issue #9716:

The reason these ranges are adjusted is because in emit we have "before PCs", while the RA/CL (in debug_locations) uses "after PC"s:
...][Inst][...
    |     |
    |     | PC after
    |
    | PC before
In other words, if we have the following instruction stream:
Inst0 0x00 ...
Inst1 0x04 mov rax, <...> ; L#1 = ...
Inst2 0x08 use rax ; last use
Inst3 0x12 ...
RA/CL will give us L#1: %rax@[Inst1, Inst2), equivalent to [0x08, 0x12), equivalent to [0x08], equivalent to [0x05, 0x09) (how emit renders it).

Considering this, the bug is due to how the RA/CL-supplied range excludes <+239>: mov rcx, qword ptr [r15 + 0x50]. For the mov example above, it is correct to exclude PC: 0x04, since at that point rax isn't defined yet. In our case, r15 already has the right value.

In fact, there seems to be a good amount of confusion going on between the RA and CL. If you look at the ranges that are definitely RA-produced, they _exclude_ the def (are so are in effect using the "PC before" convention).

Separately, there should be a test verifying the start-adjust. If you just remove that +1 today, all of the tests pass.

Wasmtime GitHub notifications bot (Apr 15 2025 at 20:36):

alexcrichton closed issue #9716:

Test Case

The wasm file and executable are compiled directly from wasmtime examples.

> cargo build -p example-fib-debug-wasm --target wasm32-unknown-unknown
> cargo build --example fib-debug

Steps to Reproduce

Run the fib-debug executable inside lldb with the jit plugin enabled.

> lldb -- ./target/debug/examples/fib-debug
(lldb) target create "./target/debug/examples/fib-debug"
Current executable set to '/Users/bkolobara/dev/wasmtime/target/debug/examples/fib-debug' (arm64).
(lldb) settings set plugin.jit-loader.gdb.enable on
(lldb) b fib.rs:6
Breakpoint 1: no locations (pending).
WARNING:  Unable to resolve breakpoint to any actual locations.
(lldb) r
Process 87206 launched: '/Users/bkolobara/dev/wasmtime/target/debug/examples/fib-debug' (arm64)
1 location added to breakpoint 1
Process 87206 stopped

* thread #1, name = 'main', queue = 'com.apple.main-thread', stop reason = breakpoint 1.1
    frame #0: 0x00000001041381c4 JIT(0x1381c8000)`fib(n=<unavailable>) at fib.rs:6:17
   3        let mut a = 1;
   4        let mut b = 1;
   5        for _ in 0..n {
-> 6            let t = a;
   7            a = b;
   8            b += t;
   9        }
Target 0: (fib-debug) stopped.
warning: This version of LLDB has no plugin for the language "rust". Inspection of frame variables will be limited.
(lldb) fr v
(WasmtimeVMContext *) __vmctx = <variable not available>

(unsigned int) n = <read memory from 0xffff8 failed (0 of 4 bytes read)>

(unsigned int) a = <no location, value may have been optimized out>

(unsigned int) b = <no location, value may have been optimized out>

(core::ops::range::Range<unsigned int>) iter = <no location, value may have been optimized out>

Expected Results

Running fr v in lldb in this context should display the values of the variables:

(unsigned int) a = 1

(unsigned int) b = 1

Actual Results

(unsigned int) a = <no location, value may have been optimized out>

(unsigned int) b = <no location, value may have been optimized out>

Versions and Environment

Wasmtime version or commit: 27.0

Operating system: macOs Sequoia 15.1.1

Architecture: Apple M1 Pro

Extra Info

> lldb --version
lldb-1600.0.39.3
Apple Swift version 6.0.2 (swiftlang-6.0.2.1.2 clang-1600.0.26.4)

There was a similar issue #3884, but it was closed as fixed 2 years ago.

I'm also aware that there is some work being done on improving the debug info translation in #5537.

Last updated: Apr 16 2025 at 19:03 UTC