Programmers Guide To JDK Flight Recorder
Programmers Guide To JDK Flight Recorder
Joakim Nordström
Sustaining Engineer
Java Product Group, Oracle
February 2023
JDK Flight Recorder
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
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
9
Examining the JFR 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
Business Logic
12
Our Business Application -- Inside the Java Dumpster
Client
Sends request
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
Business Logic
destination
Services
14
package inside.dumpster.monitoring.event;
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;
return service;
}
18
public BusinessLogicService lookupService(Destination destination) {
final BusinessLogicService service;
return null;
}
serviceCallEvent.serviceImplClass = service.getClass();
serviceCallEvent.commit();
return service;
} 19
public BusinessLogicService lookupService(Destination destination) {
final BusinessLogicService service;
return null;
}
serviceCallEvent.serviceImplClass = service.getClass();
serviceCallEvent.commit();
return service;
} 20
Other metadata
21
Other metadata
22
Other metadata
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;
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
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
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
50
Using JFR events in unit tests
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
• 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]