Long Functions Cause Invalid DWARF, Debug/ Breaking Unavailable

[dan-fritchman]

Including long functions appears to cause rustc to create invalid DWARF debug files. This leaves debugging and break-pointing unavailable. Debugging fails throughout the program, not just in the long functions.

Originally uncovered while porting (someone else's!) C code, which included a function of about 5k LOC. Also reproduced with macro-generated long methods. A minimal example is available here:
https://github.com/dan-fritchman/DwDemo

Previously reported this to LLDB, whose maintainers helped point out that the DWARF files appear invalid. Building from a fresh clone of that demo repo -

DwDemo $ cargo build
   Compiling dwdemo v0.0.1 (/Users/dan/dev/HW21/DwDemo)
    Finished dev [unoptimized + debuginfo] target(s) in 8.50s
DwDemo $ dwarfdump --debug-line target/debug/dwdemo.dSYM 
error: target/debug/dwdemo.dSYM/Contents/Resources/DWARF/dwdemo: The file was not recognized as a valid object file

The demo's macros expand to a few similar-length functions, about 5-6k LOC. Shortening them (via shortening the structure/ schema files) causes dwarfdump and lldb to be happy with rustc's output -

DwDemo $ cargo build          
   Compiling dwdemo v0.0.1 (/Users/dan/dev/HW21/DwDemo)
    Finished dev [unoptimized + debuginfo] target(s) in 4.11s
DwDemo $ dwarfdump --debug-line target/debug/dwdemo.dSYM | head -n 30
target/debug/dwdemo.dSYM/Contents/Resources/DWARF/dwdemo:       file format Mach-O 64-bit x86-64

.debug_line contents:
debug_line[0x00000000]
Line table prologue:
    total_length: 0x000000ca
         version: 2
 prologue_length: 0x00000075
 min_inst_length: 1
 default_is_stmt: 1
       line_base: -5
      line_range: 14
     opcode_base: 13
standard_opcode_lengths[DW_LNS_copy] = 0
standard_opcode_lengths[DW_LNS_advance_pc] = 1
standard_opcode_lengths[DW_LNS_advance_line] = 1
standard_opcode_lengths[DW_LNS_set_file] = 1
standard_opcode_lengths[DW_LNS_set_column] = 1
standard_opcode_lengths[DW_LNS_negate_stmt] = 0
standard_opcode_lengths[DW_LNS_set_basic_block] = 0
standard_opcode_lengths[DW_LNS_const_add_pc] = 0
standard_opcode_lengths[DW_LNS_fixed_advance_pc] = 1
standard_opcode_lengths[DW_LNS_set_prologue_end] = 0
standard_opcode_lengths[DW_LNS_set_epilogue_begin] = 0
standard_opcode_lengths[DW_LNS_set_isa] = 1
include_directories[  1] = "/Users/dan/.rustup/toolchains/stable-x86_64-apple-darwin/lib/rustlib/src/rust/src/libstd"
file_names[  1]:
           name: "rt.rs"
      dir_index: 1
       mod_time: 0x00000000

All of that was run on MacOS with the stable rust toolchain.

DwDemo $ rustup show
Default host: x86_64-apple-darwin
rustup home:  /Users/dan/.rustup

installed toolchains
--------------------

stable-x86_64-apple-darwin (default)
nightly-x86_64-apple-darwin

active toolchain
----------------

stable-x86_64-apple-darwin (default)
rustc 1.46.0 (04488afe3 2020-08-24)

Thanks for all of the team's work on this project.
Please let me know if there's any further info I can provide.

[gparker42]

Couldn't reproduce with rustc 1.46.0 nor 1.49.0-nightly (ffa2e7a 2020-10-24). dwarfdump --debug-line and dwarfdump --verify found nothing wrong with dwdemo.dSYM.

But I'm running a pretty old Xcode version (10.1 10B61). Dan, which Xcode version are you using (xcodebuild --version) ?

[dan-fritchman]

Sorry, that's my mistake, I pushed the "fixed" version.
Now including the working and failing versions on two branches:

• https://github.com/dan-fritchman/DwDemo/tree/fails - failing version
• https://github.com/dan-fritchman/DwDemo/tree/works - working version

master is also now even with fails, so pulling it should also get you the failing version.
Differences between the two (dan-fritchman/DwDemo@works...fails) are just the inclusion or exclusion of fields from the data-schema.

As for tools versions - I only have the Xcode command-line tools, here's their version -

$ xcodebuild --version
xcode-select: error: tool 'xcodebuild' requires Xcode, but active developer directory '/Library/Developer/CommandLineTools' is a command line tools instance
$ xcode-select --version
xcode-select version 2373.

[gparker42]

Couldn't reproduce using the updated DwDemo with Xcode 10.1 on Mojave. xcode-select version 2373 appears to be Xcode 12; I'll try that next. (Maybe something in dsymutil has changed?)

[gparker42]

Aha, here's something:

Xcode 10.1: no errors

Xcode 12.1: dsymutil crashes while compiling dwdemo. That crash leaves behind a malformed dwdemo.dSYM. Dan, I bet you'll see a bunch of dsymutil crashes in the Crash Reports section of Console.app.

rust version seems to have no effect: 1.46.0, 1.47.0, and a recent nightly all do the same thing.

There are at least two bugs here:
The first bug is the dsymutil crash itself, probably a regression in dsymutil since Xcode 10.1.
The second bug is that rustc is reporting a successful build even though its invocation of dsymutil crashed.
There may be a third bug, if dsymutil is crashing because the debug info emitted by llvm or rustc is invalid.

[gparker42]

Single-threaded dsymutil does not crash and seems to generate a valid dSYM file. This might be a clumsy workaround:

1. Run cargo build --verbose. This runs dsymutil which crashes.
2. Re-run the last rustc command with -Z run-dsymutil=no. This doesn't run dsymutil and saves the object files that dsymutil needs.
3. Run dsymutil manually with dsymutil --num-threads 1 /path/to/DwDemo/target/debug/dwdemo. This generates the dSYM file, hopefully without crashing.

[gparker42]

So here's what's going on.

The generated dwdemo.rs file contains a large struct Bsim4Model. Bsim4Model has derive(::prost::Message). Part of that derivation is a generated fmt() for trait fmt::Debug, similar to the one generated by derive(Debug).

The fmt() function generated by prost declares almost 900 variables called builder, one for each field of Bsim4Model:

...
let builder = { let wrapper = &self.capmod; builder.field("capmod", &wrapper) };
let builder = { let wrapper = &self.diomod; builder.field("diomod", &wrapper) };
let builder = { let wrapper = &self.rdsmod; builder.field("rdsmod", &wrapper) };
...

fmt() thus has almost 900 nested lexical scopes, one for each builder. The debug info for fmt() encodes these scopes as nested DW_TAG_lexical_block.

dsymutil processes DW_TAG_lexical_block with a simple recursive function analyzeContextInfo. If they are nested too deeply it runs out of stack space and crashes. That's the crash seen here.

When running with --num-threads 1 it uses the main thread's stack; that stack is 8MB by default, which is enough to process these scopes. When running with more than one thread the threads in the thread pool have stacks that are only 512 KB each, which is not enough for these scopes.

Xcode 10's dsymutil may have pre-dated the current llvm-based implementation, so it may have not used recursion, or may have used a larger thread stack, or may have used its thread stack efficiently enough to handle this debug info without crashing.

tl;dr the bugs are:

• prost should generate fmt() implementations with less nested debug info
• dsymutil should process DIEs using code that isn't recursive and/or set its thread pool to use larger stacks
• rustc should fail when dsymutil crashes

[gparker42]

Dan, can you file the bug report for prost? The patch for prost-derive might just be this. It compiles DwDemo and doesn't crash dsymutil, but I haven't tried to run the generated fmt().

--- a/src/lib.rs	2020-01-16 09:29:57.000000000 -0800
+++ b/src/lib.rs	2020-11-04 10:57:27.000000000 -0800
@@ -163,10 +163,10 @@
             quote!(builder.field(&wrapper))
         };
         quote! {
-             let builder = {
+             {
                  let wrapper = #wrapper;
                  #call
-             };
+             }
         }
     });
     let debug_builder = if is_struct {

[gparker42]

rustc shouldn't ignore dsymutil failures: #78770
dsymutil should allow more deeply nested DIEs: https://bugs.llvm.org/show_bug.cgi?id=48029

[wesleywiser]

Visited during wg-debugging triage. It looks like all of the components of the reported issue have been resolved already. Thanks @gparker42 for investigating and reporting the individual issues!

Assigning to @davidtwco to re-test and confirm this is resolved.