RFR: 8361716 : GCTraceCPUTime may report incorrect times during high load from JNI code

Jonas Norlinder jnorlinder at openjdk.org
Mon Dec 15 14:56:22 UTC 2025


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 by using `os::getTimesSecs`.

This will not be correct if native code from e.g. JNI is used and is incurring a high load on the machine as native 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.

# Implementation Comment

Total CPU time for GC operations on the VM thread is obtained by cumulatively adding to a counter. Since system time is calculated (on Linux) with `total - user` is value contains a small error delta. If we continuously increment a value this error would grow to an unacceptable level. Therefore, the implementation will rely on the fact that no other VM operation may run during GC safepoint, making it safe to query the VM thread for it's detailed CPU time at the start and end of GC pause.

-------------

Commit messages:
 - Fix JNI bug in GCTraceCPUTime

Changes: https://git.openjdk.org/jdk/pull/28824/files
  Webrev: https://webrevs.openjdk.org/?repo=jdk&pr=28824&range=00
  Issue: https://bugs.openjdk.org/browse/JDK-8361716
  Stats: 203 lines in 11 files changed: 150 ins; 25 del; 28 mod
  Patch: https://git.openjdk.org/jdk/pull/28824.diff
  Fetch: git fetch https://git.openjdk.org/jdk.git pull/28824/head:pull/28824

PR: https://git.openjdk.org/jdk/pull/28824


More information about the hotspot-gc-dev mailing list