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

egahlin · 2021-04-07T14:28:27Z

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

Progress

Change must not contain extraneous whitespace
Commit message must refer to an issue
Change must be properly reviewed

Issue

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

Reviewers

Markus Grönlund (@mgronlun - Reviewer) ⚠️ Review applies to 7a2f5c3

Reviewing

Using git

Checkout this PR locally:
$ git fetch https://git.openjdk.java.net/jdk pull/3377/head:pull/3377
$ git checkout pull/3377

Update a local copy of the PR:
$ git checkout pull/3377
$ git pull https://git.openjdk.java.net/jdk pull/3377/head

Using Skara CLI tools

Checkout this PR locally:
$ git pr checkout 3377

View PR using the GUI difftool:
$ git pr show -t 3377

Using diff file

Download this PR as a diff file:
https://git.openjdk.java.net/jdk/pull/3377.diff

bridgekeeper · 2021-04-07T14:28:40Z

👋 Welcome back egahlin! A progress list of the required criteria for merging this PR into master will be added to the body of your pull request. There are additional pull request commands available for use with this pull request.

openjdk · 2021-04-07T14:30:47Z

@egahlin The following label will be automatically applied to this pull request:

hotspot-jfr

When this pull request is ready to be reviewed, an "RFR" email will be sent to the corresponding mailing list. If you would like to change these labels, use the /label pull request command.

mlbridge · 2021-04-08T21:30:15Z

Webrevs

stefank

Nice feature!

Just peeked at the patch and saw some include nits.

stefank · 2021-04-09T06:54:51Z

src/hotspot/share/jfr/jni/jfrJavaSupport.cpp

+#include "oops/objArrayOop.hpp"
 #include "oops/objArrayOop.inline.hpp"


We usually don't explicitly include the .hpp file when the .inline.hpp file is already included.

(I also see that the lines many a few of the include lines are not sorted)

src/hotspot/share/jfr/utilities/jfrJavaLog.cpp

mgronlun

Looks good. Nice - convenient for development!

openjdk · 2021-04-13T14:29:59Z

@egahlin This change now passes all automated pre-integration checks.

ℹ️ This project also has non-automated pre-integration requirements. Please see the file CONTRIBUTING.md for details.

After integration, the commit message for the final commit will be:

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

Reviewed-by: mgronlun

You can use pull request commands such as /summary, /contributor and /issue to adjust it as needed.

At the time when this comment was updated there had been 148 new commits pushed to the master branch:

8df8512: 8265125: IGV: cannot edit forms with NetBeans GUI builder
9cd5400: 8265138: Simplify DerUtils::checkAlg
c797511: 8264940: java/lang/invoke/6998541/Test6998541.java failed "guarantee(ik->is_initialized()) failed: java/lang/Byte$ByteCache must be initialized"
943503e: 8265035: Remove unneeded exception check from refill_ic_stubs()
fced0f0: 8265113: ProblemList gtest/GTestWrapper.java:os.release_multi_mappings on macosx-aarch64
2aae29c: 8265111: ProblemList java/util/concurrent/locks/Lock/TimedAcquireLeak.java on macosx-aarch64
a84d886: 8265112: ProblemList some java/foreign tests on macosx-aarch64
87e39cb: 8265110: ProblemList compiler/jvmci/jdk.vm.ci.code.test/src/jdk/vm/ci/code/test/NativeCallTest.java on macosx-aarch64
784f1c1: 8264200: java/nio/channels/DatagramChannel/SRTest.java fails intermittently
a4f644e: 8265064: Move clearing and setting of members into helpers in ReservedSpace
... and 138 more: https://git.openjdk.java.net/jdk/compare/fdfa1dda08f0283422f78fb315f801025e1cc7d7...master

As there are no conflicts, your changes will automatically be rebased on top of these commits when integrating. If you prefer to avoid this automatic rebasing, please check the documentation for the /integrate command for further details.

➡️ To integrate this PR with the above commit message to the master branch, type /integrate in a new comment.

egahlin · 2021-04-13T20:05:36Z

/integrate

openjdk · 2021-04-13T20:07:03Z

@egahlin Since your change was applied there have been 149 commits pushed to the master branch:

3b576ed: 8265100: (fs) WindowsFileStore.hashCode() should read cached hash code once
8df8512: 8265125: IGV: cannot edit forms with NetBeans GUI builder
9cd5400: 8265138: Simplify DerUtils::checkAlg
c797511: 8264940: java/lang/invoke/6998541/Test6998541.java failed "guarantee(ik->is_initialized()) failed: java/lang/Byte$ByteCache must be initialized"
943503e: 8265035: Remove unneeded exception check from refill_ic_stubs()
fced0f0: 8265113: ProblemList gtest/GTestWrapper.java:os.release_multi_mappings on macosx-aarch64
2aae29c: 8265111: ProblemList java/util/concurrent/locks/Lock/TimedAcquireLeak.java on macosx-aarch64
a84d886: 8265112: ProblemList some java/foreign tests on macosx-aarch64
87e39cb: 8265110: ProblemList compiler/jvmci/jdk.vm.ci.code.test/src/jdk/vm/ci/code/test/NativeCallTest.java on macosx-aarch64
784f1c1: 8264200: java/nio/channels/DatagramChannel/SRTest.java fails intermittently
... and 139 more: https://git.openjdk.java.net/jdk/compare/fdfa1dda08f0283422f78fb315f801025e1cc7d7...master

Your commit was automatically rebased without conflicts.

Pushed as commit e80012e.

💡 You may see a message that your pull request was closed with unmerged commits. This can be safely ignored.

Initial

19e0398

openjdk bot added the hotspot-jfr label Apr 7, 2021

egahlin changed the title ~~8264768: JFR: Print events to the log~~ JFR: Allow events to be printed to the log Apr 7, 2021

egahlin changed the title ~~JFR: Allow events to be printed to the log~~ 8264768: JFR: Allow events to be printed to the log Apr 7, 2021

egahlin added 2 commits Apr 8, 2021

Bypass JNI

8b01fcf

Add missing includes

f30b6ba

egahlin marked this pull request as ready for review Apr 8, 2021

openjdk bot added the rfr label Apr 8, 2021

Remove accidentally added file

30d56ed

stefank reviewed Apr 9, 2021

View changes

egahlin added 2 commits Apr 12, 2021

Add test for truncation

c152cc5

Remove oops/objArrayOop.hpp include

7a2f5c3

mgronlun approved these changes Apr 13, 2021

View changes

openjdk bot added the ready label Apr 13, 2021

egahlin added 2 commits Apr 13, 2021

Reviewer feedback

6db9739

Use an event name in tests that is not a class name

f871e09

openjdk bot closed this Apr 13, 2021

openjdk bot added integrated and removed ready rfr labels Apr 13, 2021

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

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

egahlin commented Apr 7, 2021 •

edited by openjdk[bot] bot

bridgekeeper bot commented Apr 7, 2021

openjdk bot commented Apr 7, 2021

mlbridge bot commented Apr 8, 2021 •

edited

stefank left a comment

stefank Apr 9, 2021

stefank Apr 9, 2021

mgronlun left a comment

openjdk bot commented Apr 13, 2021 •

edited

egahlin commented Apr 13, 2021

openjdk bot commented Apr 13, 2021

		#include "oops/objArrayOop.hpp"
		#include "oops/objArrayOop.inline.hpp"

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

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

Conversation

egahlin commented Apr 7, 2021 • edited by openjdk[bot] bot

Progress

Issue

Reviewers

Reviewing

bridgekeeper bot commented Apr 7, 2021

openjdk bot commented Apr 7, 2021

mlbridge bot commented Apr 8, 2021 • edited

Webrevs

stefank left a comment

stefank Apr 9, 2021

Choose a reason for hiding this comment

stefank Apr 9, 2021

Choose a reason for hiding this comment

mgronlun left a comment

openjdk bot commented Apr 13, 2021 • edited

egahlin commented Apr 13, 2021

openjdk bot commented Apr 13, 2021

egahlin commented Apr 7, 2021 •

edited by openjdk[bot] bot

mlbridge bot commented Apr 8, 2021 •

edited

openjdk bot commented Apr 13, 2021 •

edited