RFR: 8333182: Add truncated tracing mode for TraceBytecodes

[David Holmes]

On Wed, 29 May 2024 15:37:07 GMT, Claes Redestad <redestad at openjdk.org> wrote:

> We routinely use `-XX:+TraceBytecodes` to instrument what's going on during application startup. However, much of the information traced in this mode is not really used, and adding a mode which truncates non-relevant information would be helpful to speed up instrumentation, especially on larger apps.
> 
> To illustrate, running `-XX:+TraceBytecodes` on a version of netty can produce more than 844MB of output:
> 
> 14759490 bytecodes executed in 151.1s (0.098MHz)
> [BytecodeCounter::counter_value = 14759531]
> 
> 
> A sample output block looks like this:
> 
> [34051] static jobject sun.reflect.annotation.AnnotationParser.parseAnnotations2(jobject, jobject, jobject, jobject)
> [34051] 14759490    58  astore #9
> [34051] 14759491    60  aload #9
> [34051] 14759492    62  invokestatic 57 
> ... 19 more lines
> [34051] 14759512    41  invokestatic 47 <sun/reflect/annotation/AnnotationParser.parseAnnotation2(Ljava/nio/ByteBuffer;Ljdk/internal/reflect/ConstantPool;Ljava/lang/Class;Z[Ljava/lang/Class;)Ljava/lang/annotation/Annotation;> 
> 
> [34051] static jboolean sun.reflect.annotation.AnnotationParser.contains(jobject, jobject)
> [34051] 14759513     0  nofast_aload_0
> [34051] 14759514     1  astore_2
> [34051] 14759515     2  aload_2
> ...
> 
> 
> This PR add a develop flag, `TraceBytecodesTruncated` meant to be used in addition to `TraceBytecodes`. It has the effect that all but the first bytecode in each method transition as well as returns and throws will be omitted. With the patch the output may look like this:
> 
> 
> [42243] static jobject sun.reflect.annotation.AnnotationParser.parseAnnotations2(jobject, jobject, jobject, jobject)
> [42243] 14858715    58  astore
> 
> [42243] static jboolean sun.reflect.annotation.AnnotationParser.contains(jobject, jobject)
> [42243] 14858737     0  nofast_aload_0
> [42243] 14858772    35  ireturn
> 
> 
> This truncated output is sufficient for certain purposes such as when digesting the output with [bytestacks](https://github.com/cl4es/bytestacks).
> 
> Running the same application with the patch and the added flag, `-XX:+TraceBytecodes -XX:+TraceBytecodesTruncated` generates a file that is 177MB, and in about a third of the time:
> 
> 14867664 bytecodes executed in 52.4s (0.284MHz)
> [BytecodeCounter::counter_value = 14867704]
> 
> 
> This enhancement would greatly speed up some of our diagnostics, and enable using these tools on even larger apps.

Okay it sounds like UL is not a feasible short term solution here., so being able to truncate the verbose output seems reasonable.

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

Marked as reviewed by dholmes (Reviewer).

PR Review: https://git.openjdk.org/jdk/pull/19457#pullrequestreview-2089968691