LLVM Bugzilla is read-only and represents the historical archive of all LLVM issues filled before November 26, 2021. Use github to submit LLVM bugs

Bug 48029 - Rust function of sufficient length prevents breakpoints from working
Summary: Rust function of sufficient length prevents breakpoints from working
Status: RESOLVED FIXED
Alias: None
Product: tools
Classification: Unclassified
Component: llvm-dsymutil (show other bugs)
Version: trunk
Hardware: Macintosh MacOS X
: P enhancement
Assignee: Jonas Devlieghere
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2020-10-30 17:18 PDT by Dan Fritchman
Modified: 2020-11-07 10:55 PST (History)
7 users (show)

See Also:
Fixed By Commit(s):


Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description Dan Fritchman 2020-10-30 17:18:34 PDT
Following up on an issue originally reported to the VsCode plug-in CodeLLDB:
https://github.com/vadimcn/vscode-lldb/issues/369

Both the author and I reached the conclusion this comes back to LLDB. 
Discovered upon porting an existing (long, ~5k LOC) C function into Rust. With this code in place, breakpoints are not resolved:

```
break list 
Current breakpoints:
1: file = 'src/main.rs', line = 4, exact_match = 0, locations = 0 (pending)
2: file = 'main.rs', line = 5, exact_match = 0, locations = 0 (pending)
3: file = 'src/tests.rs', line = 13, exact_match = 0, locations = 0 (pending)

4: Exception breakpoint (catch: on throw: on) using: names = {'__cxa_begin_catch', '__cxa_throw', '__cxa_rethrow'}, modules(2) = libc++abi.dylib, libSystem.B.dylib

5: name = 'rust_panic', locations = 1, resolved = 1, hit count = 0
  5.1: where = spice21`rust_panic + 20 at panicking.rs:626:9, address = 0x00000001000acb04, resolved, hit count = 0
```

This is despite debug info being present: 

```
dsymutil -s  target/debug/spice21 | grep N_OSO 
[   920] 000269e1 66 (N_OSO        ) 03     0001   0000000000000000 'target/debug/deps/spice21.1qcu4jwi3fjtxyk9.rcgu.o'
[   933] 00026a80 66 (N_OSO        ) 03     0001   0000000000000000 'target/debug/deps/spice21.2ql4572xdsy6ks1i.rcgu.o'
[   946] 00026c09 66 (N_OSO        ) 03     0001   0000000000000000 'target/debug/deps/spice21.2xq4mz9sgc2ysmfp.rcgu.o'
[   955] 00026d3a 66 (N_OSO        ) 03     0001   0000000000000000 'target/debug/deps/spice21.36d1auo9zjn0ja0b.rcgu.o'
[   978] 00026f7c 66 (N_OSO        ) 03     0001   0000000000000000 'target/debug/deps/spice21.3nan5uievwffbtlg.rcgu.o'
[   991] 000270b8 66 (N_OSO        ) 03     0001   0000000000000000 'target/debug/deps/spice21.4tcozfs9ntfwgd8y.rcgu.o'
[  1001] 00027208 66 (N_OSO        ) 03     0001   0000000000000000 'target/debug/deps/libspice21-1f365d6b281ad2bf.rlib(spice21-1f365d6b281ad2bf.11mevay8dm2eejnt.rcgu.o)'
[  1029] 000274f8 66 (N_OSO        ) 03     0001   0000000000000000 'target/debug/deps/libspice21-1f365d6b281ad2bf.rlib(spice21-1f365d6b281ad2bf.13zfg5ipncreabid.rcgu.o)'
[  1039] 000276bf 66 (N_OSO        ) 03     0001   0000000000000000 'target/debug/deps/libspice21-1f365d6b281ad2bf.rlib(spice21-1f365d6b281ad2bf.1442y1ntqkhpbe43.rcgu.o)'
[  1048] 0002780c 66 (N_OSO        ) 03     0001   0000000000000000 'target/debug/deps/libspice21-1f365d6b281ad2bf.rlib(spice21-1f365d6b281ad2bf.14pwkb0vdbu5d5t8.rcgu.o)'
[  1076] 00027ac8 66 (N_OSO        ) 03     0001   0000000000000000 'target/debug/deps/libspice21-1f365d6b281ad2bf.rlib(spice21-1f365d6b281ad2bf.16uddp6gzdci0bwn.rcgu.o)'

# ... 
# about 150 others 
```

And confirming this is not an issue with the IDE plug-in, setting the same breakpoints via LLDB command also fails:

```
break set --file src/main.rs --line 5 
Breakpoint 7: no locations (pending).
WARNING:  Unable to resolve breakpoint to any actual locations.
```

All of this is on MacOS, using the stable Rust compiler and LLDB 11. 
First time bug-filer here, please let me know what info will help.
Comment 1 Jim Ingham 2020-10-30 17:49:55 PDT
File and line breakpoints use the line table from the debug info.  You can look at that in the debug info with

dwarfdump --debug-line <object-file or dSYM>

And you can see it as lldb internalized it with:

(lldb) image dump line-table main.rs

If the first one doesn't show entries for your function, then something in your toolchain is dropping the line info on the floor.

If it is in the DWARF, but not in the "image dump" output then lldb isn't internalizing the DWARF properly.

And if it is in the debug info and we show it in image dump, then for some reason the breakpoint resolver is rejecting the matches.
Comment 2 Dan Fritchman 2020-11-01 10:40:09 PST
Appears in the failing cases, `dwarfdump` doesn't recognize the Rust compiler outputs as valid. 

Working case:

```
dwarfdump --debug-line target/debug/deps/spice21-c5baf7da58e66c42.dSYM | grep -A 10 tests
           name: "tests.rs"
      dir_index: 1
       mod_time: 0x00000000
         length: 0x00000000

Address            Line   Column File   ISA Discriminator Flags
------------------ ------ ------ ------ --- ------------- -------------
0x0000000100014310     13      0      1   0             0  is_stmt
0x000000010001432f     14     25      1   0             0  is_stmt prologue_end
0x0000000100014345     15     41      1   0             0  is_stmt
0x000000010001435f     13      5      1   0             0  is_stmt
--
           name: "tests.rs"
      dir_index: 1
       mod_time: 0x00000000
         length: 0x00000000

Address            Line   Column File   ISA Discriminator Flags
------------------ ------ ------ ------ --- ------------- -------------
0x000000010006ef80     13      0      1   0             0  is_stmt
0x000000010006ef8c     13      5      1   0             0  is_stmt prologue_end
0x000000010006ef9e     19      6      1   0             0  is_stmt
0x000000010006efa4     19      6      1   0             0  is_stmt end_sequence
```

Failing case:

```
dwarfdump --debug-line target/debug/deps/spice21-c5baf7da58e66c42.dSYM                   
error: target/debug/deps/spice21-c5baf7da58e66c42.dSYM/Contents/Resources/DWARF/spice21-c5baf7da58e66c42: The file was not recognized as a valid object file
```

(Note I don't know why rustc is naming these dSYM's with identical checksum-seeming suffixes (c5baf7da58e66c42). But they are clearly different, and correspond to different versions of the source code.)

I expect you'll want to refer this to the Rust compiler. 
Any other helpful info to grab first?
Comment 3 labath 2020-11-01 23:50:33 PST
Yeah, that definitely is a bug on the producer side.

The error message makes it sound like something has gone horribly wrong when producing that file -- it does not even register as a MachO file. Maybe the compiler (or dsymutil?) crashed somehow before it could produce that file?

I think the compiler folks would ideally want a way to reproduce this bug, so a small self-contained piece of source code that triggers this would be most helpful (though it sounds like that may be hard in this case)....
Comment 4 Dan Fritchman 2020-11-03 09:22:32 PST
This is now:
https://github.com/rust-lang/rust/issues/78657

Actually came across this in a 2nd situation, which proved aways easier to reproduce. Rust's macros (including popular library ones) are perfectly capable of generating these long functions. So, this recreates it: 
https://github.com/dan-fritchman/DwDemo

Thanks for checking this out. Let me know if there's anything I can do to close.
Comment 5 Greg Parker 2020-11-05 04:53:02 PST
As discussed in the rust-lang issue linked above, this has come back around to dsymutil. labath called it: dsymutil crashed, leaving behind an invalid dSYM.

The debug info emitted by Rust DW_TAG_lexical_block DIEs nested almost 900 deep. dsymutil crashes by running out of stack space after around 720 recursive calls to analyzeContextInfo(). 

To reproduce on macOS:
1. Download http://sealiesoftware.com/DwDemo.zip and unpack it as /tmp/DwDemo/.
2. `dsymutil /tmp/DwDemo/target/debug/deps/dwdemo`. It will harmlessly complain about some missing object files and then crash.
3. `dsymutil --num-threads 1 /tmp/DwDemo/target/debug/deps/dwdemo`. This doesn't crash (see below).

One simple fix is to increase the stack size. dsymutil runs this code on worker threads with default stack size, which on macOS is only 512 KB. `dsymutil --num-threads 1` runs instead on the 8 MB main thread. 8 MB worker threads would probably support well over 10000 nested DIEs. (Unfortunately dsymutil is using std::thread, which I don't think has any way to set the stack size.)

A more robust fix would be to process DIEs without recursive calls. That would be a more difficult change. It also might be ultimately ineffective: it might simply delay the crash until similar recursive code inside the debugger.

(A larger discussion: how should Rust represent its variable scopes in debug info? Deeply nested DW_TAG_lexical_block is probably not it.)
Comment 6 labath 2020-11-05 06:58:20 PST
(In reply to Greg Parker from comment #5)
> As discussed in the rust-lang issue linked above, this has come back around
> to dsymutil. labath called it: dsymutil crashed, leaving behind an invalid
> dSYM.

What is running dsymutil? Is it the rust compiler? Sounds like something should at least be better at surfacing the fact that this step did not complete successfully.

> 
> The debug info emitted by Rust DW_TAG_lexical_block DIEs nested almost 900
> deep. 

Ouch.

> One simple fix is to increase the stack size. dsymutil runs this code on
> worker threads with default stack size, which on macOS is only 512 KB.
> `dsymutil --num-threads 1` runs instead on the 8 MB main thread. 8 MB worker
> threads would probably support well over 10000 nested DIEs. (Unfortunately
> dsymutil is using std::thread, which I don't think has any way to set the
> stack size.)

We have utilities in llvm to create threads with larger stack space, so this can be increased. That said, 900 is quite a lot, and may end up taxing a lot of other components too...

> (A larger discussion: how should Rust represent its variable scopes in debug
> info? Deeply nested DW_TAG_lexical_block is probably not it.)

What do you mean by variables scopes, exactly? Is it for variables that get declared in the middle of a block? I.e.,
void f() {
  // some code
  int x = 47; // rust creates a new lexical block here?
  // more code
}
DWARF has DW_AT_start_scope, which is supposed to handle exactly this. AFAIK, this attribute is not yet supported in llvm. The way this is done in c++ is by providing a location list (DW_AT_location) for the variable, which is a subset of the ranges specified by the enclosing lexical block.

The semantics are not exactly the same ("variable does not exist" vs. "variable exists but we don't know where it is"), but it's close enough for most purposes.
Comment 7 Greg Parker 2020-11-05 09:32:47 PST
(In reply to labath from comment #6)
> What is running dsymutil? Is it the rust compiler? Sounds like something
> should at least be better at surfacing the fact that this step did not
> complete successfully.
Yes, it's a rustc bug: it silently ignores any failure from dsymutil.
 
> > (A larger discussion: how should Rust represent its variable scopes in debug
> > info? Deeply nested DW_TAG_lexical_block is probably not it.)
> 
> What do you mean by variables scopes, exactly? Is it for variables that get
> declared in the middle of a block? I.e.,
> void f() {
>   // some code
>   int x = 47; // rust creates a new lexical block here?
>   // more code
> }
> DWARF has DW_AT_start_scope, which is supposed to handle exactly this.
> AFAIK, this attribute is not yet supported in llvm. The way this is done in
> c++ is by providing a location list (DW_AT_location) for the variable, which
> is a subset of the ranges specified by the enclosing lexical block.
> 
> The semantics are not exactly the same ("variable does not exist" vs.
> "variable exists but we don't know where it is"), but it's close enough for
> most purposes.
The problem is that Rust allows multiple variables to sequentially recycle the same name within a single source-level scope. I'm unfamiliar with the history here, but apparently handling that case without a new lexical_block confuses debuggers (or at least it used to).

https://github.com/rust-lang/rust/blob/c9f15013e0edc80989bf40b358bcefee14be5050/src/librustc_trans/debuginfo/create_scope_map.rs#L246
    // LLVM does not properly generate 'DW_AT_start_scope' fields
    // for variable DIEs. For this reason we have to introduce
    // an artificial scope at bindings whenever a variable with
    // the same name is declared in *any* parent scope.

(followed by an example of undesirable gdb behavior without the additional lexical_blocks)

Having said that, in my own tests I have seen rustc emit nested lexical_blocks even when the variables don't shadow anything, so there may be a rustc bug to improve here. 

The DwDemo code actually is a single variable name recycled 900 times; it looks something like this:
    {
        let builder = ...;
        let builder = ...;
        let builder = ...;
        ...
    }
…although the generator of that code could re-use a single variable here, which is yet another bug report to spin off of this.

DW_AT_start_scope should be perfect for Rust, someday. (I had assumed that it could only specify the variable's start location with the end location extending to the rest of the lexical_block, but on closer inspection it also allows discontiguous ranges.) Debuggers would need to correctly handle multiple variables with the same name but non-overlapping locations within a single lexical_block.
Comment 8 Greg Parker 2020-11-05 11:29:10 PST
(In reply to Greg Parker from comment #7)
> The problem is that Rust allows multiple variables to sequentially recycle
> the same name within a single source-level scope. I'm unfamiliar with the
> history here, but apparently handling that case without a new lexical_block
> confuses debuggers (or at least it used to).
> 
> https://github.com/rust-lang/rust/blob/
> c9f15013e0edc80989bf40b358bcefee14be5050/src/librustc_trans/debuginfo/
> create_scope_map.rs#L246
>     // LLVM does not properly generate 'DW_AT_start_scope' fields
>     // for variable DIEs. For this reason we have to introduce
>     // an artificial scope at bindings whenever a variable with
>     // the same name is declared in *any* parent scope.
> 
> (followed by an example of undesirable gdb behavior without the additional
> lexical_blocks)
> 
> Having said that, in my own tests I have seen rustc emit nested
> lexical_blocks even when the variables don't shadow anything, so there may
> be a rustc bug to improve here. 

Turns out the rustc implementation I was looking at was years out of date. After a 2016 rewrite rustc now adds a lexical_block even if the new variables don't shadow any old variables. Maybe that can be improved.
Comment 9 Jonas Devlieghere 2020-11-05 12:05:38 PST
Convert analyzeContextInfo to a work list: https://reviews.llvm.org/D90873
Comment 10 labath 2020-11-06 02:39:39 PST
Yea, I can see how multiple variables with the same name can be confusing. It sounds like it would be better if the rust compiler avoided creating these where it doesn't need to.

Unless, that is, there is something about rust syntax (which I know nearly nothing about) that actually makes creating a lexical block for each new variable actually the right thing to do. Though it that case, I suspect you may run into other components which behave suboptimally with this kind of input.