Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

1.71: Bad DW_TAG_lexical_block; gdb breaks on method before self is initialized #130003

Closed
apodolsk opened this issue Sep 5, 2024 · 9 comments · Fixed by #130052
Closed

1.71: Bad DW_TAG_lexical_block; gdb breaks on method before self is initialized #130003

apodolsk opened this issue Sep 5, 2024 · 9 comments · Fixed by #130052
Labels
A-debuginfo Area: Debugging information in compiled programs (DWARF, PDB, etc.) A-LLVM Area: Code generation parts specific to LLVM. Both correctness bugs and optimization-related issues. C-bug Category: This is a bug. WG-debugging Working group: Bad Rust debugging experiences

Comments

@apodolsk
Copy link

apodolsk commented Sep 5, 2024

I tried this code:

struct Foo {
    a: usize,
}

impl Foo {
    #[inline(never)]
    fn get_a(&self) -> Option<usize> {
        Some(self.a)
    }

    #[inline(never)]
    fn var_return(&self) -> usize {
        let r = self.get_a().unwrap();
        r
    }

    #[inline(never)]
    fn var_return_opt_unwrap(&self) -> Option<usize> {
        let r = self.get_a().unwrap();
        Some(r)
    }

    #[inline(never)]
    fn var_return_opt_match(&self) -> Option<usize> {
        let r = match self.get_a() {
            None => return None,
            Some(a) => a,
        };
        Some(r)
    }

    #[inline(never)]
    fn var_return_opt_try(&self) -> Option<usize> {
        let r = self.get_a()?;
        Some(r)
    }
}

fn main() {
    let f1 = Foo{ a: 1 };
    let f2 = Foo{ a: 1 };
    f1.var_return();
    f1.var_return_opt_unwrap();
    f1.var_return_opt_match();
    f2.var_return_opt_try();
}

Setting a breakpoint on var_return_opt_try in rust-gdb results in gdb stopping before self's stack slot is initialized, and gdb dereferences it to print wrong values based on self:

~/code/scrap/rust/debuginfo: cargo clean; RUSTFLAGS=-Zmir-enable-passes=-SingleUseConsts cargo +nightly build         
     Removed 0 files                    
   Compiling debuginfo v0.1.0 (/home/vich/code/scrap/rust/debuginfo)
    Finished `dev` profile [unoptimized + debuginfo] target(s) in 0.08s
~/code/scrap/rust/debuginfo: rust-gdb target/debug/debuginfo -batch -ex "b debuginfo::Foo::var_return_opt_try" -ex "r" -ex "disas" -ex "p self" -ex "n" -ex "p self"
Breakpoint 1 at 0x33d68: file std/src/panicking.rs, line 862.
Breakpoint 2 at 0x13c24: file src/main.rs, line 34.
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/usr/lib/libthread_db.so.1".

Breakpoint 2, debuginfo::Foo::var_return_opt_try (self=0x7fffffffe0f8) at src/main.rs:34
34	        let r = self.get_a()?;
Dump of assembler code for function _ZN9debuginfo3Foo18var_return_opt_try17hed204febe8a0db96E:
   0x0000555555567c20 <+0>:	sub    $0x38,%rsp
=> 0x0000555555567c24 <+4>:	mov    %rdi,0x28(%rsp)
   0x0000555555567c29 <+9>:	call   0x555555567ae0 <debuginfo::Foo::get_a>
   0x0000555555567c2e <+14>:	mov    %rax,%rdi
   0x0000555555567c31 <+17>:	mov    %rdx,%rsi
   0x0000555555567c34 <+20>:	call   0x555555567d20 <core::option::{impl#39}::branch<usize>>
   0x0000555555567c39 <+25>:	mov    %rax,0x18(%rsp)
   0x0000555555567c3e <+30>:	mov    %rdx,0x20(%rsp)
   0x0000555555567c43 <+35>:	cmpq   $0x0,0x18(%rsp)
   0x0000555555567c49 <+41>:	jne    0x555555567c65 <debuginfo::Foo::var_return_opt_try+69>
   0x0000555555567c4b <+43>:	mov    0x20(%rsp),%rax
   0x0000555555567c50 <+48>:	mov    %rax,0x30(%rsp)
   0x0000555555567c55 <+53>:	mov    %rax,0x10(%rsp)
   0x0000555555567c5a <+58>:	movq   $0x1,0x8(%rsp)
   0x0000555555567c63 <+67>:	jmp    0x555555567c74 <debuginfo::Foo::var_return_opt_try+84>
   0x0000555555567c65 <+69>:	call   0x555555567d00 <core::option::{impl#40}::from_residual<usize>>
   0x0000555555567c6a <+74>:	mov    %rax,0x8(%rsp)
   0x0000555555567c6f <+79>:	mov    %rdx,0x10(%rsp)
   0x0000555555567c74 <+84>:	mov    0x8(%rsp),%rax
   0x0000555555567c79 <+89>:	mov    0x10(%rsp),%rdx
   0x0000555555567c7e <+94>:	add    $0x38,%rsp
   0x0000555555567c82 <+98>:	ret
End of assembler dump.
$1 = (*mut debuginfo::Foo) 0x7fffffffe0f8
35	        Some(r)
$2 = (*mut debuginfo::Foo) 0x7fffffffe100
~/code/scrap/rust/debuginfo: rust-gdb --version
GNU gdb (GDB) 15.1

Note the incorrect different values of self as I step past initialization. The breakpoint should trigger just after that mov, not before it. The other functions in that program indeed do it correctly. Oddly, it seems like the ? operator is necessary for my repro, though maybe that has something to do with the hidden residual var.

(Note that f1 vs f2 is necessary to actually avoid accidental correct values of self due to stack reuse, so the other functions can't print wrong self as written. But I'm just looking at where the breakpoint hits in disassembly.)

Here's relevant llvm-dwarfdump from this binary, with a DW_TAG_lexical_block pointing at at the mov (0x...24) rather than the call:

0x0000049a:   DW_TAG_subprogram
                DW_AT_low_pc    (0x0000000000013c20)
                DW_AT_high_pc   (0x0000000000013c83)
                DW_AT_frame_base        (DW_OP_reg7 RSP)
                DW_AT_specification     (0x0000017b "_ZN9debuginfo3Foo18var_return_opt_try17hed204febe8a0db96E")

0x000004ad:     DW_TAG_formal_parameter
                  DW_AT_location        (DW_OP_fbreg +40)
                  DW_AT_name    ("self")
                  DW_AT_decl_file       ("/home/vich/code/scrap/rust/debuginfo/src/main.rs")
                  DW_AT_decl_line       (33)
                  DW_AT_type    (0x00000324 "debuginfo::Foo *")

0x000004bb:     DW_TAG_lexical_block
                  DW_AT_ranges  (0x00000060
                     [0x0000000000013c24, 0x0000000000013c29)
                     [0x0000000000013c65, 0x0000000000013c74))

0x000004c0:       DW_TAG_variable
                    DW_AT_location      (DW_OP_fbreg +7)
                    DW_AT_name  ("residual")
                    DW_AT_decl_file     ("/home/vich/code/scrap/rust/debuginfo/src/main.rs")
                    DW_AT_decl_line     (34)
                    DW_AT_type  (0x0000027d "core::option::Option<core::convert::Infallible>")

0x000004ce:       NULL

0x000004cf:     DW_TAG_lexical_block
                  DW_AT_low_pc  (0x0000000000013c55)
                  DW_AT_high_pc (0x0000000000013c63)

0x000004dc:       DW_TAG_variable
                    DW_AT_location      (DW_OP_fbreg +48)
                    DW_AT_name  ("r")
                    DW_AT_alignment     (1)
                    DW_AT_decl_file     ("/home/vich/code/scrap/rust/debuginfo/src/main.rs")
                    DW_AT_decl_line     (34)
                    DW_AT_type  (0x000001e6 "usize")

0x000004eb:       NULL

0x000004ec:     NULL

0x000004ed:   NULL

This looks pretty related to #128945 and #113819.

Like 113819, the repro hits on 1.71 but not 1.70. I'm filing separately because, unlike it, disabling SingleUseConsts doesn't seem to fix the breakpoint. I'm not 100% sure I'm disabling it right - you can see my cargo build command above.

Meta

rustc --version --verbose:

rustc 1.83.0-nightly (4ac7bcbaa 2024-09-04)
binary: rustc
commit-hash: 4ac7bcbaad8d6fd7a51bdf1b696cbc3ba4c796cf
commit-date: 2024-09-04
host: x86_64-unknown-linux-gnu
release: 1.83.0-nightly
LLVM version: 19.1.0
Backtrace

<backtrace>

@apodolsk apodolsk added the C-bug Category: This is a bug. label Sep 5, 2024
@rustbot rustbot added the needs-triage This issue may need triage. Remove it if it has been sufficiently triaged. label Sep 5, 2024
@apodolsk
Copy link
Author

apodolsk commented Sep 5, 2024

I'm not familiar with github's notification rules, so pinging @khuey @saethlin.

@khuey
Copy link
Contributor

khuey commented Sep 5, 2024

Thanks for the tag, I wouldn't have seen this otherwise.

From dwarfdump -l, we can see that the "prologue end" marker that tells the debugger where to stop is indeed placed on the mov

0x00013cb0  [  33, 0] NS
0x00013cb4  [  34,29] NS PE
0x00013cb9  [  34,17]
0000000000013cb0 <_ZN11rust_1300033Foo18var_return_opt_try17hcd26f4530d437787E>:
   13cb0:       48 83 ec 38             sub    $0x38,%rsp
   13cb4:       48 89 7c 24 28          mov    %rdi,0x28(%rsp)
   13cb9:       e8 b2 fe ff ff          call   13b70 <_ZN11rust_1300033Foo5get_a17h8300da2e5e4489e5E>

I suspect this is due to the desugaring of the ? operator since the column number provided is 29.

@khuey
Copy link
Contributor

khuey commented Sep 5, 2024

@rustbot label +A-debuginfo

@rustbot rustbot added the A-debuginfo Area: Debugging information in compiled programs (DWARF, PDB, etc.) label Sep 6, 2024
@khuey
Copy link
Contributor

khuey commented Sep 6, 2024

********************************************************************************
Regression in nightly-2023-04-24
********************************************************************************

fetching https://static.rust-lang.org/dist/2023-04-23/channel-rust-nightly-git-commit-hash.txt
nightly manifest 2023-04-23: 40 B / 40 B [========================================] 100.00 % 436.93 KB/s
converted 2023-04-23 to b628260df0587ae559253d8640ecb8738d3de613
fetching https://static.rust-lang.org/dist/2023-04-24/channel-rust-nightly-git-commit-hash.txt
nightly manifest 2023-04-24: 40 B / 40 B [========================================] 100.00 % 466.85 KB/s
converted 2023-04-24 to 7f94b314cead7059a71a265a8b64905ef2511796
looking for regression commit between 2023-04-23 and 2023-04-24
fetching (via remote github) commits from max(b628260df0587ae559253d8640ecb8738d3de613, 2023-04-21) to 7f
94b314cead7059a71a265a8b64905ef2511796
ending github query because we found starting sha: b628260df0587ae559253d8640ecb8738d3de613
get_commits_between returning commits, len: 9
  commit[0] 2023-04-22: Auto merge of #110523 - ecnelises:llvm_isa_fix, r=cuviper
  commit[1] 2023-04-22: Auto merge of #110703 - clubby789:synstructure-remove, r=Nilstrieb
  commit[2] 2023-04-23: Auto merge of #110186 - Nilstrieb:update-time, r=Mark-Simulacrum
  commit[3] 2023-04-23: Auto merge of #110655 - ChrisDenton:read-to-end, r=joshtriplett
  commit[4] 2023-04-23: Auto merge of #110497 - cjgillot:span-ctxt, r=b-naber
  commit[5] 2023-04-23: Auto merge of #107404 - cjgillot:const-debuginfo, r=oli-obk
  commit[6] 2023-04-23: Auto merge of #108118 - oli-obk:lazy_typeck, r=cjgillot
  commit[7] 2023-04-23: Auto merge of #110705 - saethlin:ignore-locals-cost, r=cjgillot
  commit[8] 2023-04-23: Auto merge of #110281 - ozkanonur:multiarch-compatible-sysroot-finding, r=jackh726
ERROR: no CI builds available between b628260df0587ae559253d8640ecb8738d3de613 and 7f94b314cead7059a71a265a8b64905ef2511796 within last 167 days

Sure enough, ConstDebugInfo is in there.

@apodolsk
Copy link
Author

apodolsk commented Sep 6, 2024

I guess you probably saw, but #128945 does suggest that the bisect is somehow misleading.

@khuey
Copy link
Contributor

khuey commented Sep 6, 2024

Yes, getting the values wrong at function entry is especially bad because it messes up conditional breakpoints.

@saethlin saethlin added A-LLVM Area: Code generation parts specific to LLVM. Both correctness bugs and optimization-related issues. WG-debugging Working group: Bad Rust debugging experiences and removed needs-triage This issue may need triage. Remove it if it has been sufficiently triaged. labels Sep 6, 2024
@khuey
Copy link
Contributor

khuey commented Sep 6, 2024

Disabling the SingleUseConsts pass doesn't do anything here because the VarDebugInfoContents::Const is created by RemoveZsts when it removes <Option as Try>::Residual. Otherwise this is identical to #128945.

The easiest way to fix this would be for DILocation to carry a "this is not a statement" flag that overrides LLVM's usual line based inference of statement markers. I'll run it by the LLVM folks and see what they say.

@khuey
Copy link
Contributor

khuey commented Sep 6, 2024

Actually, in this particular case, because the const is a ZST I think we can do better today without LLVM changes.

@khuey
Copy link
Contributor

khuey commented Sep 6, 2024

Thanks for reporting this. The linked PR will fix this particular degenerate case.

workingjubilee added a commit to workingjubilee/rustc that referenced this issue Sep 11, 2024
…-emission, r=michaelwoerister

Don't leave debug locations for constants sitting on the builder indefinitely

Because constants are currently emitted *before* the prologue, leaving the debug location on the IRBuilder spills onto other instructions in the prologue and messes up both line numbers as well as the point LLVM chooses to be the prologue end.

Example LLVM IR (irrelevant IR elided):
Before:
```
define internal { i64, i64 } `@_ZN3tmp3Foo18var_return_opt_try17he02116165b0fc08cE(ptr` align 8 %self) !dbg !347 { start:
  %self.dbg.spill = alloca [8 x i8], align 8
  %_0 = alloca [16 x i8], align 8
  %residual.dbg.spill = alloca [0 x i8], align 1
    #dbg_declare(ptr %residual.dbg.spill, !353, !DIExpression(), !357)
  store ptr %self, ptr %self.dbg.spill, align 8, !dbg !357
    #dbg_declare(ptr %self.dbg.spill, !350, !DIExpression(), !358)
```
After:
```
define internal { i64, i64 } `@_ZN3tmp3Foo18var_return_opt_try17h00b17d08874ddd90E(ptr` align 8 %self) !dbg !347 { start:
  %self.dbg.spill = alloca [8 x i8], align 8
  %_0 = alloca [16 x i8], align 8
  %residual.dbg.spill = alloca [0 x i8], align 1
    #dbg_declare(ptr %residual.dbg.spill, !353, !DIExpression(), !357)
  store ptr %self, ptr %self.dbg.spill, align 8
    #dbg_declare(ptr %self.dbg.spill, !350, !DIExpression(), !358)
```
Note in particular how !357 from %residual.dbg.spill's dbg_declare no longer falls through onto the store to %self.dbg.spill. This fixes argument values at entry when the constant is a ZST (e.g. `<Option as Try>::Residual`). This fixes rust-lang#130003 (but note that it does *not* fix issues with argument values and non-ZST constants, which emit their own stores that have debug info on them, like rust-lang#128945).

r? `@michaelwoerister`
workingjubilee added a commit to workingjubilee/rustc that referenced this issue Sep 11, 2024
…-emission, r=michaelwoerister

Don't leave debug locations for constants sitting on the builder indefinitely

Because constants are currently emitted *before* the prologue, leaving the debug location on the IRBuilder spills onto other instructions in the prologue and messes up both line numbers as well as the point LLVM chooses to be the prologue end.

Example LLVM IR (irrelevant IR elided):
Before:
```
define internal { i64, i64 } ``@_ZN3tmp3Foo18var_return_opt_try17he02116165b0fc08cE(ptr`` align 8 %self) !dbg !347 { start:
  %self.dbg.spill = alloca [8 x i8], align 8
  %_0 = alloca [16 x i8], align 8
  %residual.dbg.spill = alloca [0 x i8], align 1
    #dbg_declare(ptr %residual.dbg.spill, !353, !DIExpression(), !357)
  store ptr %self, ptr %self.dbg.spill, align 8, !dbg !357
    #dbg_declare(ptr %self.dbg.spill, !350, !DIExpression(), !358)
```
After:
```
define internal { i64, i64 } ``@_ZN3tmp3Foo18var_return_opt_try17h00b17d08874ddd90E(ptr`` align 8 %self) !dbg !347 { start:
  %self.dbg.spill = alloca [8 x i8], align 8
  %_0 = alloca [16 x i8], align 8
  %residual.dbg.spill = alloca [0 x i8], align 1
    #dbg_declare(ptr %residual.dbg.spill, !353, !DIExpression(), !357)
  store ptr %self, ptr %self.dbg.spill, align 8
    #dbg_declare(ptr %self.dbg.spill, !350, !DIExpression(), !358)
```
Note in particular how !357 from %residual.dbg.spill's dbg_declare no longer falls through onto the store to %self.dbg.spill. This fixes argument values at entry when the constant is a ZST (e.g. `<Option as Try>::Residual`). This fixes rust-lang#130003 (but note that it does *not* fix issues with argument values and non-ZST constants, which emit their own stores that have debug info on them, like rust-lang#128945).

r? ``@michaelwoerister``
Zalathar added a commit to Zalathar/rust that referenced this issue Sep 12, 2024
…-emission, r=michaelwoerister

Don't leave debug locations for constants sitting on the builder indefinitely

Because constants are currently emitted *before* the prologue, leaving the debug location on the IRBuilder spills onto other instructions in the prologue and messes up both line numbers as well as the point LLVM chooses to be the prologue end.

Example LLVM IR (irrelevant IR elided):
Before:
```
define internal { i64, i64 } ```@_ZN3tmp3Foo18var_return_opt_try17he02116165b0fc08cE(ptr``` align 8 %self) !dbg !347 { start:
  %self.dbg.spill = alloca [8 x i8], align 8
  %_0 = alloca [16 x i8], align 8
  %residual.dbg.spill = alloca [0 x i8], align 1
    #dbg_declare(ptr %residual.dbg.spill, !353, !DIExpression(), !357)
  store ptr %self, ptr %self.dbg.spill, align 8, !dbg !357
    #dbg_declare(ptr %self.dbg.spill, !350, !DIExpression(), !358)
```
After:
```
define internal { i64, i64 } ```@_ZN3tmp3Foo18var_return_opt_try17h00b17d08874ddd90E(ptr``` align 8 %self) !dbg !347 { start:
  %self.dbg.spill = alloca [8 x i8], align 8
  %_0 = alloca [16 x i8], align 8
  %residual.dbg.spill = alloca [0 x i8], align 1
    #dbg_declare(ptr %residual.dbg.spill, !353, !DIExpression(), !357)
  store ptr %self, ptr %self.dbg.spill, align 8
    #dbg_declare(ptr %self.dbg.spill, !350, !DIExpression(), !358)
```
Note in particular how !357 from %residual.dbg.spill's dbg_declare no longer falls through onto the store to %self.dbg.spill. This fixes argument values at entry when the constant is a ZST (e.g. `<Option as Try>::Residual`). This fixes rust-lang#130003 (but note that it does *not* fix issues with argument values and non-ZST constants, which emit their own stores that have debug info on them, like rust-lang#128945).

r? ```@michaelwoerister```
bors added a commit to rust-lang-ci/rust that referenced this issue Sep 13, 2024
…mission, r=michaelwoerister

Don't leave debug locations for constants sitting on the builder indefinitely

Because constants are currently emitted *before* the prologue, leaving the debug location on the IRBuilder spills onto other instructions in the prologue and messes up both line numbers as well as the point LLVM chooses to be the prologue end.

Example LLVM IR (irrelevant IR elided):
Before:
```
define internal { i64, i64 } `@_ZN3tmp3Foo18var_return_opt_try17he02116165b0fc08cE(ptr` align 8 %self) !dbg !347 { start:
  %self.dbg.spill = alloca [8 x i8], align 8
  %_0 = alloca [16 x i8], align 8
  %residual.dbg.spill = alloca [0 x i8], align 1
    #dbg_declare(ptr %residual.dbg.spill, !353, !DIExpression(), !357)
  store ptr %self, ptr %self.dbg.spill, align 8, !dbg !357
    #dbg_declare(ptr %self.dbg.spill, !350, !DIExpression(), !358)
```
After:
```
define internal { i64, i64 } `@_ZN3tmp3Foo18var_return_opt_try17h00b17d08874ddd90E(ptr` align 8 %self) !dbg !347 { start:
  %self.dbg.spill = alloca [8 x i8], align 8
  %_0 = alloca [16 x i8], align 8
  %residual.dbg.spill = alloca [0 x i8], align 1
    #dbg_declare(ptr %residual.dbg.spill, !353, !DIExpression(), !357)
  store ptr %self, ptr %self.dbg.spill, align 8
    #dbg_declare(ptr %self.dbg.spill, !350, !DIExpression(), !358)
```
Note in particular how !357 from %residual.dbg.spill's dbg_declare no longer falls through onto the store to %self.dbg.spill. This fixes argument values at entry when the constant is a ZST (e.g. `<Option as Try>::Residual`). This fixes rust-lang#130003 (but note that it does *not* fix issues with argument values and non-ZST constants, which emit their own stores that have debug info on them, like rust-lang#128945).

r? `@michaelwoerister`
@bors bors closed this as completed in 7ed9f94 Sep 13, 2024
shrirambalaji pushed a commit to shrirambalaji/rust that referenced this issue Oct 6, 2024
…finitely.

Because constants are currently emitted *before* the prologue, leaving the
debug location on the IRBuilder spills onto other instructions in the prologue
and messes up both line numbers as well as the point LLVM chooses to be the
prologue end.

Example LLVM IR (irrelevant IR elided):
Before:

define internal { i64, i64 } @_ZN3tmp3Foo18var_return_opt_try17he02116165b0fc08cE(ptr align 8 %self) !dbg !347 {
start:
  %self.dbg.spill = alloca [8 x i8], align 8
  %_0 = alloca [16 x i8], align 8
  %residual.dbg.spill = alloca [0 x i8], align 1
    #dbg_declare(ptr %residual.dbg.spill, !353, !DIExpression(), !357)
  store ptr %self, ptr %self.dbg.spill, align 8, !dbg !357
    #dbg_declare(ptr %self.dbg.spill, !350, !DIExpression(), !358)

After:

define internal { i64, i64 } @_ZN3tmp3Foo18var_return_opt_try17h00b17d08874ddd90E(ptr align 8 %self) !dbg !347 {
start:
  %self.dbg.spill = alloca [8 x i8], align 8
  %_0 = alloca [16 x i8], align 8
  %residual.dbg.spill = alloca [0 x i8], align 1
    #dbg_declare(ptr %residual.dbg.spill, !353, !DIExpression(), !357)
  store ptr %self, ptr %self.dbg.spill, align 8
    #dbg_declare(ptr %self.dbg.spill, !350, !DIExpression(), !358)

Note in particular how !357 from %residual.dbg.spill's dbg_declare no longer
falls through onto the store to %self.dbg.spill. This fixes argument values
at entry when the constant is a ZST (e.g. <Option as Try>::Residual). This
fixes rust-lang#130003 (but note that it does *not* fix issues with argument values and
non-ZST constants, which emit their own stores that have debug info on them,
like rust-lang#128945).
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
A-debuginfo Area: Debugging information in compiled programs (DWARF, PDB, etc.) A-LLVM Area: Code generation parts specific to LLVM. Both correctness bugs and optimization-related issues. C-bug Category: This is a bug. WG-debugging Working group: Bad Rust debugging experiences
Projects
None yet
Development

Successfully merging a pull request may close this issue.

4 participants