search

llvm / llvm-project

The LLVM Project is a collection of modular and reusable compiler and toolchain technologies.
http://llvm.org
Other
28.62k stars 11.83k forks source link

[DebugInfo] Lifetime of function arguments is too short in optimized code. #39063

Closed llvmbot closed 2 years ago

llvmbot commented 5 years ago
Bugzilla Link 39715
Resolution FIXED
Resolved on Jul 25, 2020 12:25
Version trunk
OS All
Depends On llvm/llvm-project#44998
Blocks llvm/llvm-project#38116
Reporter LLVM Bugzilla Contributor
CC @asl,@adrian-prantl,@dwblaikie,@djtodoro,@echristo,@fredriss,@JDevlieghere,@jmorse,@jdm,@walkerkd,@pogo59,@rnk,@tbosch,@vedantk

Extended Description

Same test case as before:

attribute((noinline)) int fn1 (long int x, long int y, long int z) { int l = x 2; int q = y z; return l + q; }

attribute((noinline)) long int fn2 (long int a, long int b, long int c) { long int q = 2 * a; return fn1 (5, 6, 7); }

int main(void) { return fn2(14, 23, 34); }

(built with -O3 -g). lldb session:

Process 30254 stopped

tbosch commented 2 years ago

mentioned in issue llvm/llvm-bugzilla-archive#46848

tbosch commented 2 years ago

mentioned in issue llvm/llvm-project#44998

tbosch commented 4 years ago

Created llvm/llvm-bugzilla-archive#46848 to track the remaining cleanup work. Closing this issue.

djtodoro commented 4 years ago

Vedant, while I am trying to land the narrow fix, could you outline the more involved real fix of getting rid of the duplicate DBG_VALUEs for COPYs?

Especially the part about:

try to make up for any loss in location coverage by making generic improvements to LiveDebugValues.

I saw that you pinged me on https://reviews.llvm.org/D80684. Would removing EntryValueCopyBackupKind from EntryDebugValues be the only required fix?

Also, how could I test that the eventual fix doesn't loose location coverage? Do you have specific test cases in mind?

Sorry for the delayed response.

What I had in mind was deleting "LiveInMap" from SelectionDAGISel::runOnMachineFunction (and everything that uses it). I tried this on a lark before commenting on 2020-05-01 and found that this resulted in ~15 or so test failures during check-llvm. Some of these are tests that are being overly strict about what they match -- these can be fixed up by mechanically updating the check lines. But others represent real regressions in location coverage.

AIUI, it should be the job of LiveDebugValues::transferRegisterCopy to track when a copy introduces a backup location for a variable, /not/ the job of the instruction selector. So (and I'm hand-waving a bit here), if we can fix the tests that regress by making transferRegisterCopy more aggressive, that could be a nice, general improvement.

My impression goes in the same way. I think the LiveDebugValues::transferRegisterCopy() should track all these copies.

As for measuring changes in location coverage, you can compile a stage2 clang binary with vs. without your changes, and use llvm-dwarfdump --statistics to collect location coverage stats.

Btw, my understanding of Djordje's comment in https://reviews.llvm.org/D80684 is that EntryValueCopyBackupKind is a hack invented to work around SelectionDAG's insertion of DBG_VALUEs after copies in the entry block. We might be able to delete EntryValueCopyBackupKind after changing SelectionDAG, but not before. Yes. That piece of code from the SelectionDAG violates the premise (before LiveDebugValues) that each DBG_VALUE represents assignment of a variable (and changing of its value potentially); so the EntryValueCopyBackupKind is used to track these copies from SelectionDAG.

vedantk commented 4 years ago

Btw, my understanding of Djordje's comment in https://reviews.llvm.org/D80684 is that EntryValueCopyBackupKind is a hack invented to work around SelectionDAG's insertion of DBG_VALUEs after copies in the entry block. We might be able to delete EntryValueCopyBackupKind after changing SelectionDAG, but not before.

vedantk commented 4 years ago

Vedant, while I am trying to land the narrow fix, could you outline the more involved real fix of getting rid of the duplicate DBG_VALUEs for COPYs?

Especially the part about:

try to make up for any loss in location coverage by making generic improvements to LiveDebugValues.

I saw that you pinged me on https://reviews.llvm.org/D80684. Would removing EntryValueCopyBackupKind from EntryDebugValues be the only required fix?

Also, how could I test that the eventual fix doesn't loose location coverage? Do you have specific test cases in mind?

Sorry for the delayed response.

What I had in mind was deleting "LiveInMap" from SelectionDAGISel::runOnMachineFunction (and everything that uses it). I tried this on a lark before commenting on 2020-05-01 and found that this resulted in ~15 or so test failures during check-llvm. Some of these are tests that are being overly strict about what they match -- these can be fixed up by mechanically updating the check lines. But others represent real regressions in location coverage.

AIUI, it should be the job of LiveDebugValues::transferRegisterCopy to track when a copy introduces a backup location for a variable, /not/ the job of the instruction selector. So (and I'm hand-waving a bit here), if we can fix the tests that regress by making transferRegisterCopy more aggressive, that could be a nice, general improvement.

As for measuring changes in location coverage, you can compile a stage2 clang binary with vs. without your changes, and use llvm-dwarfdump --statistics to collect location coverage stats.

tbosch commented 4 years ago

Vedant, while I am trying to land the narrow fix, could you outline the more involved real fix of getting rid of the duplicate DBG_VALUEs for COPYs?

Especially the part about:

try to make up for any loss in location coverage by making generic improvements to LiveDebugValues.

I saw that you pinged me on https://reviews.llvm.org/D80684. Would removing EntryValueCopyBackupKind from EntryDebugValues be the only required fix?

Also, how could I test that the eventual fix doesn't loose location coverage? Do you have specific test cases in mind?

tbosch commented 4 years ago

Vedant, sorry, this took a bit, but here is the change: https://reviews.llvm.org/D80819

I just took your patch and added a test for it. No other tests seem to have been affected by the change.

Could you have a look? Thanks!

vedantk commented 4 years ago

@​Tobias Ah, I didn't mean to hijack this thread. If you're still able to drive this forward, I think that'd be great. (Unfortunately I'm not sure I have the bandwidth to do so.)

To summarize things a bit, I see at least two possible solutions, and I suspect folks would be fine with either:

tbosch commented 4 years ago

@​Vedant: Would you like to take over this bug, as you clearly know more about the required fix than I do? Alternatively, I could try to start with your patch and see which tests fail...

jmorse commented 4 years ago

Djordje wrote:

I remember we discussed about removing this when we were implementing the debug entry values support within LiveDebugValues pass. Only deleting that piece of code causes some tests failures and we did not take an in-depth analysis back then.

Ah yeah, I remember, at the time I reckoned the physreg argument location needed to be specified differently to the vreg location for some reason. I think the explanation above is probably closer to the truth,

Yes, I think the LiveDebugValues pass can handle the copies properly. Having that implemented, we can simplify the support for entry values within that pass. These extra DBG_VALUEs (that comes from the SelcetionDAG) before LiveDebugValues volatile the assumption "every dbg_value indicates new value within the MBB for the variable", so we needed to handle it as well.

Removing some of those workarounds would be great, they make up a large portion of LiveDebugValues.

djtodoro commented 4 years ago

Sorry, I have missed this, because I have changed my email address.

@​Jeremy

[0] https://github.com/llvm/llvm-project/blob/446082b99f0bd9786d24edd3cd598dc4e5f64371/llvm/lib/CodeGen/SelectionDAG/SelectionDAGISel.cpp#L572

I remember we discussed about removing this when we were implementing the debug entry values support within LiveDebugValues pass. Only deleting that piece of code causes some tests failures and we did not take an in-depth analysis back then.

@​Vedant

If we can get away with deleting that whole chunk of SelectionDAG, and have a later pass do it right, that seems like the best outcome.

Yes, I think the LiveDebugValues pass can handle the copies properly. Having that implemented, we can simplify the support for entry values within that pass. These extra DBG_VALUEs (that comes from the SelcetionDAG) before LiveDebugValues volatile the assumption "every dbg_value indicates new value within the MBB for the variable", so we needed to handle it as well.

vedantk commented 4 years ago

Add the missing width check to SelectionDAG Thanks for finding this Jeremy! I've attached a patch which adds the missing width check to SelectionDAG. This seems to 'fix' the problem :)

Looking through the radar history from [2] (rdar://8412415), I see that the logic to add DBG_VALUEs after copies was added to SelectionDAG in an attempt to address an optimized code debugging regression. The kernel engineers who filed the radar (circa the iOS 4.1 release.. so a lot has changed since then!) didn't seem to think the change was particularly effective.

If we can get away with deleting that whole chunk of SelectionDAG, and have a later pass do it right, that seems like the best outcome.

jmorse commented 4 years ago

"but make the argument value available in the rest of the function in a vreg," if there was more than one block, of course.

jmorse commented 4 years ago

Hi Tobias, thanks for digging into this and all the reproducers!,

The X86DAGToDAGISel pass seems to be creating the DBG_VALUES. And it seems to produce too many COPY operations:

NB: I think (90% confidence) isel deliberately avoids optimising the number of COPYs created, and instead lets the register allocate handle that,

Vedant wrote:

What I'd love to understand is why that DEBUG_VALUE: fn1:z <- $edi gets created in the first place. That just seems wrong. If we can prevent that from happening, we don't need to have later passes clean things up ex post facto

It looks like those DBG_VALUEs, and in fact all the DBG_VALUEs of the argument value, originate from here [0]. dbg.value intrinsics for arguments get picked out of SelectionDAGBuilder in EmitFuncArgumentDbgValue, joined up with the ABIs argument location, and then inserted by [0]. The loop on line 614 is what's generating additional DBG_VALUEs for copies.

Exactly why this code path exists is a bit of a mystery to me; I would imagine it's something to do with past limitations on tracking variable locations. Without this code, SelectionDAG would attach the argument dbg.value to a CopyFromReg(rdi), but make the argument value available in the rest of the function in a vreg, via something like this pseudo-dag: t1 = CopyFromReg(rdi) t2, ch = CopyToReg(t1, %0) If %0 wasn't allocated to $rdi, the variable location would have to follow the copy to reach the rest of the function; and this might have been a serious problem in the past. The commit messages of [1, 2], which add large portions of the code at [0] appear to have that as a motivation.

Today, LiveDebugValues can /probably/ propagate the variable location through such a COPY, although there are various circumstances where it won't.

[0] https://github.com/llvm/llvm-project/blob/446082b99f0bd9786d24edd3cd598dc4e5f64371/llvm/lib/CodeGen/SelectionDAG/SelectionDAGISel.cpp#L572 [1] https://reviews.llvm.org/rG1b08572a665402ce57771507b3bcbe235ff1ba82 [2] https://reviews.llvm.org/rG99ff76212a0b38ceae924b3a739a8cc6a132624a

tbosch commented 4 years ago

Filed llvm/llvm-project#44998 regarding the lldb bugs.

tbosch commented 4 years ago

Ok sounds good.

Will look into the following then (probably in this order):

1) Why X86DAGToDAGISel associates the 32bit DBG_VALUE with "z" (DBG_VALUE %1:gr32, $noreg, !"z", ...) 2) Find a way to remove the DBG_VALUEs when the COPYs are folded (in RegisterCoalescer and VirtRegMap) 3) Why lldb shows the wrong values for DWARF4

vedantk commented 4 years ago

What I'd love to understand is why that DEBUG_VALUE: fn1:z <- $edi gets created in > the first place. That just seems wrong. If we can prevent that from happening, we don't need to have later passes clean things up ex post facto

As far as I understand it, this DEBUG_VALUE is created like this:

Fn1 takes a long, and the result of the multiplication is stored in an int variable. So X86DAGToDAGISel emits a COPY that uses a register subindex for 32bits, which through the following passes (Simple Register Coalescing, Virtual Register Rewriter) gets inlined into the multiplication as $edi (see the IR dumps above).

So do you refer to the fact that X86DAGToDAGISel emits these extra COPYs? I.e.: DBG_VALUE $rdi, $noreg, !"z", ... %0:gr64 = COPY $rdi

DBG_VALUE %0:gr64, $noreg, !"z", ... %1:gr32 = COPY %0.sub_32bit:gr64

DBG_VALUE %1:gr32, $noreg, !"z", ...

Yes: to be clear, the COPY instructions are fine, but the DBG_VALUE emitted for the copy is bogus (DBG_VALUE %1:gr32, $noreg, !"z", ...).

It's not always true that "z" is equal to the lower 32-bits of "z".

There are probably good reasons for emitting a DBG_VALUE after each COPY; maybe this helps with location availability when the source register gets killed but the copied register stays alive. But I think whatever logic is inserting those DBG_VALUEs is missing a width check.

tbosch commented 4 years ago

Btw, if I change the simplified example to use long in all places, there is no problem either.

tbosch commented 4 years ago

What I'd love to understand is why that DEBUG_VALUE: fn1:z <- $edi gets created in > the first place. That just seems wrong. If we can prevent that from happening, we don't need to have later passes clean things up ex post facto

As far as I understand it, this DEBUG_VALUE is created like this:

Fn1 takes a long, and the result of the multiplication is stored in an int variable. So X86DAGToDAGISel emits a COPY that uses a register subindex for 32bits, which through the following passes (Simple Register Coalescing, Virtual Register Rewriter) gets inlined into the multiplication as $edi (see the IR dumps above).

So do you refer to the fact that X86DAGToDAGISel emits these extra COPYs? I.e.: DBG_VALUE $rdi, $noreg, !"z", ... %0:gr64 = COPY $rdi

DBG_VALUE %0:gr64, $noreg, !"z", ... %1:gr32 = COPY %0.sub_32bit:gr64

DBG_VALUE %1:gr32, $noreg, !"z", ... %2:gr32 = IMUL32rr %1:gr32(tied-def 0), %1:gr32, ...

vedantk commented 4 years ago

While debugging, I also found the following problems in lldb:

1) lldb with dwarf4 uses DW_OP_GNU_entry_value, but doesn't save the value at the beginning of the function

Using clang -g produces dwarf4 (with DW_OP_GNU_entry_value instead of DW_OP_entry_value). With the example above that uses int and produces an entry_value, lldb says "z=4" when breaking at the return stmt, although z had the initial value of "2" when the function was called.

Thanks for finding this! lldb doesn't support the GNU opcodes yet, but it definitely shouldn't print the wrong value. Mind filing a separate PR for lldb?

2) lldb with dwarf5 does not seem to respect DW_OP_entry_value at all.

When using clang -gdwarf-5, lldb says "z=" when breaking at the return stmt for the example with int and the example with long.

Ouch. Well, I'm not sure how complete lldb's support for dwarf5 is. I'll ask around.

vedantk commented 4 years ago

Given this example, and the problem analysis in Comment 9, I see the following possible solutions:

Solution 1) Create a pass that combines sibling DBG_VALUEs into one Use isParameter from the first one, and everything else from the last one.

Solution 2) Make LiveDebugValues.cpp deal with multiple DBG_VALUE before an instruction: Use isParameter from the first one, and everything else from the last one.

Solution 3) Change RegisterCoalescer and VirtRegMap to also remove the corresponding DBG_VALUEs.

Options (1) and (2) seem very narrow, imho neither address the root cause. Istm that "DEBUG_VALUE: fn1:z <- $edi" doesn't make any sense: consider what happens if the caller passes in z = (1 << 33).

(3) sounds good, we should have those utilities clean up dead DBG_VALUEs. Doing just (3) would "fix" the user experience bug, and clean up the MIR stream, but imho this is still just patching over the problem.

What I'd love to understand is why that DEBUG_VALUE: fn1:z <- $edi gets created in the first place. That just seems wrong. If we can prevent that from happening, we don't need to have later passes clean things up ex post facto

tbosch commented 4 years ago

I would tend to solution 1), but am open for other ideas (and maybe I am going in the wrong direction).

@​Vedant Kumar, @​Djordje Todorovic, @​Eric Christopher: WDYT?

tbosch commented 4 years ago

Given this example, and the problem analysis in Comment 9, I see the following possible solutions:

Solution 1) Create a pass that combines sibling DBG_VALUEs into one Use isParameter from the first one, and everything else from the last one.

Solution 2) Make LiveDebugValues.cpp deal with multiple DBG_VALUE before an instruction: Use isParameter from the first one, and everything else from the last one.

Solution 3) Change RegisterCoalescer and VirtRegMap to also remove the corresponding DBG_VALUEs.

tbosch commented 4 years ago

The "Simple Register Coalescing" pass removes one COPY, but leaves the DBG_VALUE:

IR Dump After Simple Register Coalescing :

Machine code for function _Z3fn1l: NoPHIs, TracksLiveness

Function Live Ins: $rdi in %0

0B bb.0 (%ir-block.1): liveins: $rdi DBG_VALUE $rdi, $noreg, !"z", !DIExpression(), debug-location !​15; test.cc:0 line no:2 16B %4:gr64_with_sub_8bit = COPY $rdi DBG_VALUE %4:gr64_with_sub_8bit, $noreg, !"z", !DIExpression(), debug-location !​15; test.cc:0 line no:2 DBG_VALUE %4.sub_32bit:gr64_with_sub_8bit, $noreg, !"z", !DIExpression(), debug-location !​15; test.cc:0 line no:2 64B %4.sub_32bit:gr64_with_sub_8bit = IMUL32rr %4.sub_32bit:gr64_with_sub_8bit(tied-def 0), %4.sub_32bit:gr64_with_sub_8bit, implicit-def dead $eflags, debug-location !​16; test.cc:3:17 ...

And the "Virtual Register Rewriter" pass seems to remove the other COPY, and also leaves the DBG_VALUE as is:

IR Dump After Virtual Register Rewriter :

Machine code for function _Z3fn1l: NoPHIs, TracksLiveness, NoVRegs

Function Live Ins: $rdi

0B bb.0 (%ir-block.1): liveins: $rdi DBG_VALUE $rdi, $noreg, !"z", !DIExpression(), debug-location !​15; test.cc:0 line no:2 DBG_VALUE $edi, $noreg, !"z", !DIExpression(), debug-location !​15; test.cc:0 line no:2 64B renamable $edi = IMUL32rr renamable $edi(tied-def 0), renamable $edi, implicit-def dead $eflags, implicit killed $rdi, implicit-def $rdi, debug-location !​16; test.cc:3:17 ...

tbosch commented 4 years ago

The X86DAGToDAGISel pass seems to be creating the DBG_VALUES. And it seems to produce too many COPY operations:

IR dumps right after X86DAGToDAGISel with the simplified example above:

fn1(long)

IR Dump After X86 DAG->DAG Instruction Selection :

Machine code for function _Z3fn1l: IsSSA, TracksLiveness

Function Live Ins: $rdi in %0

bb.0 (%ir-block.1): liveins: $rdi DBG_VALUE $rdi, $noreg, !"z", !DIExpression(), debug-location !​15; test.cc:0 line no:2 %0:gr64 = COPY $rdi DBG_VALUE %0:gr64, $noreg, !"z", !DIExpression(), debug-location !​15; test.cc:0 line no:2 %1:gr32 = COPY %0.sub_32bit:gr64, debug-location !​16; test.cc:3:17 DBG_VALUE %1:gr32, $noreg, !"z", !DIExpression(), debug-location !​15; test.cc:0 line no:2 %2:gr32 = IMUL32rr %1:gr32(tied-def 0), %1:gr32, implicit-def dead $eflags, debug-location !​16; test.cc:3:17 DBG_VALUE %2:gr32, $noreg, !"l", !DIExpression(), debug-location !​15; test.cc:0 line no:3 %3:gr32 = ADD32ri8 %2:gr32(tied-def 0), 1, implicit-def dead $eflags, debug-location !​18; test.cc:4:16 $eax = COPY %3:gr32, debug-location !​19; test.cc:4:7 RET 0, $eax, debug-location !​19; test.cc:4:7

fn(int)

IR Dump After X86 DAG->DAG Instruction Selection :

Machine code for function _Z3fn1i: IsSSA, TracksLiveness

Function Live Ins: $edi in %0

bb.0 (%ir-block.1): liveins: $edi DBG_VALUE $edi, $noreg, !"z", !DIExpression(), debug-location !​14; test.cc:0 line no:2 %0:gr32 = COPY $edi DBG_VALUE %0:gr32, $noreg, !"z", !DIExpression(), debug-location !​14; test.cc:0 line no:2 %1:gr32 = nsw IMUL32rr %0:gr32(tied-def 0), %0:gr32, implicit-def dead $eflags, debug-location !​15; test.cc:3:17 DBG_VALUE %1:gr32, $noreg, !"l", !DIExpression(), debug-location !​14; test.cc:0 line no:3 %2:gr32 = nuw nsw ADD32ri8 %1:gr32(tied-def 0), 1, implicit-def dead $eflags, debug-location !​16; test.cc:4:16 $eax = COPY %2:gr32, debug-location !​17; test.cc:4:7 RET 0, $eax, debug-location !​17; test.cc:4:7

tbosch commented 4 years ago

While debugging, I also found the following problems in lldb:

1) lldb with dwarf4 uses DW_OP_GNU_entry_value, but doesn't save the value at the beginning of the function

Using clang -g produces dwarf4 (with DW_OP_GNU_entry_value instead of DW_OP_entry_value). With the example above that uses int and produces an entry_value, lldb says "z=4" when breaking at the return stmt, although z had the initial value of "2" when the function was called.

2) lldb with dwarf5 does not seem to respect DW_OP_entry_value at all.

When using clang -gdwarf-5, lldb says "z=" when breaking at the return stmt for the example with int and the example with long.

tbosch commented 4 years ago

Ok, here is a simpler example to show the problem:

Code (https://godbolt.org/z/yU9FHV)

attribute((noinline)) int fn1 (long z) { int l = z * z; return l+1; }

int main(void) { return fn1(2); }

Assembly

fn1(long):

DEBUG_VALUE: fn1:z <- $rdi

    #DEBUG_VALUE: fn1:z <- $edi
    imul    edi, edi
    #DEBUG_VALUE: fn1:q <- $edi
    lea     eax, [rdi + 1]
    ret

DWARF

0x00000037: DW_TAG_formal_parameter DW_AT_location (indexed (0x0) loclist = 0x00000014: [0x0000000000401110, 0x0000000000401113): DW_OP_reg5 RDI) DW_AT_name ("z") DW_AT_type (0x0000006a "long int")

Use an int argument instead of long

When using an int argument instead of long (https://godbolt.org/z/-6Q6V8), this leads to the following:

Assembly

fn1(int):

DEBUG_VALUE: fn1:z <- $edi

                                    # kill: def $edi killed $edi def $rdi
    #DEBUG_VALUE: fn1:z <- $edi
    imul    edi, edi
    #DEBUG_VALUE: fn1:q <- $edi
    lea     eax, [rdi + 1]
    ret

DWARF

0x00000037: DW_TAG_formal_parameter DW_AT_location (indexed (0x0) loclist = 0x00000014: [0x0000000000401110, 0x0000000000401113): DW_OP_reg5 RDI [0x0000000000401113, 0x0000000000401117): DW_OP_entry_value(DW_OP_reg5 RDI), DW_OP_stack_value) DW_AT_name ("z")

dwblaikie commented 4 years ago

call_site_parameters are only a partial workaround for this - they work in this case because the parameters are constants, if a caller didn't have constant parameters & didn't have any other reason to save the values aside before calling the function, they would not help recover the value & the bug remains/becomes visible

Just to loop back here - this ^ was a mistake. I either got bugs jumbled up or just misread this one - ah, yeah, I read Zach's comment:

What might be possible though is to extend the variable for as long as possible until its location is reused for something else. I haven’t seen the generated code for this example, but I expect at least in this case that that would end up being the entire function.

& assumed we weren't already doing that, according to Jeremy's comment:

ISel has picked a two-address multiply for the first instruction, meaning edx / 'z' gets overwritten. AFAIK, this is totally fine, and there's no real way of recovering the argument here.

(DW_OP_entry_value would help of course, alternately fake.use: https://reviews.llvm.org/D41043 although that's invasive).

Which I agree with - so, yeah, fixing the entry_value part seems like the only issue here (yeah, fake.use is a whole other thing, suitable to an -Og mode, etc - but much bigger project than "Why does this test case work for GCC and not Clang")

Carry on!

(oh, re: "It's probably a bug that we have so many duplicate DBG_VALUEs. " - yeah, if anyone gets an opportunity to investigate that, we have seen some compile time performance degredation likely due to something like this... )

tbosch commented 4 years ago

It's probably a bug that we have so many duplicate DBG_VALUEs. But the thing that's breaking the user experience is that the duplicate DBG_VALUEs don't all agree on the width of "z".

I think the ones that refer to $edx are wrong.

That's it! I changed the program to use int instead of long int and it works!

The DWARF DIE for the function parameter looks like this then (somehow clang decided to swap y and z in the multiplication if I do this too):

0x00000054: DW_TAG_formal_parameter DW_AT_location (0x00000000: [0x0000000000401110, 0x0000000000401113): DW_OP_reg4 RSI [0x0000000000401113, 0x0000000000401117): DW_OP_GNU_entry_value(DW_OP_reg4 RSI), DW_OP_stack_value) DW_AT_name ("y")

vedantk commented 4 years ago

The LiveDebugValues pass, which is responsible for creating entry value locations, is giving up too early.

Before LiveDebugValues, the MIR for fn1 starts with this:

  bb.0.entry:
    liveins: $rdi, $rdx, $rsi

    DBG_VALUE $rdi, $noreg, !&#8203;14, !DIExpression(), debug-location !&#8203;19
    DBG_VALUE $edi, $noreg, !&#8203;14, !DIExpression(), debug-location !&#8203;19
    DBG_VALUE $rsi, $noreg, !&#8203;15, !DIExpression(), debug-location !&#8203;19
    DBG_VALUE $rsi, $noreg, !&#8203;15, !DIExpression(), debug-location !&#8203;19
    DBG_VALUE $esi, $noreg, !&#8203;15, !DIExpression(), debug-location !&#8203;19
    DBG_VALUE $rdx, $noreg, !&#8203;16, !DIExpression(), debug-location !&#8203;19
    DBG_VALUE $rdx, $noreg, !&#8203;16, !DIExpression(), debug-location !&#8203;19
    DBG_VALUE $edx, $noreg, !&#8203;16, !DIExpression(), debug-location !&#8203;19
    ...

LDV takes the first DBG_VALUE for "z" and stashes a backup entry value location for it:

Creating the backup entry location:   DBG_VALUE $rdx, $noreg, !"z", !DIExpression(), debug-location !&#8203;19; fn.c:0 line no:2

But then it immediately finds another and mistakes it for a clobber of the parameter:

Deleting a DBG entry value because of: DBG_VALUE $edx, $noreg, !"z", !DIExpression(), debug-location !&#8203;19; fn.c:0 line no:2

It's probably a bug that we have so many duplicate DBG_VALUEs. But the thing that's breaking the user experience is that the duplicate DBG_VALUEs don't all agree on the width of "z".

I think the ones that refer to $edx are wrong.

tbosch commented 4 years ago

The llvm dwarf output is actually from an older clang version. With the current master, the problem still exists. However, the DWARF output does contain the call sites:

0x0000002e: DW_TAG_subprogram DW_AT_APPLE_omit_frame_ptr (true) DW_AT_frame_base (DW_OP_reg7 RSP) DW_AT_call_all_calls (true) DW_AT_name ("fn1") DW_AT_APPLE_optimized (true)

0x0000004b: DW_TAG_formal_parameter DW_AT_location (DW_OP_reg5 RDI) DW_AT_name ("x")

0x00000058: DW_TAG_formal_parameter DW_AT_location (DW_OP_reg4 RSI) DW_AT_name ("y")

0x00000065: DW_TAG_formal_parameter DW_AT_location (0x00000000: [0x0000000000401110, 0x0000000000401113): DW_OP_reg1 RDX) DW_AT_name ("z")

0x0000008f: DW_TAG_subprogram DW_AT_APPLE_omit_frame_ptr (true) DW_AT_frame_base (DW_OP_reg7 RSP) DW_AT_call_all_calls (true) DW_AT_name ("main") DW_AT_APPLE_optimized (true)

0x000000a8: DW_TAG_call_site DW_AT_call_origin (0x0000002e) DW_AT_call_tail_call (true) DW_AT_call_pc (0x000000000040112f)

0x000000b5: DW_TAG_call_site_parameter DW_AT_location (DW_OP_reg1 RDX) DW_AT_call_value (DW_OP_constu 0x22)

0x000000bb: DW_TAG_call_site_parameter DW_AT_location (DW_OP_reg4 RSI) DW_AT_call_value (DW_OP_lit23)

0x000000c0: DW_TAG_call_site_parameter DW_AT_location (DW_OP_reg5 RDI) DW_AT_call_value (DW_OP_lit14)

dwblaikie commented 4 years ago

call_site_parameters are only a partial workaround for this - they work in this case because the parameters are constants, if a caller didn't have constant parameters & didn't have any other reason to save the values aside before calling the function, they would not help recover the value & the bug remains/becomes visible

Happy to chat further about how this all works - maybe video chat if that's helpful - just ping me :)

tbosch commented 4 years ago

Note that i also tried with -gdwarf-5 and lldb with the same results.

tbosch commented 4 years ago

Interestingly, this works with gcc (the dexter test above passes with gcc).

GCC (gcc -g -O3)

Debugger output

Breakpoint with gcc + gdb at the return stmt of fn1 Breakpoint 1, fn1 (x=14, y=23, z=34) at test.cc:5 5 return l + q;

Codegen (https://godbolt.org/z/R9VgvE)

fn1(long, long, long): imul esi, edx lea eax, [rsi+rdi*2] ret

DWARF (version 4, only important parts)

0x00000029: DW_TAG_subprogram DW_AT_name ("main") DW_AT_GNU_all_call_sites (true)

0x0000004b: DW_TAG_GNU_call_site DW_AT_GNU_tail_call (true)

0x00000058: DW_TAG_GNU_call_site_parameter DW_AT_location (DW_OP_reg5 RDI) DW_AT_GNU_call_site_value (DW_OP_breg5 RDI+0)

0x0000005e: DW_TAG_GNU_call_site_parameter DW_AT_location (DW_OP_reg4 RSI) DW_AT_GNU_call_site_value (DW_OP_lit23)

0x00000063: DW_TAG_GNU_call_site_parameter DW_AT_location (DW_OP_reg1 RDX) DW_AT_GNU_call_site_value (DW_OP_breg1 RDX+0)

0x00000072: DW_TAG_subprogram DW_AT_name ("fn1") DW_AT_GNU_all_call_sites (true)

0x00000098: DW_TAG_formal_parameter DW_AT_name ("x") DW_AT_location (DW_OP_reg5 RDI)

0x000000a4: DW_TAG_formal_parameter DW_AT_name ("y") DW_AT_location (0x00000004: [0x0000000000001150, 0x0000000000001153): DW_OP_reg4 RSI [0x0000000000001153, 0x0000000000001157): DW_OP_GNU_entry_value(DW_OP_reg4 RSI), DW_OP_stack_value) DW_AT_unknown_2137 (0x00000000)

0x000000b6: DW_TAG_formal_parameter DW_AT_name ("z") DW_AT_location (DW_OP_reg1 RDX)

LLVM (clang -ggdb -O3)

Debugger output

Breakpoint with clang + gdb at the return stmt of fn1: Breakpoint 1, fn1 (x=14, y=23, z=) at test.cc:5 5 return l + q;

Codegen (https://godbolt.org/z/K9oT-e)

fn1(long, long, long): imul edx, esi lea eax, [rdx + 2*rdi] ret

DWARF (version 4, only important parts)

0x0000002a: DW_TAG_subprogram DW_AT_name ("fn1") DW_AT_external (true)

0x00000047: DW_TAG_formal_parameter DW_AT_location (0x00000000: [0x0000000000401110, 0x0000000000401117): DW_OP_reg5 RDI) DW_AT_name ("x")

0x00000056: DW_TAG_formal_parameter DW_AT_location (0x00000023: [0x0000000000401110, 0x0000000000401117): DW_OP_reg4 RSI) DW_AT_name ("y")

0x00000065: DW_TAG_formal_parameter DW_AT_location (0x00000046: [0x0000000000401110, 0x0000000000401113): DW_OP_reg1 RDX) DW_AT_name ("z")

0x0000008f: DW_TAG_subprogram DW_AT_name ("main")

tbosch commented 4 years ago

Here is a dexter test that reproduces the problem. It passes with -O0, but fails with -O3:

// REQUIRES: lldb
// UNSUPPORTED: system-windows
//
// RUN: %dexter --fail-lt 1.0 -w \
// RUN:     --builder 'clang' --debugger 'lldb' --cflags "-O3 -glldb" -- %s

__attribute__((noinline))
int fn1 (long int x, long int y, long int z) {
        int l = x * 2;
        int q = y * z; // DexLabel('alive')
        return l + q; // DexLabel('dead')
}

int main(void) {
        return fn1(14, 23, 34);
}

// DexExpectWatchValue('z', '34', on_line='alive')
// DexExpectWatchValue('z', '34', on_line='dead')
jmorse commented 5 years ago

With llvm/clang r354569 I get the following codegen for fn1:

--------8<-------- 0000000000400480 : 400480: 0f af d6 imul %esi,%edx 400483: 8d 04 7a lea (%rdx,%rdi,2),%eax 400486: c3 retq -------->8--------

ISel has picked a two-address multiply for the first instruction, meaning edx / 'z' gets overwritten. AFAIK, this is totally fine, and there's no real way of recovering the argument here.

(DW_OP_entry_value would help of course, alternately fake.use: https://reviews.llvm.org/D41043 although that's invasive).

llvmbot commented 5 years ago

If we’re just asking about user expectation, then the end of the scope (which in this case is the whole function). But I’ll grant that this isn’t always possible.

What might be possible though is to extend the variable for as long as possible until its location is reused for something else. I haven’t seen the generated code for this example, but I expect at least in this case that that would end up being the entire function.

echristo commented 5 years ago

So, the lifetime of z has ended at that point, how long would you expect the lifetime to be extended for this?

llvmbot commented 5 years ago

assigned to @tbosch