8225429: Regression in disassembly quality
Schmidt, Lutz
lutz.schmidt at sap.com
Fri Jun 7 19:11:10 UTC 2019
Kirk,
if the currently active (and failing) nmethod isn't enough for you to debug, the only remedy currently existing is -XX:+PrintAssembly which prints all nmethods at compilation time. If it's just a handful of nmethods under suspicion, you could use CompilerOracle to selectively print those.
The "big" solution would be to print/disassemble all nmethods in the code heap at failure time. That functionality doesn't exist yet.
Regards,
Lutz
On 07.06.19, 17:50, "Kodewerk" <kirk at kodewerk.com> wrote:
Hi Chris,
I was just recently dealing with a JVM crash caused by C2 compilation missing a barrier. It only showed up on certain production system which could never be replicated in a test environment. Having a full print assembly in that situation wasn’t a great option. Although there is an obscure way to get the assembly for a single method it would be great if there was better ways to easily target specific compilation events.
— Kirk
> On Jun 7, 2019, at 1:41 AM, Chris Newland <cnewland at chrisnewland.com> wrote:
>
> Hi all,
>
> Just a note that JITWatch is aimed at product VM users and expects the old
> (full) PrintAssembly output.
>
> If that's changing I can work around it but just thought I'd mention it.
>
> Kind regards,
>
> Chris
>
> On Fri, June 7, 2019 08:56, Schmidt, Lutz wrote:
>> To all with emotions on PrintAssembly output!
>>
>>
>> I'm actually happy that there is some discussion now on how much
>> information should be printed when.
>>
>> I had sent out a request for comments before I actually started working
>> on this task. Back then, it was around Nov/Dec 2018, I got "bashed"
>> because the sample output I showed seemed bloated and way to verbose for
>> some.
>>
>> As a result of those comments, I introduced all the switches and #defines
>> to make the output configurable in a wide range. The default settings
>> were selected such that only minimal output is generated. I knew that
>> would not satisfy everybody. I am pretty much with Jon Rose: when you run
>> into a problem and print a disassembly, print as much information as you
>> have. You may not have a second chance.
>>
>> In essence, I'm happy with any default setting you may find most helpful.
>> If there is anything I can do to help (fixing bugs, enhancing
>> functionality), let me know.
>>
>> Thanks,
>> Lutz
>>
>>
>>
>> On 07.06.19, 01:16, "hotspot-dev on behalf of David Holmes"
>> <hotspot-dev-bounces at openjdk.java.net on behalf of
>> david.holmes at oracle.com> wrote:
>>
>> Hi Andrew,
>>
>>
>> On 7/06/2019 1:19 am, Andrew Haley wrote:
>>
>>> In a debug build, if you printed a disassembled method, you used to
>>> get a lot of information about a method. Now, you just get raw
>>> disassembly. This patch restores the status quo ante,
>>>
>>> http://cr.openjdk.java.net/~aph/8225429-1/
>>>
>>
>> src/hotspot/share/asm/codeBuffer.hpp
>>
>> _collect_comments = ( PrintAssembly
>> || PrintStubCode
>> || PrintMethodHandleStubs
>> || PrintInterpreter
>> || PrintSignatureHandlers
>> + || UnlockDiagnosticVMOptions
>> );
>>
>>
>> Would it be better to explicitly enable this in debug, using
>> trueInDebug, versus using an otherwise unrelated flag that happens to be
>> "true in debug"? Or is there also some reason to turn this on in product
>> when UnlockDiagnosticVMOptions is used?
>>
>> Thanks,
>> David
>>
>>
>>
>>> There are other bugs in the new disassembly output: in particular
>>> options processing seems to be very broken. However, this patch is enough
>>> to get things going again, so at least we can get some work done.
>>>
>>> Before:
>>>
>>>
>>> # {method} {0x00007f2f64833660} 'decodeModuleName'
>>> '(ILjava/lang/String;)Ljava/lang/String;' in
>>> 'jdk/internal/module/ModuleInfo$ConstantPool'
>>> # this: rsi:rsi = 'jdk/internal/module/ModuleInfo$ConstantPool'
>>> # parm0: rdx = int
>>> # parm1: rcx:rcx = 'java/lang/String'
>>> # [sp+0x40] (sp of caller)
>>> ;; N542: # B1 <- BLOCK HEAD IS JUNK Freq: 1
>>>
>>>
>>> 0x00007f2fb1168440: mov r10d,DWORD PTR [rsi+0x8]
>>> 0x00007f2fb1168444: movabs r12,0x800000000
>>> 0x00007f2fb116844e: add r10,r12
>>> 0x00007f2fb1168451: xor r12,r12
>>> 0x00007f2fb1168454: cmp rax,r10
>>> 0x00007f2fb1168457: jne 0x00007f2fb104d6a0 ; {runtime_call ic_miss_stub}
>>> 0x00007f2fb116845d: nop
>>> 0x00007f2fb116845e: nop
>>> 0x00007f2fb116845f: nop
>>> [Verified Entry Point]
>>> ;; B1: # B54 B2 <- BLOCK HEAD IS JUNK Freq: 1
>>>
>>>
>>> 0x00007f2fb1168460: mov DWORD PTR [rsp-0x16000],eax
>>> 0x00007f2fb1168467: push rbp
>>> 0x00007f2fb1168468: sub rsp,0x30 ;*synchronization entry
>>> ; - jdk.internal.module.ModuleInfo$ConstantPool::decodeModuleName at -1
>>> (line 877)
>>>
>>>
>>> 0x00007f2fb116846c: mov r10,rsi
>>> 0x00007f2fb116846f: mov r9,rcx
>>> 0x00007f2fb1168472: mov edi,DWORD PTR [rcx+0xc] ;*getfield value
>>> {reexecute=0 rethrow=0 return_oop=0}
>>> ; - java.lang.String::length at 1 (line 658)
>>> ; - jdk.internal.module.ModuleInfo$ConstantPool::decodeModuleName at 1
>>> (line 877)
>>> ; implicit exception: dispatches to 0x00007f2fb116872a
>>> ;; B2: # B55 B3 <- B1 Freq: 0.999999
>>>
>>>
>>> Now you only get this, even in a debug build:
>>>
>>>
>>> 0x00007ff1c5176c20: mov r10d,DWORD PTR [rsi+0x8]
>>> 0x00007ff1c5176c24: movabs r12,0x800000000
>>> 0x00007ff1c5176c2e: add r10,r12
>>> 0x00007ff1c5176c31: xor r12,r12
>>> 0x00007ff1c5176c34: cmp rax,r10
>>> 0x00007ff1c5176c37: jne 0x00007ff1c5113da0
>>> 0x00007ff1c5176c3d: nop
>>> 0x00007ff1c5176c3e: nop
>>> 0x00007ff1c5176c3f: nop
>>> 0x00007ff1c5176c40: mov DWORD PTR [rsp-0x16000],eax
>>> 0x00007ff1c5176c47: push rbp
>>> 0x00007ff1c5176c48: sub rsp,0x30
>>> 0x00007ff1c5176c4c: mov r11,rsi
>>> 0x00007ff1c5176c4f: mov r9,rcx
>>> 0x00007ff1c5176c52: mov r10d,DWORD PTR [rcx+0xc]
>>>
>>>
>>> There are no comments at all, just raw disassembly.
>>>
>>>
>>> This patch restores the status quo ante:
>>>
>>>
>>> # {method} {0x00007f9f53c2e3c0} 'decodeModuleName'
>>> '(ILjava/lang/String;)Ljava/lang/String;' in
>>> 'jdk/internal/module/ModuleInfo$ConstantPool'
>>> # this: rsi:rsi = 'jdk/internal/module/ModuleInfo$ConstantPool'
>>> # parm0: rdx = int
>>> # parm1: rcx:rcx = 'java/lang/String'
>>> # [sp+0x40] (sp of caller)
>>> ;; N551: # out( B1 ) <- BLOCK HEAD IS JUNK Freq: 1
>>> 0x00007f9fb4d64620: mov r10d,DWORD PTR [rsi+0x8]
>>> 0x00007f9fb4d64624: movabs r12,0x800000000
>>> 0x00007f9fb4d6462e: add r10,r12
>>> 0x00007f9fb4d64631: xor r12,r12
>>> 0x00007f9fb4d64634: cmp rax,r10
>>> 0x00007f9fb4d64637: jne 0x00007f9fb4cfeda0 ;
>>> {runtime_call ic_miss_stub}
>>> 0x00007f9fb4d6463d: nop
>>> 0x00007f9fb4d6463e: nop
>>> 0x00007f9fb4d6463f: nop
>>> [Verified Entry Point]
>>> ;; B1: # out( B55 B2 ) <- BLOCK HEAD IS JUNK Freq: 1
>>> 0x00007f9fb4d64640: mov DWORD PTR [rsp-0x16000],eax
>>> 0x00007f9fb4d64647: push rbp
>>> 0x00007f9fb4d64648: sub rsp,0x30
>>> ;*synchronization entry
>>> ; - jdk.internal.module.ModuleInfo$ConstantPool::decodeModuleName at -1
>>> (line 876)
>>> 0x00007f9fb4d6464c: mov r11,rsi
>>> 0x00007f9fb4d6464f: mov r9,rcx
>>> 0x00007f9fb4d64652: mov r10d,DWORD PTR [rcx+0xc] ;*getfield
>>> value {reexecute=0 rethrow=0 return_oop=0} ; -
>>> java.lang.String::length at 1 (line 673)
>>> ; - jdk.internal.module.ModuleInfo$ConstantPool::decodeModuleName at 1
>>> (line 876)
>>> ; implicit exception: dispatches to 0x00007f9fb4d648fe
>>> ;; B2: # out( B56 B3 ) <- in( B1 ) Freq: 0.999999
>>>
>>>
>>
>>
>>
>
>
More information about the hotspot-dev
mailing list