Skip to content

Incorrect line table generation for await points #123341

Closed
@Sandlot19

Description

@Sandlot19

I’m a developer for the Fuchsia Debugger (zxdb), and noticed an issue with setting a breakpoint on a line of rust code containing an await. In particular, this issue was filed: Breakpoint set on await line does not stop. There are additional details in that bug report with my investigation, and the workaround for zxdb will be similar to what LLDB does.

While debugging some async code, I noticed that a breakpoint I set on a particular line number wasn’t being hit. It turned out that the line table for the async function call site looked incorrect. Namely, the line table entry for a line containing an await generated an is_stmt on a ud2 instruction, which is never actually executed. The typical algorithm debuggers use for placing breakpoints uses the lowest address for the function that is marked is_stmt in the line table, which in this case is incorrect, since the first code either isn’t associated with the callsite, or shouldn’t be marked is_stmt.

This code is a minimal reproducer:

async fn process_int(i: u32) -> u32 {
    tokio::time::sleep(tokio::time::Duration::from_secs(2)).await;
    i+1
}

#[tokio::main(flavor = "current_thread")]
async fn main() -> Result<(), Box<dyn Error + Send + Sync>>{
    println!("Hello world!");

    let i = process_int(15).await; // Set a breakpoint on this line.

    println!("{}", i);
    Ok(())
}

Here is the relevant section of the line table, the above source is located in file index 3 in the fourth column, and the line indicated above is 18 in the second column (llvm-dwarfdump-15 --debug-line):

0x000000000001f219     18     29      3   0             0  is_stmt // <-- This address is a ud2 instruction, but is marked as valid
0x000000000001f21b      0     29      3   0             0 
0x000000000001f220     14      1      3   0             0  is_stmt
0x000000000001f228     16      5      3   0             0  is_stmt
0x000000000001f240     14      1      3   0             0  is_stmt
0x000000000001f256      0      1      3   0             0 
0x000000000001f25b     18     29      3   0             0  is_stmt // <-- This is the most reasonable address to choose for the breakpoint in the line table.
0x000000000001f268     14      1      3   0             0  is_stmt
0x000000000001f281      0      1      3   0             0 
0x000000000001f297     16      5      3   0             0  is_stmt
0x000000000001f2a7      0      5      3   0             0 
0x000000000001f2b4     18     13      3   0             0  is_stmt
0x000000000001f2bb      0     13      3   0             0 
0x000000000001f2cb     18     29      3   0             0 
0x000000000001f2d2     18     13      3   0             0 
0x000000000001f2e9     18     29      3   0             0

LLDB sets a breakpoint in several locations:

(lldb) b main.rs:18
Breakpoint 1: 3 locations.
(lldb) r
Hello world!
Process 1338689 stopped
* thread #1, name = 'tokio-test', stop reason = breakpoint 1.2
    frame #0: 0x00005555555732b4 tokio-test`tokio_test::main::_$u7b$$u7b$closure$u7d$$u7d$::hbcd05a4ce5f705a7((null)=0x00007fffffffcb60) at main.rs:18:13
   15  	async fn main() -> Result<(), Box<dyn Error + Send + Sync>>{
   16  	   println!("Hello world!");
   17  	
-> 18  	   let i = process_int(15).await;
   19  	
   20  	   println!("{}", i);
   21  	   Ok(())
(lldb) breakpoint list
Current breakpoints:
1: file = 'main.rs', line = 18, exact_match = 0, locations = 3, resolved = 3, hit count = 1
  1.1: where = tokio-test`tokio_test::main::_$u7b$$u7b$closure$u7d$$u7d$::hbcd05a4ce5f705a7 + 73 at main.rs:18:29, address = 0x0000555555573219, resolved, hit count = 0   <-- Location on ud2, which is required by the debugger algorithm.
  1.2: where = tokio-test`tokio_test::main::_$u7b$$u7b$closure$u7d$$u7d$::hbcd05a4ce5f705a7 + 228 at main.rs:18:13, address = 0x00005555555732b4, resolved, hit count = 1   <-- Location that gets hit first.
  1.3: where = tokio-test`tokio_test::main::_$u7b$$u7b$closure$u7d$$u7d$::hbcd05a4ce5f705a7 + 487 at main.rs:18:13, address = 0x00005555555733b7, resolved, hit count = 0   <-- Location that gets hit when the future is resolved.

(lldb) dis 
tokio-test`tokio_test::main::_$u7b$$u7b$closure$u7d$$u7d$::hbcd05a4ce5f705a7:
    0x5555555731d0 <+0>:   subq   $0x238, %rsp              ; imm = 0x238 
    0x5555555731d7 <+7>:   movq   %rdx, 0x28(%rsp)
    0x5555555731dc <+12>:  movq   %rdi, 0x30(%rsp)
    0x5555555731e1 <+17>:  movq   %rdi, 0x38(%rsp)
    0x5555555731e6 <+22>:  movq   %rsi, 0x48(%rsp)
    0x5555555731eb <+27>:  movq   %rdx, 0x1e8(%rsp)
    0x5555555731f3 <+35>:  movq   0x48(%rsp), %rax
    0x5555555731f8 <+40>:  movzbl 0x80(%rax), %eax
    0x5555555731ff <+47>:  movq   %rax, 0x40(%rsp)
    0x555555573204 <+52>:  movq   0x40(%rsp), %rax
    0x555555573209 <+57>:  leaq   0x101308(%rip), %rcx
    0x555555573210 <+64>:  movslq (%rcx,%rax,4), %rax
    0x555555573214 <+68>:  addq   %rcx, %rax
    0x555555573217 <+71>:  jmpq   *%rax
    0x555555573219 <+73>:  ud2                          <-- Here's the first address, indicated by the lowest address in the line table.
    0x55555557321b <+75>:  movq   0x28(%rsp), %rax
    0x555555573220 <+80>:  movq   %rax, 0x1e0(%rsp)
    0x555555573228 <+88>:  leaq   0x146f49(%rip), %rsi
    0x55555557322f <+95>:  leaq   0x50(%rsp), %rdi
    0x555555573234 <+100>: movl   $0x1, %edx
    0x555555573239 <+105>: callq  0x555555571820            ; core::fmt::Arguments::new_const::h9d890b958e6b6cea at mod.rs:321
    0x55555557323e <+110>: jmp    0x555555573297            ; <+199> at main.rs:16:5
    0x555555573240 <+112>: xorl   %eax, %eax
    0x555555573242 <+114>: testb  $0x1, %al
    0x555555573244 <+116>: jne    0x555555573240            ; <+112> at main.rs:14:1
    0x555555573246 <+118>: jmp    0x55555557330d            ; <+317> at main.rs:14:1
    0x55555557324b <+123>: xorl   %eax, %eax
    0x55555557324d <+125>: testb  $0x1, %al
    0x55555557324f <+127>: jne    0x55555557324b            ; <+123> at main.rs:14:1
    0x555555573251 <+129>: jmp    0x555555573329            ; <+345> at main.rs:14:1
    0x555555573256 <+134>: movq   0x28(%rsp), %rax
    0x55555557325b <+139>: movq   %rax, 0x1e0(%rsp)
    0x555555573263 <+147>: jmp    0x5555555732e9            ; <+281> at main.rs:18:29
    0x555555573268 <+152>: movq   0x48(%rsp), %rax
    0x55555557326d <+157>: movb   $0x2, 0x80(%rax)
    0x555555573274 <+164>: movq   0x1f0(%rsp), %rdi
    0x55555557327c <+172>: callq  0x55555556c040            ; symbol stub for: _Unwind_Resume
    0x555555573281 <+177>: movq   %rax, %rcx
    0x555555573284 <+180>: movl   %edx, %eax
    0x555555573286 <+182>: movq   %rcx, 0x1f0(%rsp)
    0x55555557328e <+190>: movl   %eax, 0x1f8(%rsp)
    0x555555573295 <+197>: jmp    0x555555573268            ; <+152> at main.rs:14:1
    0x555555573297 <+199>: leaq   0xd88f2(%rip), %rax       ; std::io::stdio::_print::hc62f134794ba50d8 at stdio.rs:1105
    0x55555557329e <+206>: leaq   0x50(%rsp), %rdi
    0x5555555732a3 <+211>: callq  *%rax
    0x5555555732a5 <+213>: jmp    0x5555555732a7            ; <+215> at main.rs
    0x5555555732a7 <+215>: leaq   0x108(%rsp), %rdi
    0x5555555732af <+223>: movl   $0xf, %esi
->  0x5555555732b4 <+228>: callq  0x5555555714c0            <-- Where lldb actually stopped.
    0x5555555732b9 <+233>: jmp    0x5555555732bb            ; <+235> at main.rs
    0x5555555732bb <+235>: leaq   0x88(%rsp), %rdi
    0x5555555732c3 <+243>: leaq   0x108(%rsp), %rsi
    0x5555555732cb <+251>: callq  0x555555572f40            ; _$LT$F$u20$as$u20$core..future..into_future..IntoFuture$GT$::into_future::h1cf8907f0c2ba760 at into_future.rs:137
    0x5555555732d0 <+256>: jmp    0x5555555732d2            ; <+258> at main.rs:18:13
    0x5555555732d2 <+258>: movq   0x48(%rsp), %rdi
    0x5555555732d7 <+263>: leaq   0x88(%rsp), %rsi
    0x5555555732df <+271>: movl   $0x80, %edx
    0x5555555732e4 <+276>: callq  0x55555556c060            ; ___lldb_unnamed_symbol6291 + 16
    0x5555555732e9 <+281>: movq   0x48(%rsp), %rax
    0x5555555732ee <+286>: movq   %rax, 0x230(%rsp)
...
    0x555555573368 <+408>: jmp    0x555555573345            ; <+373> at main.rs:18:29
    0x55555557336a <+410>: movq   0x20(%rsp), %rdi
    0x55555557336f <+415>: movq   0x1e0(%rsp), %rsi
    0x555555573377 <+423>: callq  0x555555572f70            ; tokio_test::process_int::_$u7b$$u7b$closure$u7d$$u7d$::h8fcde729a73e470f at main.rs:9
    0x55555557337c <+428>: movl   %edx, 0x18(%rsp)
    0x555555573380 <+432>: movl   %eax, 0x1c(%rsp)
    0x555555573384 <+436>: jmp    0x555555573386            ; <+438> at main.rs
    0x555555573386 <+438>: movl   0x18(%rsp), %eax
    0x55555557338a <+442>: movl   0x1c(%rsp), %ecx
    0x55555557338e <+446>: movl   %ecx, 0x188(%rsp)
    0x555555573395 <+453>: movl   %eax, 0x18c(%rsp)
    0x55555557339c <+460>: movl   0x188(%rsp), %eax
    0x5555555733a3 <+467>: cmpq   $0x0, %rax
    0x5555555733a7 <+471>: jne    0x5555555733ca            ; <+506> at main.rs
    0x5555555733a9 <+473>: movl   0x18c(%rsp), %eax
    0x5555555733b0 <+480>: movl   %eax, 0x204(%rsp)
    0x5555555733b7 <+487>: movl   %eax, 0x84(%rsp)     <-- Third location
    0x5555555733be <+494>: movq   0x48(%rsp), %rdi
    0x5555555733c3 <+499>: callq  0x5555555748e0            ; core::ptr::drop_in_place$LT$tokio_test..process_int..$u7b$$u7b$closure$u7d$$u7d$$GT$::h16e2f156df1eb4f6 at mod.rs:507
    0x5555555733c8 <+504>: jmp    0x5555555733ef            ; <+543> at main.rs
    0x5555555733ca <+506>: movq   0x38(%rsp), %rax
    0x5555555733cf <+511>: movq   0x30(%rsp), %rcx
    0x5555555733d4 <+516>: movq   $0x1, (%rcx)
    0x5555555733db <+523>: movq   0x48(%rsp), %rcx
    0x5555555733e0 <+528>: movb   $0x3, 0x80(%rcx)
    0x5555555733e7 <+535>: addq   $0x238, %rsp              ; imm = 0x238 
    0x5555555733ee <+542>: retq

Luckily, this is generally correct. The breakpoint hits the call instruction for function. The thread is stopped again when you hit the third location when the Future is dropped, which is wacky. But that’s an issue with LLDB.

GDB has better results, since it just sets the breakpoint addresses on the ud2 instruction and on the call site, avoiding the double stoppage that LLDB has.

rustc --version --verbose:

rustc 1.77.0 (aedd173a2 2024-03-17)
binary: rustc
commit-hash: aedd173a2c086e558c2b66d3743b344f977621a7
commit-date: 2024-03-17
host: x86_64-unknown-linux-gnu
release: 1.77.0
LLVM version: 17.0.6

Metadata

Metadata

Assignees

Labels

A-async-awaitArea: Async & AwaitA-debuginfoArea: Debugging information in compiled programs (DWARF, PDB, etc.)AsyncAwait-TriagedAsync-await issues that have been triaged during a working group meeting.C-bugCategory: This is a bug.T-compilerRelevant to the compiler team, which will review and decide on the PR/issue.WG-asyncWorking group: Async & awaitWG-debuggingWorking group: Bad Rust debugging experiences

Type

No type

Projects

No projects

Milestone

No milestone

Relationships

None yet

Development

No branches or pull requests

Issue actions