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

Rust function of sufficient length prevents breakpoints from working #47373

Closed
dan-fritchman opened this issue Oct 31, 2020 · 12 comments
Closed
Assignees
Labels
bugzilla Issues migrated from bugzilla llvm-tools All llvm tools that do not have corresponding tag

Comments

@dan-fritchman
Copy link

Bugzilla Link 48029
Resolution FIXED
Resolved on Nov 07, 2020 10:55
Version trunk
OS MacOS X
CC @adrian-prantl,@fredriss,@JDevlieghere,@jimingham,@labath

Extended Description

Following up on an issue originally reported to the VsCode plug-in CodeLLDB:
vadimcn/codelldb#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.

@dan-fritchman
Copy link
Author

assigned to @JDevlieghere

@jimingham
Copy link
Collaborator

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

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.

@dan-fritchman
Copy link
Author

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?

@labath
Copy link
Collaborator

labath commented Nov 2, 2020

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)....

@dan-fritchman
Copy link
Author

This is now:
rust-lang/rust#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.

@llvmbot
Copy link
Collaborator

llvmbot commented Nov 5, 2020

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.)

@labath
Copy link
Collaborator

labath commented Nov 5, 2020

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.

@llvmbot
Copy link
Collaborator

llvmbot commented Nov 5, 2020

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.

@llvmbot
Copy link
Collaborator

llvmbot commented Nov 5, 2020

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.

@JDevlieghere
Copy link
Member

Convert analyzeContextInfo to a work list: https://reviews.llvm.org/D90873

@labath
Copy link
Collaborator

labath commented Nov 6, 2020

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.

@JDevlieghere
Copy link
Member

@llvmbot llvmbot transferred this issue from llvm/llvm-bugzilla-archive Dec 10, 2021
This issue was closed.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bugzilla Issues migrated from bugzilla llvm-tools All llvm tools that do not have corresponding tag
Projects
None yet
Development

No branches or pull requests

5 participants