RFR: 8264768: JFR: Allow events to be printed to the log [v5]

[Erik Gahlin]

> 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

Erik Gahlin has updated the pull request incrementally with one additional commit since the last revision:

  Reviewer feedback

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

Changes:
  - all: https://git.openjdk.java.net/jdk/pull/3377/files
  - new: https://git.openjdk.java.net/jdk/pull/3377/files/7a2f5c38..6db9739e

Webrevs:
 - full: https://webrevs.openjdk.java.net/?repo=jdk&pr=3377&range=04
 - incr: https://webrevs.openjdk.java.net/?repo=jdk&pr=3377&range=03-04

  Stats: 4 lines in 3 files changed: 2 ins; 1 del; 1 mod
  Patch: https://git.openjdk.java.net/jdk/pull/3377.diff
  Fetch: git fetch https://git.openjdk.java.net/jdk pull/3377/head:pull/3377

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