Integrated: 8264768: JFR: Allow events to be printed to the log

[Erik Gahlin]

On Wed, 7 Apr 2021 14:28:27 GMT, Erik Gahlin <egahlin at openjdk.org> wrote:

> Hi,
> 
> Could I have a review of change that allow events to be printed to the log. 
> 
> This feature is meant for debugging purposes and to simplify development of new events, both user-defined and JDK events. It's not suitable for production environments because 1) The amount of data that will printed in the default configuration 2) The overhead of formatting the output 3) Events may contain sensitive information that should not end up in a log file.
> 
> To print only user-defined events to standard out:
> $  java -Xlog:jfr+event=debug -XX:StartFlightRecording ...
> 
> To print only JDK events to standard out:
> $  java -Xlog:jfr+event+system=debug -XX:StartFlightRecording ...
> 
> To print both user-defined and JDK events to standard out:
> $  java -Xlog:jfr+event*=debug -XX:StartFlightRecording ...
> 
> To print more than five frames in a stack trace:
> $  java -Xlog:jfr+event*=trace -XX:StartFlightRecording ...
> 
> To print all events to standard out without decoration, similar to 'jfr print'
> $  java -Xlog:jfr+event*=debug::none -XX:StartFlightRecording ...
> 
> Example outputs of -Xlog:jfr+event*=debug:
> 
> [2.444s][debug][jfr,system,event] jdk.CPULoad {
> [2.444s][debug][jfr,system,event]   startTime = 15:32:09.605
> [2.444s][debug][jfr,system,event]   jvmUser = 8,27%
> [2.444s][debug][jfr,system,event]   jvmSystem = 0,68%
> [2.444s][debug][jfr,system,event]   machineTotal = 12,78%
> [2.444s][debug][jfr,system,event] }
> 
> [7.352s][debug][jfr,event       ] testing.FooBarBaz {
> [7.352s][debug][jfr,event       ]   startTime = 15:33:11.526
> [7.352s][debug][jfr,event       ]   duration = 1,00 s
> [7.352s][debug][jfr,event       ]   eventThread = "main" (javaThreadId = 1)
> [7.352s][debug][jfr,event       ]   stackTrace = [
> [7.352s][debug][jfr,event       ]     Test.method3() line: 32
> [7.352s][debug][jfr,event       ]     Test.method2() line: 24
> [7.352s][debug][jfr,event       ]     Test.method1() line: 20
> [7.352s][debug][jfr,event       ]     Test.main(String[]) line: 15
> [7.352s][debug][jfr,event       ]     jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Method, Object, Object[])
> [7.352s][debug][jfr,event       ]     ...
> [7.352s][debug][jfr,event       ]   ]
> [7.352s][debug][jfr,event       ] }
> 
> There is no good way to do filtering per event, since log tags needs to be known at compile time and JFR allows user-defined events to be registered at runtime. Maybe something can be invented that allows UL to accept some JFR specific syntax, i.e. -Xlog:jfr[jdk.ConcurrentModeFailure,jdk.AllocationRequiringGC], but it's outside the scope of this enhancement request. 
> 
> A custom .jfc file can always be created for the events you want to record, i.e. -Xlog:jfr+event*=debug -XX:StartFlightRecording:settings=custom.jfc
> 
> Testing: jdk/jdk/jfr
> 
> Thanks
> Erik

This pull request has now been integrated.

Changeset: e80012ed
Author:    Erik Gahlin <egahlin at openjdk.org>
URL:       https://git.openjdk.java.net/jdk/commit/e80012ed
Stats:     1121 lines in 29 files changed: 1090 ins; 7 del; 24 mod

8264768: JFR: Allow events to be printed to the log

Reviewed-by: mgronlun

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

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