How to include IO-bound methods in Java Flight Recorder sampling?

Question

I'm starting JFR at launch by specifying the following CLI options to the Java program under test:

-Xmx24g -XX:+UnlockCommercialFeatures -XX:+FlightRecorder 
-XX:FlightRecorderOptions=defaultrecording=true,dumponexit=true,settings=profile

The test execution takes 90 seconds to complete.

After opening the JFR dump in Java Mission Control, the Call Tree tab in JMC looks like this:

There is less than 1 sample per second. That makes the detail drill-down, Hot Methods and Overview tabs effectively useless. After initial investigation it was determined the method sampling is set to the default of 10ms, and, as it turns out, this unexpected result is because ~98% of the 90 seconds are spent waiting on socket I/O while performing various different database reads, so I'm only getting method samples for the other ~2% of the time.

How can I include I/O-bound samples in the method time, in order to help locate the trace that's spending the most time waiting for database results? The process contains database queries in multiple places, which in turn are called from multiple other places, so guessing at the slow call path is not easy.

Does enabling sampling at non-safe points make any difference? — Lesiak, Apr 28 '19 at 21:42
@Lesiak I made some progress and had to re-write the question, I believe at this point your suggestion is not applicable. — Alex R, Apr 28 '19 at 23:51
Indeed I/O-bound samples not be included in the methods sampling makes the method sampling of JFR pretty useless if the application is mainly spending most of its time doing database read/writes (which is the case of 90% of enterprise applications...). I was really disappointing when i discovered this limitation. I would really like an option to include them. — Olivier Masseau, Aug 15 '22 at 00:32

score 3 · Accepted Answer · edited Apr 29 '19 at 02:13

3

The lowest method execution sampling rate on JDK 8 is 10 ms, which is what you get with profile settings. This should be more than sufficient for a 90 seconds recording, assuming there is load on the application. There was a bug in JDK 11 that lead to too few samples, but I can see from the screenshot you are running an earlier release.

If you want to know what the application is doing when it is waiting, you should look at the Latency tab (not Hot Methods) or Socket Read / Socket Write tabs. There are events for Socket Read, Socket Write, Monitor Blocked, Monitor Wait etc., but may not apply if you are using async I/O.

EDIT

edited Apr 29 '19 at 02:13

Alex R

11,364
15
100
180

answered Apr 28 '19 at 23:52

Kire Haglin

6,569
22
27

Latency Tab (Socked Read) tells me what the application is doing, but not "where" it's doing it – Alex R Apr 29 '19 at 01:16
You can look at the stack trace to see where it originated from. – Kire Haglin Apr 29 '19 at 01:48
1

Hah! I just realized the line under Socket Read is clickable – Alex R Apr 29 '19 at 01:56
Good! There have been changes in the GUI. Socket Read/Write was in the Latency tab, but in 5.x it moved to Socket Read and Socket Write tabs. – Kire Haglin Apr 29 '19 at 02:12

How to include IO-bound methods in Java Flight Recorder sampling?

1 Answers1

Linked