Debug Quality Tracker

[Keno]

I've started working on debug info quality. This will likely be a rather long process with many subparts, but this issues is intended to serve as an umbrella issue for testcases/TODOs/etc. For now I'm planning to paste test cases directly into comments here, but if that gets unwieldy, I'll move them to gist.

[Keno]

Currently jlcall parameters terminate at the first call because they reference the argument register.
Test case:

begin  # LineEdit.jl, line 1441:
    return history_prev_prefix(data,(top(getfield))((top(getfield))(data,:histprompt),:hp),(top(getfield))(data,:prefix))
end

define %jl_value_t* @julia_anonymous_21645(%jl_value_t*, %jl_value_t**, i32) #0 !lam !15 {
top:
  call void @llvm.stackprotector(i8* %StackGuard, i8** %StackGuardSlot), !dbg !16
  call void @llvm.dbg.value(metadata %jl_value_t** %1, i64 0, metadata !17, metadata !18), !dbg !16
  call void @llvm.dbg.value(metadata %jl_value_t** %1, i64 0, metadata !19, metadata !20), !dbg !16
  call void @llvm.dbg.value(metadata %jl_value_t** %1, i64 0, metadata !21, metadata !22), !dbg !16
  %3 = alloca %jl_value_t*, i32 6
  %4 = getelementptr %jl_value_t*, %jl_value_t** %3, i32 2, !dbg !16  
  [snip]
  br i1 %14, label %ifcont, label %else, !dbg !16

else:                                             ; preds = %top
  call void @jl_error(i8* getelementptr inbounds ([26 x i8], [26 x i8]* @_j_str25, i32 0, i32 0)), !dbg !16
  unreachable, !dbg !16

ifcont:                                           ; preds = %top
  %const = bitcast i64 13008184512 to i64, !dbg !23
  call void @llvm.dbg.value(metadata %jl_value_t** %1, i64 0, metadata !17, metadata !18), !dbg !16
  call void @llvm.dbg.value(metadata %jl_value_t** %1, i64 0, metadata !19, metadata !20), !dbg !16
  call void @llvm.dbg.value(metadata %jl_value_t** %1, i64 0, metadata !21, metadata !22), !dbg !16
  [snip]
  call void @llvm.dbg.declare(metadata %jl_value_t** %4, metadata !19, metadata !18), !dbg !23
  [snip]
  ; Debug Info Terminates here (see below)
  %24 = call %jl_value_t* @jl_f_get_field(%jl_value_t* null, %jl_value_t** %23, i32 2), !dbg !23
  [snip]
}

Debug Info for anonymous
Parameters:
 - s
 - data
 - c
0x0000000000000000: pushq   %rbp                      x x x
0x0000000000000001: pushq   %r15                      | | |
0x0000000000000003: pushq   %r14                      | | |
0x0000000000000005: pushq   %r13                      | | |
0x0000000000000007: pushq   %r12                      | | |
0x0000000000000009: pushq   %rbx                      | | |
0x000000000000000a: subq    $56, %rsp                 | | |
0x000000000000000e: movabsq $140735116509296, %rax    | | |
0x0000000000000018: movq    (%rax), %rax              | | |
0x000000000000001b: movq    %rax, 48(%rsp)            | | |
0x0000000000000020: movq    $8, (%rsp)                | | |
0x0000000000000028: movabsq $4357094304, %r12         | | |
0x0000000000000032: movq    (%r12), %rax              | | |
0x0000000000000036: movq    %rax, 8(%rsp)             | | |
0x000000000000003b: leaq    (%rsp), %rax              | | |
0x000000000000003f: movq    %rax, (%r12)              | | |
0x0000000000000043: vxorps  %xmm0, %xmm0, %xmm0       | | |
0x0000000000000047: vmovups %xmm0, 32(%rsp)           | | |
0x000000000000004d: vmovups %xmm0, 16(%rsp)           | | |
0x0000000000000053: cmpl    $3, %edx                  | | |
0x0000000000000056: jne     204                       | | |
0x000000000000005c: leaq    16(%rsp), %r14            | | |
0x0000000000000061: movq    8(%rsi), %rbx             | | |
0x0000000000000065: movq    %rbx, (%r14)              | | |
0x0000000000000068: movq    %rbx, 24(%rsp)            | | |
0x000000000000006d: movabsq $13008184512, %rbp        | | |
0x0000000000000077: leaq    34560(%rbp), %rax         | | |
0x000000000000007e: movq    %rax, 32(%rsp)            | | |
0x0000000000000083: leaq    8(%r14), %r13             | | |
0x0000000000000087: movabsq $4354511040, %r15         | | |
0x0000000000000091: xorl    %edi, %edi                | | |
0x0000000000000093: movl    $2, %edx                  | | |
0x0000000000000098: movq    %r13, %rsi                x x x
0x000000000000009b: callq   *%r15
0x000000000000009e: movq    %rax, 24(%rsp)
0x00000000000000a3: leaq    34896(%rbp), %rax
0x00000000000000aa: movq    %rax, 32(%rsp)
0x00000000000000af: xorl    %edi, %edi
0x00000000000000b1: movl    $2, %edx
0x00000000000000b6: movq    %r13, %rsi
0x00000000000000b9: callq   *%r15
0x00000000000000bc: movq    %rax, 24(%rsp)
0x00000000000000c1: movq    %rbx, 32(%rsp)
0x00000000000000c6: movq    %rbp, 40(%rsp)
0x00000000000000cb: leaq    16(%r14), %rsi
0x00000000000000cf: xorl    %edi, %edi
0x00000000000000d1: movl    $2, %edx
0x00000000000000d6: callq   *%r15
0x00000000000000d9: movq    %rax, 32(%rsp)
0x00000000000000de: movabsq $4354452720, %rax
0x00000000000000e8: movabsq $4402566448, %rdi
0x00000000000000f2: movl    $3, %edx
0x00000000000000f7: movq    %r14, %rsi
0x00000000000000fa: callq   *%rax
0x00000000000000fc: movq    8(%rsp), %rcx
0x0000000000000101: movq    %rcx, (%r12)
0x0000000000000105: movabsq $140735116509296, %rcx
0x000000000000010f: movq    (%rcx), %rcx
0x0000000000000112: cmpq    48(%rsp), %rcx
0x0000000000000117: jne 37
0x0000000000000119: addq    $56, %rsp
0x000000000000011d: popq    %rbx
0x000000000000011e: popq    %r12
0x0000000000000120: popq    %r13
0x0000000000000122: popq    %r14
0x0000000000000124: popq    %r15
0x0000000000000126: popq    %rbp
0x0000000000000127: retq
0x0000000000000128: movabsq $13259796480, %rdi
0x0000000000000132: movabsq $4354496336, %rax
0x000000000000013c: callq   *%rax
0x000000000000013e: movabsq $140735472325644, %rax
0x0000000000000148: callq   *%rax

Needs to be fixed in LLVM most likely.

[yuyichao]

FWIW I suspect merging GC frame in #11508 will break certain debug info created by make_gcroot. (Edit: which is one of the reasons I think it's not ready to be merged yet)

[aviks]

Are you looking for examples where local variables are not shown? I have one:

https://gist.github.com/aviks/ad207b71e514ffe79c13

(Note: this is on OSX, where we get a segfault on running that test. No segfault in linux)

Let me know if you need any more info.

EDIT: This is with DISABLE_OPT defined

[Keno]

We have bad debug info in the error paths of most functions because variables get clobbered by the arguments to the throw function. Not quite sure how to fix this yet. Maybe we can do some sort of stack dump before proceeding.

Example:

Debug Info for sqrt
Parameters:
 - x
0x0000000000000000:pushq     %rax                      x
0x0000000000000001:testq     %rdi, %rdi                |
0x0000000000000004:js        11                        |
0x0000000000000006:cvtsi2sdq %rdi, %xmm0               |
0x000000000000000b:sqrtsd    %xmm0, %xmm0              |
0x000000000000000f:popq      %rax                      |
0x0000000000000010:retq                                x
0x0000000000000011:movabsq   $140593633984248, %rax
0x000000000000001b:movq      (%rax), %rdi
0x000000000000001e:movabsq   $140593630660592, %rax
0x0000000000000028:movl      $139, %esi
0x000000000000002d:callq     *%rax
0x000000000000002f:nop

[Keno]

My current evil plan for fixing the second case is to do the following:

fail:                                             ; preds = %top
  call void @jl_stackspill(), !dbg 17
  %2 = load %jl_value_t*, %jl_value_t** @jl_domain_exception, align 8, !dbg !17, !tbaa !19
  call void @jl_throw_with_superfluous_argument(%jl_value_t* %2, i32 139), !dbg !17
  unreachable, !dbg !17

Where jl_stackspill is an assembly routine that just dumps the current register state to the stack.
jl_throw can then pick that up and with appropriate DWARF magic pretend to the debugger that it returns at the location of jl_stackspill while at the same time giving the debugger full register information. Anybody have any better ideas?

[KristofferC]

Is this still relevant?

[KristofferC]

One year later, closing due to inactivity.

[vtjnash]

It's been largely fixed now (with the right -g and/or -O flags)