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

GCTraceCPUTime may report incorrect times during high load from JNI code

XMLWordPrintable

    • gc

      GCTraceCPUTime is used by Serial, Parallel and G1 to estimate GC CPU time spent during safepoints. It estimates CPU time by sampling the CPU time for entire process.

      This will not work if JNI is used and is incurring a high load on the machine as JNI code is not paused during safepoints.

      A minimal example:

          public static void main(String[] args) {
              // Initial GC that clean up start-up garbage etc.
              System.gc();

              for (int i = 1; i <= 128; i++) {
                  addLoad(); // Creates 128 threads, that spins in a loop
                  try {
                      Thread.sleep(2000);
                  } catch (InterruptedException e) {}
                  System.gc();
              }
              System.exit(0);
          }

      where addLoad() is a native call to a C++ program that create 128 pthreads that busy-spin forever with the largest nice value allowed.

      In such scenario we can observe using G1

      [0.026s][info][gc,cpu] GC(0) User=0.00s Sys=0.00s Real=0.01s
      [2.103s][info][gc,cpu] GC(1) User=0.89s Sys=0.00s Real=0.03s
      [4.129s][info][gc,cpu] GC(2) User=0.51s Sys=0.00s Real=0.01s
      [6.195s][info][gc,cpu] GC(3) User=1.72s Sys=0.00s Real=0.06s
      [8.244s][info][gc,cpu] GC(4) User=1.46s Sys=0.00s Real=0.05s
      ...
      [201.191s][info][gc,cpu] GC(76) User=37.91s Sys=0.00s Real=1.19s
      [205.064s][info][gc,cpu] GC(77) User=52.44s Sys=0.00s Real=1.64s
      [208.068s][info][gc,cpu] GC(78) User=23.49s Sys=0.00s Real=0.74s
      [211.795s][info][gc,cpu] GC(79) User=46.96s Sys=0.00s Real=1.47s

      Since the Java code does not do anything the time should be close to 0.

      With JDK-8359110 an infrastructure to precisely sample GC threads for their CPU time was introduced. A solution to this bug may possibly piggyback on that framework.

            jnorlinder Jonas Norlinder
            jnorlinder Jonas Norlinder
            Votes:
            0 Vote for this issue
            Watchers:
            2 Start watching this issue

              Created:
              Updated: