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

[Jonas Norlinder]

> 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.

Jonas Norlinder has updated the pull request incrementally with one additional commit since the last revision:

  Remove trailing whitespace

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

Changes:
  - all: https://git.openjdk.org/jdk/pull/28824/files
  - new: https://git.openjdk.org/jdk/pull/28824/files/86853846..a4af8042

Webrevs:
 - full: https://webrevs.openjdk.org/?repo=jdk&pr=28824&range=06
 - incr: https://webrevs.openjdk.org/?repo=jdk&pr=28824&range=05-06

  Stats: 1 line in 1 file changed: 0 ins; 0 del; 1 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