Variable Debug Info covers 0 instructions (using USING_VARIABLE_LIVE_RANGE) #47202

cshung · 2021-01-20T01:11:22Z

R2RDump of windows, x64, release build of System.Private.CoreLib built using crossgen2 shows that USING_VARIABLE_LIVE_RANGE can produce variable mapping that covers 0 instruction. Attached please find the R2RDump of the offending method.

void Interop.GetRandomBytes(byte*, int)
Handle: 0x0600000A
Rid: 10
EntryPointRuntimeFunctionId: 8
Number of RuntimeFunctions: 1
Number of fixups: 4
    TableIndex 4, Offset 0117: Interop+BCrypt+NTSTATUS Interop+BCrypt.BCryptGenRandom(IntPtr, byte*, int, int) (INDIRECT_PINVOKE_TARGET)
    TableIndex 4, Offset 01EC: Interop+BCrypt+NTSTATUS (TYPE_HANDLE)
    TableIndex 4, Offset 0266: System.InvalidOperationException (TYPE_HANDLE)
    TableIndex 4, Offset 027D: System.OutOfMemoryException (TYPE_HANDLE)

void Interop.GetRandomBytes(byte*, int)
Id: 8
StartAddress: 0x001CCC00
Size: 194 bytes
UnwindRVA: 0x00021EC4
Version:            1
Flags:              0x03 EHANDLER UHANDLER
SizeOfProlog:       0x0013
CountOfUnwindCodes: 10
FrameRegister:      None
FrameOffset:        0x0
PersonalityRVA:     0x4F9ECC
UnwindCode[0]: CodeOffset 0x0013 FrameOffset 0x0000 NextOffset 0x0 Op 0 - Scaled small
UnwindCode[2]: CodeOffset 0x000B FrameOffset 0x0000 NextOffset 0x0 Op RSI(6)
UnwindCode[4]: CodeOffset 0x0009 FrameOffset 0x0000 NextOffset 0x0 Op R12(12)
UnwindCode[6]: CodeOffset 0x0005 FrameOffset 0x0000 NextOffset 0x0 Op R14(14)
UnwindCode[8]: CodeOffset 0x0001 FrameOffset 0x0000 NextOffset 0x0 Op RBP(5)

Debug Info
    Bounds:
    Native Offset: 0x0, Prolog, Source Types: StackEmpty
    Native Offset: 0x1B, IL Offset: 0x0000, Source Types: StackEmpty
    Native Offset: 0x6E, IL Offset: 0x000e, Source Types: StackEmpty
    Native Offset: 0x72, Epilog, Source Types: StackEmpty
    Native Offset: 0x83, IL Offset: 0x0011, Source Types: StackEmpty
    Native Offset: 0x8B, IL Offset: 0x0019, Source Types: StackEmpty
    Native Offset: 0x9D, IL Offset: 0x001e, Source Types: SourceTypeInvalid
    Native Offset: 0xA6, IL Offset: 0x001f, Source Types: StackEmpty
    Native Offset: 0xB8, IL Offset: 0x0024, Source Types: SourceTypeInvalid

    Variable Locations:
    Variable Number: 0
    Start Offset: 0x0
    End Offset: 0x1B
    Loc Type: VLT_REG
    Register: RCX

    Variable Number: 0
    Start Offset: 0x1B
    End Offset: 0x22
    Loc Type: VLT_REG
    Register: RCX

    Variable Number: 1
    Start Offset: 0x0
    End Offset: 0x1B
    Loc Type: VLT_REG
    Register: RDX

    Variable Number: 1
    Start Offset: 0x1B
    End Offset: 0x1C
    Loc Type: VLT_REG
    Register: RDX

    Variable Number: 2
    Start Offset: 0x6E
    End Offset: 0x72
    Loc Type: VLT_REG
    Register: RSI

    Variable Number: 2
    Start Offset: 0x83
    End Offset: 0x83
    Loc Type: VLT_REG
    Register: RSI

The text was updated successfully, but these errors were encountered:

ghost · 2021-01-20T01:11:23Z

Tagging subscribers to this area: @tommcdon
See info in area-owners.md if you want to be subscribed.

Issue Details

R2RDump of windows, x64, release build of System.Private.CoreLib built using crossgen2 shows that USING_VARIABLE_LIVE_RANGE can produce variable mapping that covers 0 instruction. Attached please find the R2RDump of the offending method.

void Interop.GetRandomBytes(byte*, int)
Handle: 0x0600000A
Rid: 10
EntryPointRuntimeFunctionId: 8
Number of RuntimeFunctions: 1
Number of fixups: 4
    TableIndex 4, Offset 0117: Interop+BCrypt+NTSTATUS Interop+BCrypt.BCryptGenRandom(IntPtr, byte*, int, int) (INDIRECT_PINVOKE_TARGET)
    TableIndex 4, Offset 01EC: Interop+BCrypt+NTSTATUS (TYPE_HANDLE)
    TableIndex 4, Offset 0266: System.InvalidOperationException (TYPE_HANDLE)
    TableIndex 4, Offset 027D: System.OutOfMemoryException (TYPE_HANDLE)

void Interop.GetRandomBytes(byte*, int)
Id: 8
StartAddress: 0x001CCC00
Size: 194 bytes
UnwindRVA: 0x00021EC4
Version:            1
Flags:              0x03 EHANDLER UHANDLER
SizeOfProlog:       0x0013
CountOfUnwindCodes: 10
FrameRegister:      None
FrameOffset:        0x0
PersonalityRVA:     0x4F9ECC
UnwindCode[0]: CodeOffset 0x0013 FrameOffset 0x0000 NextOffset 0x0 Op 0 - Scaled small
UnwindCode[2]: CodeOffset 0x000B FrameOffset 0x0000 NextOffset 0x0 Op RSI(6)
UnwindCode[4]: CodeOffset 0x0009 FrameOffset 0x0000 NextOffset 0x0 Op R12(12)
UnwindCode[6]: CodeOffset 0x0005 FrameOffset 0x0000 NextOffset 0x0 Op R14(14)
UnwindCode[8]: CodeOffset 0x0001 FrameOffset 0x0000 NextOffset 0x0 Op RBP(5)

Debug Info
    Bounds:
    Native Offset: 0x0, Prolog, Source Types: StackEmpty
    Native Offset: 0x1B, IL Offset: 0x0000, Source Types: StackEmpty
    Native Offset: 0x6E, IL Offset: 0x000e, Source Types: StackEmpty
    Native Offset: 0x72, Epilog, Source Types: StackEmpty
    Native Offset: 0x83, IL Offset: 0x0011, Source Types: StackEmpty
    Native Offset: 0x8B, IL Offset: 0x0019, Source Types: StackEmpty
    Native Offset: 0x9D, IL Offset: 0x001e, Source Types: SourceTypeInvalid
    Native Offset: 0xA6, IL Offset: 0x001f, Source Types: StackEmpty
    Native Offset: 0xB8, IL Offset: 0x0024, Source Types: SourceTypeInvalid

    Variable Locations:
    Variable Number: 0
    Start Offset: 0x0
    End Offset: 0x1B
    Loc Type: VLT_REG
    Register: RCX

    Variable Number: 0
    Start Offset: 0x1B
    End Offset: 0x22
    Loc Type: VLT_REG
    Register: RCX

    Variable Number: 1
    Start Offset: 0x0
    End Offset: 0x1B
    Loc Type: VLT_REG
    Register: RDX

    Variable Number: 1
    Start Offset: 0x1B
    End Offset: 0x1C
    Loc Type: VLT_REG
    Register: RDX

    Variable Number: 2
    Start Offset: 0x6E
    End Offset: 0x72
    Loc Type: VLT_REG
    Register: RSI

    Variable Number: 2
    Start Offset: 0x83
    End Offset: 0x83
    Loc Type: VLT_REG
    Register: RSI

Author:	cshung
Assignees:	-
Labels:	`area-CodeGen-coreclr`, `area-Diagnostics-coreclr`
Milestone:	-

danmoseley · 2021-01-20T06:29:09Z

@cshung please just one area label

JulieLeeMSFT · 2021-01-22T22:38:05Z

CC @davidwrighton for crossgen2 related issue.

BruceForstall · 2021-01-26T01:10:43Z

USING_VARIABLE_LIVE_RANGE is still not an enabled feature (see #2107, #38894)

AndyAyersMS · 2022-09-19T18:30:53Z

USING_VARIABLE_LIVE_RANGE was enabled by #50162

EgorBo · 2022-10-05T17:02:49Z

Probably worth assigning to @BrianBohe who worked on this feature in the first place? 🙂

BrianBohe · 2022-10-20T15:48:43Z

First, let me share the steps to reproduce this. On an up-to-date copy of the repo run:

.\build.cmd clr+libs -rc debug -c release && .\src\tests\build.cmd debug generatelayoutonly
./dotnet <path_to_repo>\artifacts\bin\coreclr\windows.x64.Debug\R2RDump\R2RDump.dll --in <path_to_repo>\artifacts\bin\coreclr\windows.x64.Debug\System.Private.CoreLib.dll

And now we can search for any Start Offset: reported above an End Offset: with equal value. In particular, the reported case is still there:

void Interop.GetRandomBytes(byte*, int)
Id: 8
...
    Variable Number: 2
    Start Offset: 0xA6
    End Offset: 0xA6
    Loc Type: VLT_REG
    Register: RSI

We can use corerun in place of dotnet to get the same result:
<path_to_repo>\artifacts\tests\coreclr\windows.x64.Debug\Tests\Core_Root\corerun.exe -c <path_to_repo>\artifacts\tests\coreclr\windows.x64.Debug\Tests\Core_Root\ <path_to_repo>\artifacts\tests\coreclr\windows.x64.Debug\Tests\Core_Root\System.Private.CoreLib.dll

Interop.GetRandomBytes is compiled and pre-jitted in System.Private.CoreLib.dll when building the repository, so we can take part of the command used when building the repository and debug the jit at the moment of jitting that method:
<path_to_repo>\artifacts\bin\coreclr\windows.x64.Checked\crossgen2\crossgen2.exe -o:<path_to_repo>\artifacts\bin\coreclr\windows.x64.Checked\System.Private.CoreLib.dll -r:<path_to_repo>\artifacts\bin\coreclr\windows.x64.Checked\IL*.dll --targetarch:x64 -m:<path_to_repo>\artifacts\bin\coreclr\windows.x64.Checked\StandardOptimizationData.mibc --embed-pgo-data -O --verify-type-and-field-layout <path_to_repo>\artifacts\bin\coreclr\windows.x64.Checked\IL\System.Private.CoreLib.dll --pdb --pdb-path:<path_to_repo>\artifacts\bin\coreclr\windows.x64.Checked\PDB

In particular, I opened crossgen2 on vs running .\src\coreclr\tools\aot\crossgen2.sln on terminal. I set it on debug mode for x64, opened "Startup project properties" > "Debug" > "Open Debug Launch Properties UI" and filled the command line arguments with:
-o:prueba -r:C:\runtimes\runtime2\artifacts\bin\coreclr\windows.x64.Debug\IL\*.dll --targetarch:x64 -m:C:\runtimes\runtime2\artifacts\bin\coreclr\windows.x64.Debug\StandardOptimizationData.mibc --embed-pgo-data -O --verify-type-and-field-layout C:\runtimes\runtime2\artifacts\bin\coreclr\windows.x64.Debug\IL\System.Private.CoreLib.dll --pdb --pdb-path:C:\runtimes\runtime2\artifacts\bin\coreclr\windows.x64.Debug\PDB --parallelism 1 --optimize --print-repro-instructions --jitpath=C:\runtimes\runtime2\artifacts\tests\coreclr\windows.x64.Debug\Tests\Core_Root\clrjit_win_x64_x64.dll --singlemethodtypename "Interop" --singlemethodname "GetRandomBytes" --singlemethodindex 1 --codegenopt JitDump=GetRandomBytes

BrianBohe · 2022-10-20T15:52:59Z

In this example, we have block BB03, which begins with V02 alive in rsi and is last used in gtID [000030].

------------ BB03 [032..03F) -> BB05 (cond), preds={BB02} succs={BB04,BB05}
N103 (???,???) [000066] -----------                                  IL_OFFSET void   INLRT @ 0x03C[E-] REG NA
N105 (  3,  2) [000030]   -----------                 t30 =        LCL_VAR   int    V02 loc0         u:1 rsi (last use) REG rsi $c1
N107 (  1,  4) [000031]   -c---------                 t31 =        CNS_INT   int    -0x3fffffe9 REG NA $44
                                                                                 /--*  t30    int    
                                                                                +--*  t31    int    
N109 (  5,  7) [000032]   J------N---                         *  NE        void   REG NA $183
N111 (  7,  9) [000038]   -----------                          *  JTRUE     void   REG NA $VN.Void

Note that [000066] doesn't emit code and operands are consumed before the parent node, so V02 is marked as death before the first instruction of BB03 is emitted.

      L_M2510_BB03:
Mapped BB03 to G_M2510_IG06
Added IP mapping: 0x003C STACK_EMPTY (G_M2510_IG06,ins#0,ofs#0) label
Generating: N103 (???,???) [000066]-----------                                IL_OFFSET void   INLRT @ 0x03C[E-] REG NA
Generating: N105 (  3,  2) [000030]  -----------                   t30 =    LCL_VAR   int    V02 loc0         u:1 rsi (last use) REG rsi $c1
Generating: N107 (  1,  4) [000031]  -c---------                   t31 =    CNS_INT   int    -0x3fffffe9 REG NA $44
                                                                                                   /--*  t30    int    
                                                                                                  +--*  t31    int    
Generating: N109 (  5,  7) [000032]  J------N---                         *  NE        void   REG NA $183
							V02 in reg rsi is becoming dead  [000030]
							Live regs: 00000040 {rsi} => 00000000 {}
							Live vars: {V02} => {}
IN001e:        cmp      esi, 0xD1FFAB1E
Generating: N111 (  7,  9) [000038]  -----------                          *  JTRUE     void   REG NA $VN.Void
IN001f:        jne      L_M2510_BB05

As BB06 is emitted before BB03 and finished with no variable alive, V02 live range starts at the beginning of BB03: V02 loc0: rsi [(G_M2510_IG06,ins#0,ofs#0), (G_M2510_IG06,ins#0,ofs#0)].

Reporting an empty range can be helpful if the variable becomes alive in the instruction emitted immediately after it dies, as its range is just extended as it has never been dead. A few examples of this when running crossgen over private corelib are:

--singlemethodtypename "System.Decimal+DecCalc" --singlemethodname "Div128By96" --singlemethodindex 1
--singlemethodtypename "System.Decimal+DecCalc" --singlemethodname "OverflowUnscale" --singlemethodindex 1
--singlemethodtypename "System.Decimal+DecCalc" --singlemethodname "DecAddSub" --singlemethodindex 1
--singlemethodtypename "System.Decimal+DecCalc" --singlemethodname "VarDecCmpSub" --singlemethodindex 1

A workaround for this is to remove any empty range non-extended while creating new live ranges and iterate through all variables' last range, removing the leading empty ranges (if they are). They are usually a few variables tracked with this system, so a linear scan over this list of last ranges seems reasonable.

Also, V02 is the last use in an operand, but the outer tree [000032] emits an instruction that does not alter its src dst operands. V02 will be in rsi even after executing cmp. It may have value to reconsider when a variable should be marked as dead.

BrianBohe · 2022-11-02T16:41:52Z

Solved in 77289

cshung added area-CodeGen-coreclr CLR JIT compiler in src/coreclr/src/jit and related components such as SuperPMI area-Diagnostics-coreclr labels Jan 20, 2021

dotnet-issue-labeler bot added the untriaged New issue has not been triaged by the area owner label Jan 20, 2021

danmoseley removed the area-Diagnostics-coreclr label Jan 20, 2021

BruceForstall added this to the Future milestone Jan 26, 2021

BruceForstall removed the untriaged New issue has not been triaged by the area owner label Jan 26, 2021

cshung mentioned this issue Aug 24, 2021

Update ready to run icsharpcode/ILSpy#2489

Merged

JulieLeeMSFT assigned EgorBo Oct 5, 2022

JulieLeeMSFT assigned BrianBohe and unassigned EgorBo Oct 11, 2022

This was referenced Oct 20, 2022

Avoid reporting empty debug info ranges to the vm #77289

Merged

[WIP] Alternative approach to issue 47202 #77370

Closed

Extending variable live ranges in more cases #77439

Closed

BrianBohe closed this as completed Nov 2, 2022

JulieLeeMSFT modified the milestones: Future, 8.0.0 Nov 4, 2022

ghost locked as resolved and limited conversation to collaborators Dec 5, 2022

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Variable Debug Info covers 0 instructions (using USING_VARIABLE_LIVE_RANGE) #47202

Variable Debug Info covers 0 instructions (using USING_VARIABLE_LIVE_RANGE) #47202

cshung commented Jan 20, 2021

ghost commented Jan 20, 2021

danmoseley commented Jan 20, 2021

JulieLeeMSFT commented Jan 22, 2021

BruceForstall commented Jan 26, 2021

AndyAyersMS commented Sep 19, 2022

EgorBo commented Oct 5, 2022 •

edited

Loading

BrianBohe commented Oct 20, 2022

BrianBohe commented Oct 20, 2022

BrianBohe commented Nov 2, 2022

Variable Debug Info covers 0 instructions (using USING_VARIABLE_LIVE_RANGE) #47202

Variable Debug Info covers 0 instructions (using USING_VARIABLE_LIVE_RANGE) #47202

Comments

cshung commented Jan 20, 2021

ghost commented Jan 20, 2021

danmoseley commented Jan 20, 2021

JulieLeeMSFT commented Jan 22, 2021

BruceForstall commented Jan 26, 2021

AndyAyersMS commented Sep 19, 2022

EgorBo commented Oct 5, 2022 • edited Loading

BrianBohe commented Oct 20, 2022

BrianBohe commented Oct 20, 2022

BrianBohe commented Nov 2, 2022

EgorBo commented Oct 5, 2022 •

edited

Loading