0% found this document useful (0 votes)
38 views59 pages

Programmers Guide To JDK Flight Recorder

Uploaded by

yofarah09
Copyright
© © All Rights Reserved
We take content rights seriously. If you suspect this is your content, claim it here.
Available Formats
Download as PDF, TXT or read online on Scribd
0% found this document useful (0 votes)
38 views59 pages

Programmers Guide To JDK Flight Recorder

Uploaded by

yofarah09
Copyright
© © All Rights Reserved
We take content rights seriously. If you suspect this is your content, claim it here.
Available Formats
Download as PDF, TXT or read online on Scribd

Programmer’s Guide to

the JDK Flight Recorder

Joakim Nordström
Sustaining Engineer
Java Product Group, Oracle
February 2023
JDK Flight Recorder

• Records events from the JVM, the JDK and


applications
• unified way to inspect the entire software
stack
• correlate events across different software
layers and components
• Part of the JVM
• Low overhead
• Designed to be ”always on”

2
Agenda

1 2
Analyzing
3 4 5
Start/stop Create and Consuming Using events
recordings recordings use custom events in unit-test
events

3
Designed to be always on

• Two profiles shipped with the JVM


• default.jfc
• less than 1% overhead
• designed for continous recording, ”always on”
• profile.jfc
• can have slightly more overhead (<2%)
• slightly changed thresholds
• a few more stack traces

Tip: don’t alter these files!


• Make copies if needed
• Use jfr commmandline tool!
• Store custom settings together with app
settings

4
Designed to be always on 00:01
00:02
00:03
00:04
00:05
• Always start your JVM with Flight Recording! 00:06
00:07
• Default profile has less than 1 % overhead 00:08
00:09
00:10
00:11
java -XX:StartFlightRecording:dumponexit=true,\ 00:12
00:13
filename=/var/log/rec_%p_%t.jfr 00:14
00:15
00:16
00:17

Continous recording
• dumponexit=true 00:18
• will write JFR on JVM exit 00:19
00:20
• default name: hotspot_<pid>_<timestamp>.jfr 00:21
00:22
• filename can be 00:23
00:24
• directory 00:25
• filename
• %p for Process ID /var/log/rec_1854_202030208.jfr
• %t for timestamp

5
Start a recording during runtime 00:01
00:02
00:03
00:04
• Start recording using the “profile” setting: 00:05
00:06
$ jcmd <pid> JFR.start settings=profile \ 00:07
filename=profiling.jfr \ 00:08
duration=10m 00:09
00:10
00:11
JFR.start
00:12

Proflile recording
00:13
00:14
00:15
00:16
00:17

Continous recording
10 m
00:18
00:19
00:20
00:21
profiling.jfr 00:22
00:23
00:24
00:25

/var/log/rec_1854_202030208.jfr

6
Using JCMD to control JFR recordings 00:01
List all running JVMs pids: 00:02
00:03
$ jcmd 00:04
• Start recording 00:05
$ jcmd <pid> JFR.start List all jcmd commands: 00:06
00:07
$ jcmd <pid> help 00:08
00:09
• Write recording to disk 00:10
00:11
$ jcmd <pid> JFR.dump JFR.start
00:12

Proflile recording
00:13
00:14
• Stop recording 00:15
00:16
$ jcmd <pid> JFR.stop 00:17
JFR.dump 00:18
00:19
• Check active recordings profiling.jfr 00:20
00:21
$ jcmd <pid> JFR.check 00:22
00:23
30496: JFR.stop 00:24
Recording 1: name=1 maxsize=250,0MB (running) 00:25

7
Agenda

1 2
Analyzing
3 4 5
Start/stop Create and Consuming Using events
recordings recordings use custom events in unit-test
events

8
Examining the JFR recording

JDK Mission Control 8, “JMC”


• Graphical interface to analyze recordings
• Separate download:
oracle.com/java/technologies/jdk-mission-control.html
• Eclipse Plugins

9
Examining the JFR recording

JFR commandline tool


• Available in the JDK
• List events, output as text/JSON
• Create .jfc configuration files
• Disassemble chunks from recording
• If you have very large JFR recording
• Assemble leftover JFR chunks
• Scrub events from recording

10
Agenda

1 2
Analyzing
3 4 5
Start/stop Create and Consuming Using events
recordings recordings use custom events in unit-test
events

11
Our Business Application -- Inside the Java Dumpster

Client
Mimics a real world system
• Server application Sends request

• (Jetty, Micronaut, Tomcat, WebLogic, etc)


Business Application
• JDK 19

Business Logic

Client sends request to Business Application


destination
Business Logic decides based on destination
which service should handle the request
Services

12
Our Business Application -- Inside the Java Dumpster

Client

Sends request

Service lookupService(Destination destination) {


Business Application

switch(destination) {
case Comp3: Business Logic
return new UploadImageService();

destination
case Comp4:
return new EarnCreditsService();

Services
...
}
}

13
Our Business Application -- Inside the Java Dumpster

Client
Requirements
• Monitor service calls Sends request

• Catch unhandled destinations Business Application

Business Logic

destination

Services

14
package inside.dumpster.monitoring.event;

public class ServiceCallEvent {

public String destination;

public Class serviceImplClass;


}

15
package inside.dumpster.monitoring.event; @Name
• unique
• use reverse domain-name notation
@Name("inside.dumpster.ServiceCall") • com.acme.Application

@Label("Service Call")
@Label
@Category({"Business Application", "Services"}) • capitalized
public class ServiceCallEvent extends jdk.jfr.Event { • human-readable

@Label("Service Destination")
@Name (for a field)
public String destination; • start with lowerCase

@Name("serviceClass") @Category
• capitalized
@Label("Service Implementation Class") • descriptive
• unique
public Class serviceImplClass;
• create a logic hierarchy
}

16
public BusinessLogicService lookupService(Destination destination) {
final BusinessLogicService service;

switch(destination) {
case Comp3:
service = new UploadImageService();
break;
...
}

return service;
}

17
public BusinessLogicService lookupService(Destination destination) {
final BusinessLogicService service;

ServiceCallEvent serviceCallEvent = new ServiceCallEvent();


serviceCallEvent.destination = destination.name();
serviceCallEvent.begin();
switch(destination) {
case Comp3:
service = new UploadImageService();
break;
...
}
serviceCallEvent.serviceImplClass = service.getClass();
serviceCallEvent.commit();

return service;
}

18
public BusinessLogicService lookupService(Destination destination) {
final BusinessLogicService service;

ServiceCallEvent serviceCallEvent = new ServiceCallEvent();


serviceCallEvent.destination = destination.name();
serviceCallEvent.begin();
switch(destination) {
case Comp3:
service = new UploadImageService();
break;
...
case Unknown:
default:
UnhandledServiceCallEvent unhandledServiceEvent = new UnhandledServiceCallEvent();
unhandledServiceEvent.destination = destination.name();
unhandledServiceEvent.commit();

return null;
}
serviceCallEvent.serviceImplClass = service.getClass();
serviceCallEvent.commit();

return service;
} 19
public BusinessLogicService lookupService(Destination destination) {
final BusinessLogicService service;

ServiceCallEvent serviceCallEvent = new ServiceCallEvent();


serviceCallEvent.destination = destination.name();
serviceCallEvent.begin();
switch(destination) {
case Comp3:
service = new UploadImageService();
break;
...
case Unknown:
default:
UnhandledServiceCallEvent unhandledServiceEvent = new UnhandledServiceCallEvent();
unhandledServiceEvent.destination = destination.name();
unhandledServiceEvent.commit();

return null;
}
serviceCallEvent.serviceImplClass = service.getClass();
serviceCallEvent.commit();

return service;
} 20
Other metadata

Event used in tight loop:


@Label(”Bytes Read")
for (int pos : backend.getNext()) {
@Category({"Backend", ”IO"})
var event = new BytesRead();
@Enabled(true )
event.begin();
public class BytesRead extends Event {
byte b[] = backend.read(pos);
@Label(”Bytes Read")
event.end();
@DataAmount
event.bytes = b.length();
public long bytes;
event.commit();
}
}

21
Other metadata

Event used in tight loop:


@Label(”Bytes Read")
for (int pos : backend.getNext()) {
@Category({"Backend", ”IO"})
var event = new BytesRead();
@Enabled(false)
event.begin();
public class BytesRead extends Event {
byte b[] = backend.read(pos);
@Label(”Bytes Read")
event.end();
@DataAmount
event.bytes = b.length();
public long bytes;
event.commit();
}
}

22
Other metadata

Event used in tight loop:


@Label(”Bytes Read")
for (int pos : backend.getNext()) {
@Category({"Backend", ”IO"})
var event = new BytesRead();
@Enabled(false)
event.begin();
public class BytesRead extends Event {
byte b[] = backend.read(pos);
@Label(”Bytes Read")
event.end();
@DataAmount
event.bytes = b.length();
public long bytes;
event.commit();
}
}
Some other annotations:
@MemoryAddress
@Frequency
@Percentage

23
Agenda

1 2
Analyzing
3 4 5
Start/stop Create and Consuming Using events
recordings recordings use custom events in unit-test
events

24
Agenda

1 2
Analyzing
3 4 5
Start/stop Create and Consuming Using events
recordings recordings use custom events in unit-test
events

25
26 Copyright © 2022, Oracle and/or its affiliates | Confidential: Internal/Restricted/Highly Restricted [Date]
package inside.dumpster.monitoring.event;

@Category({"Business Application", "Services"})


@Name("inside.dumpster.ServiceCall")
@Label("Service Call")
public class ServiceCallEvent extends Event {
@Label("Service Destination")
public
27
String destination;
Copyright © 2022, Oracle and/or its affiliates | Confidential: Internal/Restricted/Highly Restricted [Date]
28 Copyright © 2022, Oracle and/or its affiliates | Confidential: Internal/Restricted/Highly Restricted [Date]
29 Copyright © 2022, Oracle and/or its affiliates | Confidential: Internal/Restricted/Highly Restricted [Date]
30 Copyright © 2022, Oracle and/or its affiliates | Confidential: Internal/Restricted/Highly Restricted [Date]
Agenda

1 2
Analyzing
3 4 5
Start/stop Create and Consuming Using events
recordings recordings use custom events in unit-test
events

31
Consuming events programmatically

jdk.jfr.consumer.EventStream
• Stream events from recording

jdk.jfr.Recording
• Configure, start, stop, dump recording

jdk.jfr.consumer.RecordingStream
• Stream events

jdk.management.jfr.RemoteRecordingStream
• Stream events from remote source

32
Monitoring CPU level using RecordingStream

Problem
• Our JVM takes up a lot of CPU, and we don’t
know why
Action
• When the CPU load is high, dump a JFR
recording to analyze why this happens

.JFR

33
Monitoring CPU level using RecordingStream
1.
2.
3. RecordingStream has no events
4. enabled without Configuration
5. • enable events explicitly, or
6. void startCPULoadMonitor(Path dumpPath) throws Exception { • add Configuration
7.
8. try (var stream = new RecordingStream()) {
9.
10. stream.enable("jdk.CPULoad").withPeriod(Duration.ofSeconds(1));
11. stream.onEvent("jdk.CPULoad", event -> {
12. float cpuLoad = event.getFloat(“jvmUser");
13. if (cpuLoad > 0.8) {
14. stream.dump(dumpPath);
15. }
16. });
17.
18. }
19. }
34
Monitoring CPU level using RecordingStream
1.
2.
3. RecordingStream has no events
4. enabled without Configuration
5. • enable events explicitly, or
6. void startCPULoadMonitor(Path dumpPath) throws Exception { • add Configuration
7. Configuration conf = Configuration.getConfiguration("default");
8. try (var stream = new RecordingStream( conf )) {
9.
10. // stream.enable("jdk.CPULoad").withPeriod(Duration.ofSeconds(1));
11. stream.onEvent("jdk.CPULoad", event -> {
12. float cpuLoad = event.getFloat(“jvmUser");
13. if (cpuLoad > 0.8) {
14. stream.dump(dumpPath);
15. }
16. });
17.
18. }
19. }
35
Monitoring CPU level using RecordingStream
1.
2.
3. RecordingStream has no events
4. enabled without Configuration
5. • enable events explicitly, or
6. void startCPULoadMonitor(Path dumpPath) throws Exception { • add Configuration
7. Configuration conf = Configuration.getConfiguration("default");
8. try (var stream = new RecordingStream( conf )) {
9.
10. stream.enable("jdk.CPULoad").withPeriod(Duration.ofSeconds(1));
11. stream.onEvent("jdk.CPULoad", event -> {
12. float cpuLoad = event.getFloat(“jvmUser"); Since we want a JFR file to
13. if (cpuLoad > 0.8) { analyze, we want as many events
14. stream.dump(dumpPath); as possible – use Configuration
15. }
16. });
17.
18. }
19. }
36
Monitoring CPU level using RecordingStream
1.
2.
3.
4.
5.
6. void startCPULoadMonitor(Path dumpPath) throws Exception {
7. Configuration conf = Configuration.getConfiguration("default");
8. try (var stream = new RecordingStream( conf )) {
9.
10. stream.enable("jdk.CPULoad").withPeriod(Duration.ofSeconds(1));
11. stream.onEvent("jdk.CPULoad", event -> {
12. float cpuLoad = event.getFloat(“jvmUser");
13. if (cpuLoad > 0.8) {
14. stream.dump(dumpPath);
15. }
16. }); .JFR
17. stream.start();
18. }
19. }
37
Monitoring CPU level using RecordingStream

.JFR

38
Monitoring CPU level using RecordingStream

39
Monitoring CPU level using RecordingStream

40
Monitoring CPU level using RecordingStream

41
Monitoring CPU level using RecordingStream

42
Remotely monitoring CPU level using RemoteRecordingStream

Problem
• We’re saving JFR recordings on high CPU, but our .JFR .JFR .JFR .JFR
server nodes are shortlived, and automatically
removed
Solution
• Dump JFR recording on a more persistent node

.JFR .JFR .JFR .JFR

43
Remotely monitoring CPU level using RemoteRecordingStream

Problem
• We’re saving JFR recordings on high CPU, but our
server nodes are shortlived, and automatically
removed
Solution
• Dump JFR recording on a more persistent node

.JFR
.JFR

44
Remotely monitoring CPU level using RemoteRecordingStream
1. void startCPULoadMonitor(String host, Path dumpPath) throws Exception {
2.
3.
4.
5.
6.
7.
8. try (var stream = new RemoteRecordingStream()) {
9.
10. stream.enable("jdk.CPULoad").withPeriod(Duration.ofSeconds(1));
11. stream.onEvent("jdk.CPULoad", event -> {
12. float cpuLoad = event.getFloat(“jvmUser");
13. if (cpuLoad > 0.8) {
14. stream.dump(dumpPath);
15. }
16. });
17. stream.start();
18. }
19. }
45
Remotely monitoring CPU level using RemoteRecordingStream
1. void startCPULoadMonitor(String host, Path dumpPath) throws Exception {
2. JMXServiceURL u = new JMXServiceURL(
3. "service:jmx:rmi:///jndi/rmi://" + host + "/jmxrmi");
4. JMXConnector c = JMXConnectorFactory.connect(u,
5. Map.of("jmx.remote.credentials", new String[]{user, pwd}));
6. MBeanServerConnection conn = c.getMBeanServerConnection();
7.
8. try (var stream = new RemoteRecordingStream( conn )) {
9.
10. stream.enable("jdk.CPULoad").withPeriod(Duration.ofSeconds(1));
11. stream.onEvent("jdk.CPULoad", event -> {
12. float cpuLoad = event.getFloat(“jvmUser");
13. if (cpuLoad > 0.8) {
14. stream.dump(dumpPath);
15. }
16. });
17. stream.start();
18. }
19. }
46
Remotely monitoring CPU level using RemoteRecordingStream
1. void startCPULoadMonitor(String host, Path dumpPath) throws Exception {
2. JMXServiceURL u = new JMXServiceURL(
3. "service:jmx:rmi:///jndi/rmi://" + host + "/jmxrmi");
4. JMXConnector c = JMXConnectorFactory.connect(u,
5. Map.of("jmx.remote.credentials", new String[]{user, pwd}));
6. MBeanServerConnection conn = c.getMBeanServerConnection();
7.
8. try (var stream = new RemoteRecordingStream( conn )) { Javadoc:
9. stream.setMaxAge(Duration.ofMinutes(10)); It's highly recommended that a max
10. stream.enable("jdk.CPULoad").withPeriod(Duration.ofSeconds(1)); age or max size is set before starting
11. stream.onEvent("jdk.CPULoad", event -> { the stream.
12. float cpuLoad = event.getFloat(“jvmUser");
13. if (cpuLoad > 0.8) { This means we’ll keep 10 minutes
14. stream.dump(dumpPath); worth of data on the client.
15. }
16. });
17. stream.start();
18. }
19. }
47
Remotely monitoring CPU level using RemoteRecordingStream

.JFR

Client side Server side

java –jar RemoteMonitor.jar server12:12345 java -XX:StartFlightRecording


-Dcom.sun.management.jmxremote.port=12345
-Dcom.sun.management.jmxremote.authenticate=true
-Dcom.sun.management.jmxremote.password.file=jmx.pwd
-Dcom.sun.management.jmxremote.access.file=jmx.acs
-Dcom.sun.management.jmxremote.ssl=false
-Djava.rmi.server.hostname=127.0.0.1
-jar server.jar
JMX setup link:
https://docs.oracle.com/en/java/javase/19/management/monitoring-and-management-using-jmx-technology.html

48
Agenda

1 2
Analyzing
3 4 5
Start/stop Create and Consuming Using events
recordings recordings use custom events in unit-test
events

49
Using JFR events in unit tests

JEP 421: Deprecate Finalization for Removal

Finalizers are deprecated for removal

New JFR event:


• jdk.FinalizerStatistics events are
emitted for each instantiated class with
a non-empty finalize() method

50
Using JFR events in unit tests

Finalizers are deprecated for removal

Problem
• Developers keep adding finalizers in their
services.
Solution
• Add a testcase that captures all
jdk.FinalizerStatistics events

51
Using JFR events in unit tests -- Recording
1. public void testNoServicesUsesFinalizers() throws Exception {
2. try (Recording r = new Recording()) {
3. r.enable("jdk.FinalizerStatistics");
4. r.start();
5.
6. callAllServices(); // performs a call to each registered service
7.
8. r.stop();
9. r.dump(tempFile);
10.
11. try (EventStream stream = EventStream.openFile(tempFile)) {
12. stream.onEvent("jdk.FinalizerStatistics", event -> {
13. classesWithFinalizers.add(event.getClass("finalizableClass").getName());
14. });
15. stream.start();
16. }
17. Files.delete(tempFile);
18. }
19. assertTrue(classesWithFinalizers.isEmpty);
20. } 52
Using JFR events in unit tests -- Recording
1. public void testNoServicesUsesFinalizers() throws Exception {
2. try (Recording r = new Recording()) {
3. r.enable("jdk.FinalizerStatistics");
4. r.start();
5.
6. callAllServices(); // performs a call to each registered service
7.
8. r.stop();
9. r.dump(tempFile);
10.
11. try (EventStream stream = EventStream.openFile(f)) {
12. stream.onEvent("jdk.FinalizerStatistics", event -> {
13. classesWithFinalizers.add(event.getClass("finalizableClass").getName());
14. });
15. stream.start();
16. }
17. Files.delete(tempFile);
18. }
19. assertTrue(classesWithFinalizers.isEmpty);
20. } 53
Using JFR events in unit tests

Recommended to use jdk.jfr.Recording


• RecordingStream can be used in unit-testing,
however:
• cumbersome to end the stream;
have to wait for all events to be consumed

• Until now!
• JDK-8295487 JFR: Add stop methods for
recording streams
• NB: Will come in JDK 20

54
Using JFR events in unit tests -- RecordingStream
1.
2. @Test public void testNoServicesUsesFinalizers throws Exception {
3. try (var stream = new RecordingStream()) {
4. stream.enable("jdk.FinalizerStatistics");
5. stream.onEvent("jdk.FinalizerStatistics", (event) -> {
6. classesWithFinalizers.add(event.getClass("finalizableClass").getName());
7. });
8. stream.startAsync();
9.
10. callAllServices();
11.
12. stream.stop(); // new in JDK 20
13. }
14. assertTrue(classesWithFinalizers.isEmpty);
15. }

55
Using JFR events in unit tests -- RecordingStream
1.
2. @Test public void testNoServicesUsesFinalizers throws Exception {
3. try (var stream = new RecordingStream()) {
4. stream.enable("jdk.FinalizerStatistics");
5. stream.onEvent("jdk.FinalizerStatistics", (event) -> {
6. classesWithFinalizers.add(event.getClass("finalizableClass").getName());
7. });
8. stream.startAsync();
9.
10. callAllServices();
11.
12. stream.stop(); // new in JDK 20
13. }
14. assertTrue(classesWithFinalizers.isEmpty);
15. }

56
Agenda

1 2
Analyzing
3 4 5
Start/stop Create and Consuming Using events
recordings recordings use custom events in unit-test
events

57
Questions?

Blog: jaokim.github.io
Github: github.com/jaokim/inside-java-dumpster
Twitter: @jaokim
Mastodon: @[email protected]

58
eof

59 Copyright © 2022, Oracle and/or its affiliates | Confidential: Internal/Restricted/Highly Restricted [Date]

You might also like