std: avoid pre-parsing dwarf info #3005

daurnimator · 2019-08-04T15:42:04Z

This pull request refactors debug.zig to not scan dwarf info. Instead the seekable stream is used directly to pull out info.

andrewrk · 2019-08-04T18:40:22Z

I tried this out with the assertion from #2957 and it hung in findCompileUnit, endless loop in while (this_unit_offset < debug_info_end) { (with master branch it does not hang)

daurnimator · 2019-08-05T04:39:30Z

@andrewrk I'll have a look tonight. Any other notes/comments on the changes in this PR?

daurnimator · 2019-08-05T14:52:12Z

Apologies for all the force pushes... I keep spying more memory leaks in std/debug.zig. Evidently the previous version of the code only expected to be run when everything was about to exit.

andrewrk · 2019-08-05T16:29:32Z

Evidently the previous version of the code only expected to be run when everything was about to exit.

Yes that's exactly true - the original version of this code had this assumption. It also has the assumption that it will only be called once. Fixing the leaks and this other assumption will require a full audit.

andrewrk · 2019-08-05T18:27:16Z

I tried this again with the same test case.

Master branch takes 5.244s and this branch takes 6.431s. Also master branch produces this trace, and this branch only produces one frame:

Assertion failed. This is a bug in the Zig compiler.
/home/andy/dev/zig/src-self-hosted/stage1.zig:37:5: 0xbfa569 in stage2_panic (userland)
    @panic(ptr[0..len]);
    ^
/home/andy/dev/zig/src/util.cpp:28:0: 0xbc41dd in assert (/home/andy/dev/zig/src/util.cpp)
        stage2_panic(msg, strlen(msg));

/home/andy/dev/zig/src/analyze.cpp:501:0: 0xbc6304 in get_pointer_to_type_extra (/home/andy/dev/zig/src/analyze.cpp)
        assert(byte_alignment == 0);

/home/andy/dev/zig/src/ir.cpp:14428:0: 0xb629d8 in ir_analyze_alloca (/home/andy/dev/zig/src/ir.cpp)
    result->base.value.type = get_pointer_to_type_extra(ira->codegen, var_type, false, false,

/home/andy/dev/zig/src/ir.cpp:14558:0: 0xb63066 in ir_resolve_result_raw (/home/andy/dev/zig/src/ir.cpp)
                    alloca_gen = ir_analyze_alloca(ira, result_loc->source_instruction, value_type, align,

/home/andy/dev/zig/src/ir.cpp:14728:0: 0xb63a65 in ir_resolve_result (/home/andy/dev/zig/src/ir.cpp)
            value, force_runtime, non_null_comptime);

/home/andy/dev/zig/src/ir.cpp:24352:0: 0xb86380 in ir_analyze_instruction_end_expr (/home/andy/dev/zig/src/ir.cpp)
            value->value.type, value, false, false, true);

/home/andy/dev/zig/src/ir.cpp:24799:0: 0xb877a2 in ir_analyze_instruction_base (/home/andy/dev/zig/src/ir.cpp)
            return ir_analyze_instruction_end_expr(ira, (IrInstructionEndExpr *)instruction);

/home/andy/dev/zig/src/ir.cpp:24862:0: 0xb87ae4 in ir_analyze (/home/andy/dev/zig/src/ir.cpp)
        IrInstruction *new_instruction = ir_analyze_instruction_base(ira, old_instruction);

/home/andy/dev/zig/src/analyze.cpp:3881:0: 0xbd0252 in analyze_fn_ir (/home/andy/dev/zig/src/analyze.cpp)
            &fn_table_entry->analyzed_executable, fn_type_id->return_type, return_type_node);

/home/andy/dev/zig/src/analyze.cpp:3967:0: 0xbd069f in analyze_fn_body (/home/andy/dev/zig/src/analyze.cpp)
    analyze_fn_ir(g, fn_table_entry, return_type_node);

/home/andy/dev/zig/src/analyze.cpp:4099:0: 0xbd0f53 in semantic_analyze (/home/andy/dev/zig/src/analyze.cpp)
            analyze_fn_body(g, fn_entry);

/home/andy/dev/zig/src/codegen.cpp:8557:0: 0xb25683 in gen_root_source (/home/andy/dev/zig/src/codegen.cpp)
        semantic_analyze(g);

/home/andy/dev/zig/src/codegen.cpp:9498:0: 0xb28c14 in codegen_build_and_link (/home/andy/dev/zig/src/codegen.cpp)
            gen_root_source(g);

/home/andy/dev/zig/src/main.cpp:1207:0: 0xb03b69 in main (/home/andy/dev/zig/src/main.cpp)
                codegen_build_and_link(g);

???:?:?: 0x7facfefcbb8d in ??? (???)


???:?:?: 0x266258d4c544154 in ??? (???)


Segmentation fault

vs

Assertion failed. This is a bug in the Zig compiler.
/home/andy/downloads/zig/src-self-hosted/stage1.zig:37:5: 0xf1ba99 in stage2_panic (userland)
    @panic(ptr[0..len]);
    ^
home/andy/downloads/zig/src/util.cpp:28:0: 0xee9b4f in assert (/home/andy/downloads/zig/src/util.cpp)
Unable to dump stack trace: FileNotFound
Aborted

daurnimator · 2019-08-06T02:14:48Z

std/debug.zig

-    const line_info_offset = try compile_unit.die.getAttrSecOffset(DW.AT_stmt_list);
+fn getLineNumberInfoDwarf(di: *DwarfInfo, compile_unit_die: Die, target_address: usize) !LineInfo {
+    const compile_unit_cwd = try compile_unit_die.getAttrString(di, di.allocator, DW.AT_comp_dir);
+    defer di.allocator.free(compile_unit_cwd);


TODO: this defer may be the cause of andrew's issue: I noticed the path in his short traceback is missing a leading /. Perhaps it got freed and set to 0xaa by compile_unit_cwd getting collected.

daurnimator · 2019-08-06T02:16:18Z

std/debug.zig

@@ -1439,6 +1468,11 @@ const LineNumberProgram = struct {
        };
    }

+    pub fn deinit(self: *LineNumberProgram) void {
+        self.include_dirs.deinit();


TODO: free .include_dirs members?

daurnimator · 2019-08-08T15:09:15Z

Master branch takes 5.244s and this branch takes 6.431s. Also master branch produces this trace, and this branch only produces one frame:

What do you get with the test case of the following?:

const std = @import("std");

pub fn main() void {
    std.debug.dumpCurrentStackTrace(@returnAddress());
}

With the test case from #2957 I get a fast full traceback in 1.32s (but no symbols... as my llvm library has been stripped). compared to 11 seconds with master (also no symbols due to stripping).

daurnimator · 2019-09-04T03:17:31Z

@n1tram1

andrewrk

Here's my test now:

#3454 (comment)

master: 0m7.338s

when analyzing /home/andy/Downloads/zig/build/test.zig:4:9: assertion failed. This is a bug in the Zig compiler.
/home/andy/Downloads/zig/src-self-hosted/stage1.zig:37:5: 0xfe2ccc in stage2_panic (userland)
    @panic(ptr[0..len]);
    ^
/home/andy/Downloads/zig/src/analyze.cpp:8898:0: 0xfc3367 in src_assert (/home/andy/Downloads/zig/src/analyze.cpp)
    stage2_panic(msg, strlen(msg));

/home/andy/Downloads/zig/src/ir.cpp:8363:0: 0xf267fb in ir_gen_node_extra (/home/andy/Downloads/zig/src/ir.cpp)
        src_assert(irb->exec->first_err_trace_msg != nullptr, node);

/home/andy/Downloads/zig/src/ir.cpp:3948:0: 0xf12d8e in ir_gen_assign (/home/andy/Downloads/zig/src/ir.cpp)
            &result_loc_inst->base);

/home/andy/Downloads/zig/src/ir.cpp:4180:0: 0xf13d14 in ir_gen_bin_op (/home/andy/Downloads/zig/src/ir.cpp)
            return ir_lval_wrap(irb, scope, ir_gen_assign(irb, scope, node), lval, result_loc);

/home/andy/Downloads/zig/src/ir.cpp:8211:0: 0xf25cd1 in ir_gen_node_raw (/home/andy/Downloads/zig/src/ir.cpp)
            return ir_gen_bin_op(irb, scope, node, lval, result_loc);

/home/andy/Downloads/zig/src/ir.cpp:8358:0: 0xf2678f in ir_gen_node_extra (/home/andy/Downloads/zig/src/ir.cpp)
    IrInstruction *result = ir_gen_node_raw(irb, node, child_scope, lval, result_loc);

/home/andy/Downloads/zig/src/ir.cpp:8369:0: 0xf26834 in ir_gen_node (/home/andy/Downloads/zig/src/ir.cpp)
    return ir_gen_node_extra(irb, node, scope, LValNone, nullptr);

/home/andy/Downloads/zig/src/ir.cpp:3828:0: 0xf125c0 in ir_gen_block (/home/andy/Downloads/zig/src/ir.cpp)
        IrInstruction *statement_value = ir_gen_node(irb, statement_node, child_scope);

/home/andy/Downloads/zig/src/ir.cpp:8207:0: 0xf25c87 in ir_gen_node_raw (/home/andy/Downloads/zig/src/ir.cpp)
            return ir_gen_block(irb, scope, node, lval, result_loc);

/home/andy/Downloads/zig/src/ir.cpp:8358:0: 0xf2678f in ir_gen_node_extra (/home/andy/Downloads/zig/src/ir.cpp)
    IrInstruction *result = ir_gen_node_raw(irb, node, child_scope, lval, result_loc);

/home/andy/Downloads/zig/src/ir.cpp:8401:0: 0xf269b6 in ir_gen (/home/andy/Downloads/zig/src/ir.cpp)
    IrInstruction *result = ir_gen_node_extra(irb, node, scope, LValNone, nullptr);

/home/andy/Downloads/zig/src/ir.cpp:8425:0: 0xf26b01 in ir_gen_fn (/home/andy/Downloads/zig/src/ir.cpp)
    return ir_gen(codegen, body_node, fn_entry->child_scope, ir_executable);

/home/andy/Downloads/zig/src/analyze.cpp:4593:0: 0xfb49ab in analyze_fn_body (/home/andy/Downloads/zig/src/analyze.cpp)
    ir_gen_fn(g, fn_table_entry);

/home/andy/Downloads/zig/src/analyze.cpp:4738:0: 0xfb5392 in semantic_analyze (/home/andy/Downloads/zig/src/analyze.cpp)
            analyze_fn_body(g, fn_entry);

/home/andy/Downloads/zig/src/codegen.cpp:9123:0: 0xef5dc7 in gen_root_source (/home/andy/Downloads/zig/src/codegen.cpp)
        semantic_analyze(g);

/home/andy/Downloads/zig/src/codegen.cpp:10095:0: 0xef9766 in codegen_build_and_link (/home/andy/Downloads/zig/src/codegen.cpp)
            gen_root_source(g);

/home/andy/Downloads/zig/src/main.cpp:1343:0: 0xecf976 in main (/home/andy/Downloads/zig/src/main.cpp)
                codegen_build_and_link(g);

???:?:?: 0x7ff9970a1b8d in ??? (???)


???:?:?: 0x6c66258d4c544154 in ??? (???)


Segmentation fault (core dumped)

this PR: 0m26.467s

when analyzing /home/andy/Downloads/zig/build/test.zig:4:9: assertion failed. This is a bug in the Zig compiler.
/home/andy/Downloads/zig/src-self-hosted/stage1.zig:37:5: 0xfe2ccc in stage2_panic (userland)
    @panic(ptr[0..len]);
    ^
home/andy/Downloads/zig/src/analyze.cpp:8898:0: 0xfc3367 in src_assert (/home/andy/Downloads/zig/src/analyze.cpp)
home/andy/Downloads/zig/src/ir.cpp:8363:0: 0xf267fb in ir_gen_node_extra (/home/andy/Downloads/zig/src/ir.cpp)
home/andy/Downloads/zig/src/ir.cpp:3948:0: 0xf12d8e in ir_gen_assign (/home/andy/Downloads/zig/src/ir.cpp)
home/andy/Downloads/zig/src/ir.cpp:4180:0: 0xf13d14 in ir_gen_bin_op (/home/andy/Downloads/zig/src/ir.cpp)
home/andy/Downloads/zig/src/ir.cpp:8211:0: 0xf25cd1 in ir_gen_node_raw (/home/andy/Downloads/zig/src/ir.cpp)
home/andy/Downloads/zig/src/ir.cpp:8358:0: 0xf2678f in ir_gen_node_extra (/home/andy/Downloads/zig/src/ir.cpp)
home/andy/Downloads/zig/src/ir.cpp:8369:0: 0xf26834 in ir_gen_node (/home/andy/Downloads/zig/src/ir.cpp)
home/andy/Downloads/zig/src/ir.cpp:3828:0: 0xf125c0 in ir_gen_block (/home/andy/Downloads/zig/src/ir.cpp)
home/andy/Downloads/zig/src/ir.cpp:8207:0: 0xf25c87 in ir_gen_node_raw (/home/andy/Downloads/zig/src/ir.cpp)
home/andy/Downloads/zig/src/ir.cpp:8358:0: 0xf2678f in ir_gen_node_extra (/home/andy/Downloads/zig/src/ir.cpp)
home/andy/Downloads/zig/src/ir.cpp:8401:0: 0xf269b6 in ir_gen (/home/andy/Downloads/zig/src/ir.cpp)
home/andy/Downloads/zig/src/ir.cpp:8425:0: 0xf26b01 in ir_gen_fn (/home/andy/Downloads/zig/src/ir.cpp)
home/andy/Downloads/zig/src/analyze.cpp:4593:0: 0xfb49ab in analyze_fn_body (/home/andy/Downloads/zig/src/analyze.cpp)
home/andy/Downloads/zig/src/analyze.cpp:4738:0: 0xfb5392 in semantic_analyze (/home/andy/Downloads/zig/src/analyze.cpp)
home/andy/Downloads/zig/src/codegen.cpp:9123:0: 0xef5dc7 in gen_root_source (/home/andy/Downloads/zig/src/codegen.cpp)
home/andy/Downloads/zig/src/codegen.cpp:10095:0: 0xef9766 in codegen_build_and_link (/home/andy/Downloads/zig/src/codegen.cpp)
home/andy/Downloads/zig/src/main.cpp:1343:0: 0xecf976 in main (/home/andy/Downloads/zig/src/main.cpp)
???:?:?: 0x7f9d00a33b8d in ??? (???)


???:?:?: 0x5f16258d4c544154 in ??? (???)


Segmentation fault (core dumped)

It's much slower and missing most of the useful content. Maybe I merged the conflicts incorrectly, let me know if I did.

I'll be happy to look at this again after you've demonstrated that you've tested on enough different cases to have confidence that it performs better, and doesn't cause any regressions.

daurnimator · 2019-10-26T02:03:29Z

I grabbed the sample you linked and put it into test/stage1/behavior/bugs/3464.zig:

With current master (3aeb1b1):

$ time ./zig test ../test/stage1/behavior/bugs/3464.zig
when analyzing /home/daurnimator/src/zig/test/stage1/behavior/bugs/3464.zig:4:9: assertion failed. This is a bug in the Zig compiler.
???:?:?: 0x55dc3b9bfcec in ??? (???)


???:?:?: 0x55dc3b99ed5f in ??? (???)


???:?:?: 0x55dc3b8fbab5 in ??? (???)


???:?:?: 0x55dc3b8e77c3 in ??? (???)


???:?:?: 0x55dc3b8e87d8 in ??? (???)


???:?:?: 0x55dc3b8faf83 in ??? (???)


???:?:?: 0x55dc3b8fba49 in ??? (???)


???:?:?: 0x55dc3b8fbaee in ??? (???)


???:?:?: 0x55dc3b8e6f49 in ??? (???)


???:?:?: 0x55dc3b8faf39 in ??? (???)


???:?:?: 0x55dc3b8fba49 in ??? (???)


???:?:?: 0x55dc3b8fbc85 in ??? (???)


???:?:?: 0x55dc3b8fbdf0 in ??? (???)


???:?:?: 0x55dc3b98f9a2 in ??? (???)


???:?:?: 0x55dc3b99043e in ??? (???)


???:?:?: 0x55dc3b8c97cb in ??? (???)


???:?:?: 0x55dc3b8cd560 in ??? (???)


???:?:?: 0x55dc3b8a118a in ??? (???)


???:?:?: 0x7f6ab7bdc152 in ??? (???)


???:?:?: 0x495641003d285b3c in ??? (???)


Segmentation fault (core dumped)

real	0m10.320s
user	0m5.307s
sys	0m2.033s

With this PR:

$ time ./zig test ../test/stage1/behavior/bugs/3464.zig 
when analyzing /home/daurnimator/src/zig/test/stage1/behavior/bugs/3464.zig:4:9: assertion failed. This is a bug in the Zig compiler.
???:?:?: 0x55eacdc7dedc in ??? (???)


???:?:?: 0x55eacdc5cf4f in ??? (???)


???:?:?: 0x55eacdbb9ca5 in ??? (???)


???:?:?: 0x55eacdba59b3 in ??? (???)


???:?:?: 0x55eacdba69c8 in ??? (???)


???:?:?: 0x55eacdbb9173 in ??? (???)


???:?:?: 0x55eacdbb9c39 in ??? (???)


???:?:?: 0x55eacdbb9cde in ??? (???)


???:?:?: 0x55eacdba5139 in ??? (???)


???:?:?: 0x55eacdbb9129 in ??? (???)


???:?:?: 0x55eacdbb9c39 in ??? (???)


???:?:?: 0x55eacdbb9e75 in ??? (???)


???:?:?: 0x55eacdbb9fe0 in ??? (???)


???:?:?: 0x55eacdc4db92 in ??? (???)


???:?:?: 0x55eacdc4e62e in ??? (???)


???:?:?: 0x55eacdb879bb in ??? (???)


???:?:?: 0x55eacdb8b750 in ??? (???)


???:?:?: 0x55eacdb5f37a in ??? (???)


???:?:?: 0x7fe0d4d4c152 in ??? (???)


???:?:?: 0x4956410009376b3c in ??? (???)


Segmentation fault (core dumped)

real	0m0.651s
user	0m0.370s
sys	0m0.073s

Now that wasn't useful I guess.... I'm not sure why neither traceback has symbols. What did you compile/run to get them? Are you using the self-hosted compiler? How?

I also moved `ncmd` into a shorter scope.

andrewrk · 2019-12-16T01:06:08Z

I'm not convinced this is an improvement. All 3 times I tested this, it was worse than status quo. If you do another pass at this, I want to see a more detailed analysis of why the code is better than status quo.

daurnimator force-pushed the fast-dwarf-traces branch from 0299bf8 to 9fb0149 Compare August 4, 2019 16:01

daurnimator added enhancement Solving this issue will likely involve adding new logic or components to the codebase. standard library This issue involves writing Zig code for the standard library. labels Aug 4, 2019

daurnimator force-pushed the fast-dwarf-traces branch 5 times, most recently from 219978a to c10eec5 Compare August 5, 2019 14:50

daurnimator mentioned this pull request Aug 5, 2019

Read traceback data from external debug info #3014

Closed

daurnimator commented Aug 6, 2019

View reviewed changes

andrewrk modified the milestones: 0.5.0, 0.6.0 Aug 19, 2019

andrewrk removed this from the 0.6.0 milestone Oct 1, 2019

andrewrk requested changes Oct 25, 2019

View reviewed changes

daurnimator force-pushed the fast-dwarf-traces branch from c10eec5 to 0dbe3d4 Compare October 26, 2019 02:01

daurnimator mentioned this pull request Nov 24, 2019

refactor std/debug.zig DwarfInfo operations to be methods #3764

Merged

daurnimator added 4 commits November 26, 2019 15:33

std.debug: factor out getPcRange to a Die method

808b7d8

std: avoid pre-parsing dwarf info

fcf0ea0

std: remove TODOs for rejected proposal ziglang#1403

7219386

I also moved `ncmd` into a shorter scope.

std: fix some memory leaks in traceback code

6ce630b

daurnimator force-pushed the fast-dwarf-traces branch from 0dbe3d4 to 6ce630b Compare November 26, 2019 07:09

andrewrk closed this Dec 16, 2019

daurnimator mentioned this pull request Feb 1, 2020

Fix double close in openElfDebugInfo #4345

Merged

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Uh oh!

Uh oh!

std: avoid pre-parsing dwarf info #3005

std: avoid pre-parsing dwarf info #3005

Uh oh!

daurnimator commented Aug 4, 2019

Uh oh!

andrewrk commented Aug 4, 2019 •

edited

Loading

Uh oh!

daurnimator commented Aug 5, 2019

Uh oh!

daurnimator commented Aug 5, 2019

Uh oh!

andrewrk commented Aug 5, 2019

Uh oh!

andrewrk commented Aug 5, 2019

Uh oh!

daurnimator Aug 6, 2019

Uh oh!

daurnimator Aug 6, 2019

Uh oh!

daurnimator commented Aug 8, 2019

Uh oh!

daurnimator commented Sep 4, 2019

Uh oh!

andrewrk left a comment

Uh oh!

daurnimator commented Oct 26, 2019 •

edited

Loading

Uh oh!

andrewrk commented Dec 16, 2019

Uh oh!

Uh oh!

Uh oh!

std: avoid pre-parsing dwarf info #3005

std: avoid pre-parsing dwarf info #3005

Uh oh!

Conversation

daurnimator commented Aug 4, 2019

Uh oh!

andrewrk commented Aug 4, 2019 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

daurnimator commented Aug 5, 2019

Uh oh!

daurnimator commented Aug 5, 2019

Uh oh!

andrewrk commented Aug 5, 2019

Uh oh!

andrewrk commented Aug 5, 2019

Uh oh!

daurnimator Aug 6, 2019

Choose a reason for hiding this comment

Uh oh!

daurnimator Aug 6, 2019

Choose a reason for hiding this comment

Uh oh!

daurnimator commented Aug 8, 2019

Uh oh!

daurnimator commented Sep 4, 2019

Uh oh!

andrewrk left a comment

Choose a reason for hiding this comment

master: 0m7.338s

this PR: 0m26.467s

Uh oh!

daurnimator commented Oct 26, 2019 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

andrewrk commented Dec 16, 2019

Uh oh!

Uh oh!

andrewrk commented Aug 4, 2019 •

edited

Loading

daurnimator commented Oct 26, 2019 •

edited

Loading