Uploaded image for project: 'JDK'
  1. JDK
  2. JDK-8323755

JFR fails to get a stack trace of System.currentTimeMillis() on AArch64

XMLWordPrintable

    • jfr
    • aarch64

      The attached example calls System.currentTimeMillis() in a loop for 10 seconds. When profiling with JFR, we expect to get nearly 1000 execution samples, since the default CPU profiling interval is 10ms. In fact, we get only ~100 samples. This means, 90% of samples are lost.

      Such inaccurate profiling is completely misleading: it gives user a wrong impression that `baseline` consumes 10x more CPU comparing to `timeLoop`, while the truth is that both methods are equally expensive.

      Also, JFR output (bad.jfr) contains several samples with an invalid stack trace, which looks truncated and contains a duplicate `timeLoop` frame:
       [0] Test.time
       [1] Test.wrapper
       [2] Test.timeLoop
       [3] Test.timeLoop

      This is likely caused by the same problem: when the stack walker attempts to get a sender frame at a wrong location, it may find garbage on the stack and silently discard the sample, or it may find something that resembles a normal frame.

      How to run:
      java -XX:+UnlockDiagnosticVMOptions -XX:+DebugNonSafepoints -XX:StartFlightRecording=settings=profile,filename=bad.jfr Test

        1. bad.jfr
          214 kB
        2. good.html
          40 kB
        3. Test.java
          0.7 kB

            mgronlun Markus Grönlund
            apangin Andrei Pangin
            Votes:
            0 Vote for this issue
            Watchers:
            5 Start watching this issue

              Created:
              Updated: