RFR: JDK-8278329: some TraceDeoptimization code not included in PRODUCT build

[Tom Rodriguez]

On Tue, 7 Dec 2021 14:46:05 GMT, Tobias Holenstein <duke at openjdk.java.net> wrote:

> After "JDK-8154011: Make `TraceDeoptimization` a diagnostic flag" some code was not included in the PRODUCT build. 
> 
> Removed all the #ifndef PRODUCT guards around `TraceDeoptimization` checks and made sure to be consistent. 
> 
> The DEOPT PACKING messages were controlled by `PrintDeoptimizationDetails` (develop flag), but DEOPT UNPACKING is controlled by `TraceDeoptimization` (product flag),. Therefore changed DEOPT PACKING messages to be controlled by `TraceDeoptimization` as well. 
> 
> Checked that tests are not affected. Checked on Aurora that performance is not affected.

We can convert JDK-8278329 into a RFE if we need to.  Creating yet another bug just complicates things.  For debugging output the distinction between a bug and an RFE is pretty small anyway.

The first thing I notice that in a release build we get `[CodeBlob]` in this output which isn't very helpful.

DEOPT PACKING thread 0x00007fae8000dc00 Compiled frame (sp=0x000070000dd06ee0 unextended sp=0x000070000dd06ee0, fp=0x000000000000003a, real_fp=0x000070000dd06f10, pc=0x0000000116950388)
     [CodeBlob]
     Virtual frames (innermost first):

In fastdebug we get output like:

     nmethod   2351 1042       4       jdk.internal.misc.Unsafe::allocateUninitializedArray (55 bytes)

so I think the code is using a print function that doesn't exist in product.  That said I don't think that line of output is helpful since it reiterates the information in the trap or packing messages, so I'd be inclined to delete it.
A full pack/unpack sequence looks like this:

Uncommon trap   bci=2 pc=0x00000001169ba620, relative_pc=0x00000000000005c0, method=scala.collection.mutable.HashTable$class.elemEquals(Lscala/collection/mutable/HashTable;Ljava/lang/Object;Ljava/lang/Object;)Z, debug_id=0
Uncommon trap occurred in scala.collection.mutable.HashTable$class::findEntry compiler=c2 compile_id=1418 (@0x00000001169ba620) thread=7171 reason=unstable_if action=reinterpret unloaded_class_index=-1 debug_id=0
DEOPT PACKING thread 0x00007fae8000dc00 Compiled frame (sp=0x000070000dd06230 unextended sp=0x000070000dd06230, fp=0x00000006016a06e0, real_fp=0x000070000dd06280, pc=0x00000001169ba620)
     [CodeBlob]
     Virtual frames (innermost first):
        0 - (0x00007fae90293010) - if_acmpne @ bci 2 
        1 - (0x00007fae90294328) - invokestatic @ bci 3 
        2 - (0x00007fae90295640) - invokeinterface @ bci 35 
     Created vframeArray 0x00007fadf1041800

DEOPT UNPACKING thread 0x00007fae8000dc00 vframeArray 0x00007fadf1041800 mode 2

{method} {0x0000000133ac41a8} 'findEntry' '(Lscala/collection/mutable/HashTable;Ljava/lang/Object;)Lscala/collection/mutable/HashEntry;' in 'scala/collection/mutable/HashTable$class' - invokeinterface @ bci 35 sp = 0x000070000dd061f0
{method} {0x0000000133824bf8} 'elemEquals' '(Ljava/lang/Object;Ljava/lang/Object;)Z' in 'scala/collection/mutable/HashMap' - invokestatic @ bci 3 sp = 0x000070000dd06180
{method} {0x0000000133ac4a60} 'elemEquals' '(Lscala/collection/mutable/HashTable;Ljava/lang/Object;Ljava/lang/Object;)Z' in 'scala/collection/mutable/HashTable$class' - if_acmpne @ bci 2 sp = 0x000070000dd06118

The `{method}` lines correspond to the vframes in the `PACKING` step so it would be nice if they were printed in a similar way, without the extra blank line in between.  We should also use a different printing function so they are printed in a more natural way, like class.name(parameters) without the '{method}` part.  So I'd recommended moving the `DEOPT UNPACKING` printing into `vframeArray::unpack_to_stack and try to make the output look similar between the two.  The unpacking step just add information about the sp used in the recreated interpreter frame.  Maybe something like this:

DEOPT UNPACKING thread 0x00007fae8000dc00 vframeArray 0x00007fadf1041800 mode 2
     Virtual frames (innermost first):
        0 - {0x0000000133ac41a8} scala/collection/mutable/HashTable$class.findEntry(Lscala/collection/mutable/HashTable;Ljava/lang/Object;)Lscala/collection/mutable/HashEntry; - invokeinterface @ bci 35 sp =
        1 - {0x0000000133824bf8} scala/collection/mutable/HashMap.elemEquals(Ljava/lang/Object;Ljava/lang/Object;)Z - invokestatic @ bci 3 sp =
        2 - {0x0000000133ac4a60} scala/collection/mutable/HashTable$class.elemEquals(Lscala/collection/mutable/HashTable;Ljava/lang/Object;Ljava/lang/Object;)Z - if_acmpne @ bci 2 sp =
``` and update the vframe printing to include similar information about the actual method?
There's also the issue of 2 `Uncommon trap` messages for every trap that show slightly different information.  A single message would be clearer but maybe there's some good reason for the double printing that I'm missing.
I can prepare a changeset with my suggestions if it's unclear what I'm asking for.
I'm fine with the current state of PrintDeoptimizationDetails being non-product, but I'm surprised no one has finally deleted the `Verbose` and `WizardMode` flags.  Those are some ancient artifacts that should probably be purged.

-------------

PR: https://git.openjdk.java.net/jdk/pull/6746