Forum Stats

  • 3,876,074 Users
  • 2,267,056 Discussions
  • 7,912,419 Comments

Discussions

Events shown in the Range Navigator when viewing System Properties for a JFR recording

5af06565-fdcb-41d4-9d87-adcbe3f7d91b
edited Sep 24, 2015 3:17AM in Java Mission Control

What are the events shown in the Range Navigator when viewing the System Properties tab for a Java Flight Recorder recording? I'm guessing that they mark the times when JFR is writing events to disk.

I'm asking because, when capturing a lot of information using JFR, we see two effects that correlate with these events: (1) CPU use ramps up a bit between one event and the next, dropping back to the starting level after each event, even though the application workload is constant; (2) the clock used for high-resolution timestamping on all the events JFR captures appears  to run slower in the period immediately following each of these events, perhaps for the period while JFR is writing to disk. The slowing of the clock appears as an increase in the rate of events shown in the Range Navigator in other tabs - I've also parsed selected  events out of the original FR file to check their apparent rates.

I'm seeing this on Java EE applications running on JBoss EAP 6.x, on Java 7 on small vSphere virtual machines.

Best Answer

  • Klara Ward, Java Mission Control Dev-Oracle
    edited Sep 23, 2015 9:27AM Answer ✓

    The events shown in the range navigotor in any time should be shown at the time they are created. not when they are written to disk which can be a while later, depending on the settings.

    In the System Properties tab you should generally see one spike per chunk in your recording. You should see the same as if you go to the Events tabgroup and only enable the Java Virtual Machine/Initial System Property in the Event Types view.

    As to the CPU usage and timestamp degradations, that sounds interesting.

    What exact version of Java 7 are you using, there might have been some bugfixes done in later releases.

Answers

  • Klara Ward, Java Mission Control Dev-Oracle
    edited Sep 23, 2015 9:27AM Answer ✓

    The events shown in the range navigotor in any time should be shown at the time they are created. not when they are written to disk which can be a while later, depending on the settings.

    In the System Properties tab you should generally see one spike per chunk in your recording. You should see the same as if you go to the Events tabgroup and only enable the Java Virtual Machine/Initial System Property in the Event Types view.

    As to the CPU usage and timestamp degradations, that sounds interesting.

    What exact version of Java 7 are you using, there might have been some bugfixes done in later releases.

  • 5af06565-fdcb-41d4-9d87-adcbe3f7d91b
    edited Sep 23, 2015 1:06PM

    Thanks, Klara, for a speedy and informative response. In the Events tabgroup I don't see that event type in the unfiltered list of event types. This *is* an old Java version - 1.7.0_45-b18. (It's a big project, in a secure environment, with constant time pressure... but one of these days we shall make the jump to Java 8. In the meantime I'll see if I can get a later Java 7 version.)

    Your answer addressed my main concern - there is one of these events per JFR chunk. We need to be more selective in our use of JFR, using different profiles for different kinds of test.

    JFR has been extremely useful in showing us inefficiencies in the application under test - e.g. incredible stack depth with nested EJB calls. As we remove these inefficiencies there will be much  less for JFR to record, and the effects I mentioned should be much reduced.

    Thanks again

         Justin

  • Klara Ward, Java Mission Control Dev-Oracle
    edited Sep 24, 2015 3:17AM

    Using a newer JDK 7 update is probably a good idea, I can never remember what was fixed in which update, but according to this forums FAQ, at least some things have been fixed in 7u71. Using the latest is generally a good thing I guess

This discussion has been closed.