JDK-8358342 : G1: G1CodeRootSet performance breaks down on even moderate load
  • Type: Bug
  • Component: hotspot
  • Sub-Component: gc
  • Affected Version: 21.0.4,22
  • Priority: P3
  • Status: Open
  • Resolution: Unresolved
  • Submitted: 2025-06-02
  • Updated: 2025-11-18
The Version table provides details related to the release that this issue/RFE will be addressed.

Unresolved : Release in which this issue/RFE will be addressed.
Resolved: Release in which this issue/RFE has been resolved.
Fixed : Release in which this issue/RFE has been fixed. The release containing this fix may be available for download as an Early Access Release or a General Availability Release.

To download the current JDK release, click here.
JDK 26
26Unresolved
Related Reports
Causes :  
Relates :  
Relates :  
Relates :  
Relates :  
Description
Developers reported their application experienced extremely long young GC evacuation pauses sometimes after the application running for about 5m~30m, starting from JDK 21.0.4 (last year). When occurred, the long pause appeared to be associated with a spike in GCU usage. In some extreme cases, the long evacuation pauses could reach >90s. 

The extremely long young G1 evacuation pauses appeared to be associated with specific usages of the application, which made it difficult to reproduce. I investigated the issue with 'gc+phases=debug' from some test runs with reproduced long evacuation pauses (but magnitude lower, <1s). According to the GC logs, the long pauses were due to long Code Root Scan operations. That connected the issue to JDK-8315503, which was back-ported to JDK 21.0.4. I was not able to reproduce the extreme long young G1 evacuation with the CCStress.java from JDK-8315503. I experimented with increasing the number generated classes with CCStress.java without being able to reproduce.

JDK-8315503 switched to use ConcurrentHashTable to store code root. The initial table size was 2^2 (set with 'Log2DefaultNumBuckets = 2'), which was small. I added a command-line option, which was used for the developers to run with a larger initial hashtable for the code root. The idea was to avoid the operations for growing the table and copying the table entries. With the initial table size set to 2^15, the developers reported the extreme long young G1 evacuation no longer occurred in their non-testing runs. 

Using a very large code root hash-table increased memory usages since the code root table was per region. The memory overhead became problematic when very large Java heap was used.

Reporting the issue for more thoughts. I/we was not able to construct a specific test case to demonstrate the issue (sorry about that part).   



Comments
Is also very cpu specific; above results were on some somewhat older Intel processor, on newer AMD my test does not exhibit this scaling issue to that extent.
14-11-2025

Just added code that lets every thread add a few thousand unique fake nmethods to a single shared CodeRootSet at start of GC to force the apparent issue (for testing/reproduction only of course). E.g. Threads Log2 Initial Size Code roots/thread Additional time/thread [ms] 8 2 1000 ~5 8 2 10000 ~160 8 9 10000 ~25 8 16 10000 ~15 20 2 1000 ~30 20 2 10000 ~1200 20 9 10000 ~80 20 16 10000 ~30 I suspect there is he same scalability issue for the remembered sets (JDK-8267830, JDK-8296803), but it may as well be JDK-8315924 where we just grow way too much. Bumping priority.
14-11-2025

I can reproduce the slowness now with some code modifications. It seems that expanding the CHT is extremely slow, particularly if a few threads are trying to insert at the same time. Not only the expansion is slow, but also actual insertion apparently. In my tests though there is very little sys time, so that may be a different issue.
13-11-2025

[~jiangli]: if you still have your reproducer, can you try this patch on your reproducer: diff --git a/src/hotspot/share/gc/g1/g1CodeRootSet.cpp b/src/hotspot/share/gc/g1/g1CodeRootSet.cpp index 60ad3a2af32..3e763ac5d09 100644 --- a/src/hotspot/share/gc/g1/g1CodeRootSet.cpp +++ b/src/hotspot/share/gc/g1/g1CodeRootSet.cpp @@ -122,7 +122,7 @@ class G1CodeRootSetHashTable : public CHeapObj<mtGC> { if (inserted) { AtomicAccess::inc(&_num_entries); } - if (grow_hint) { + if (grow_hint && !SafepointSynchronize::is_at_safepoint()) { _table.grow(Thread::current()); } } It simply disables growing of the CHT during the GC pause. That might give us a clue about whether the issue is related to growing the table or not. I am still trying to rerproduce.
13-11-2025

I am not sure this issue is directly caused by the changes, but has to do more with the environment. High sys times in that range indicate environment problems, particularly related to transparent huge pages (or unlikely nowadays, swapping). This would fit actually, memory allocations in this case in the gc cause long pauses due to defragmentation. There is the question whether these long pauses are always the only place they happen. There is certainly room for an RFE to decrease the number of resizings, particularly during GC. I'll try to reproduce a bit more.
12-11-2025

The system in total scanned 2411 nmethods; there should not be many resizings happening, even starting with just 4 entries for that table, also considering that I do not expect that all code roots will be added to a single region (may happen, even then we are looking at around 10 resizings (from 2^2 -> 2^12). What caught my eye was this: I 2024-11-08T16:13:49.174085-08:00 0 [2024-11-08T16:13:49.174-0800][6424.522s][info ][gc,cpu ] GC(8) User=4.49s Sys=13.73s Real=0.90s I.e. extremely high sys times.
05-11-2025

Following are some of my thoughts that I also commented in our internal bug while looking into the issue: I think there were two main effects with https://github.com/openjdk/jdk/pull/15811/files: Changed to allow multiple worker threads to do concurrent scanning of the coderoot for each region. Before that only one worker thread was used to do the coderoot for each region. So that part should help things, as described by the bug & PR. The storage of the coderoot for each region was changed. Before the change it used a resizeable hashtable. The initial size was 32 and the max was 512. The table would grow once, from the initial small size to the max size when needed. Now a ConcurrentHashTable is used (allowing concurrent scanning). The initial size is 2^2. If the number of nmethods is large, the table would need to grow multiple times (each time it doubles the size). IIUC the remaining is unaffected. So the overhead of the table growing seems could be involved here.
05-11-2025

[~tschatzl] Thanks for the ping. Our developers gave ok for sharing following logs: ``` I 2024-11-08T16:13:48.276437-08:00 0 [2024-11-08T16:13:48.276-0800][6423.624s][info ][gc,start ] GC(8) Pause Young (Normal) (G1 Evacuation Pause) I 2024-11-08T16:13:48.276475-08:00 0 [2024-11-08T16:13:48.276-0800][6423.624s][info ][gc,task ] GC(8) Using 83 workers of 83 for evacuation I 2024-11-08T16:13:48.276477-08:00 0 [2024-11-08T16:13:48.276-0800][6423.624s][debug][gc,age ] GC(8) Desired survivor size 335544320 bytes, new threshold 15 (max threshold 15) I 2024-11-08T16:13:48.277902-08:00 0 [2024-11-08T16:13:48.277-0800][6423.625s][debug][gc,humongous ] GC(8) Humongous region 0 (object size 16974248 @ 0x00000005f4000000) remset 0 code roots 0 marked 0 reclaim candidate 1 type array 1 I 2024-11-08T16:13:48.285974-08:00 0 [2024-11-08T16:13:48.285-0800][6423.633s][debug][gc,phases ] GC(8) Worker 7 scanned 1 nmethods in heap region 0x000050323c6454d0, accumulated scan time: 0.02ms I 2024-11-08T16:13:48.286012-08:00 0 [2024-11-08T16:13:48.285-0800][6423.633s][debug][gc,phases ] GC(8) Worker 43 scanned 1 nmethods in heap region 0x000050323d95a360, accumulated scan time: 0.01ms I 2024-11-08T16:13:48.286014-08:00 0 [2024-11-08T16:13:48.285-0800][6423.633s][debug][gc,phases ] GC(8) Worker 17 scanned 5 nmethods in heap region 0x000050323e23b440, accumulated scan time: 0.04ms I 2024-11-08T16:13:48.286016-08:00 0 [2024-11-08T16:13:48.285-0800][6423.633s][debug][gc,phases ] GC(8) Worker 7 scanned 3 nmethods in heap region 0x000050323d95b290, accumulated scan time: 0.14ms I 2024-11-08T16:13:48.286017-08:00 0 [2024-11-08T16:13:48.285-0800][6423.633s][debug][gc,phases ] GC(8) Worker 31 scanned 2 nmethods in heap region 0x000050323d95a870, accumulated scan time: 0.03ms I 2024-11-08T16:13:48.286183-08:00 0 [2024-11-08T16:13:48.286-0800][6423.634s][debug][gc,phases ] GC(8) Worker 5 scanned 1 nmethods in heap region 0x000050323e8a30e0, accumulated scan time: 0.01ms I 2024-11-08T16:13:48.287026-08:00 0 [2024-11-08T16:13:48.285-0800][6423.633s][debug][gc,phases ] GC(8) Worker 35 scanned 1 nmethods in heap region 0x000050323e23ba70, accumulated scan time: 0.01ms I 2024-11-08T16:13:48.292000-08:00 0 [2024-11-08T16:13:48.291-0800][6423.639s][debug][gc,phases ] GC(8) Worker 17 scanned 21 nmethods in heap region 0x000050323e4a75f0, accumulated scan time: 0.20ms I 2024-11-08T16:13:48.297106-08:00 0 [2024-11-08T16:13:48.291-0800][6423.639s][debug][gc,phases ] GC(8) Worker 47 scanned 22 nmethods in heap region 0x000050323e4a75f0, accumulated scan time: 0.00ms I 2024-11-08T16:13:48.297162-08:00 0 [2024-11-08T16:13:48.294-0800][6423.642s][debug][gc,phases ] GC(8) Worker 77 scanned 1 nmethods in heap region 0x000050323e4a77a0, accumulated scan time: 0.00ms I 2024-11-08T16:13:48.297234-08:00 0 [2024-11-08T16:13:48.296-0800][6423.644s][debug][gc,phases ] GC(8) Worker 44 scanned 6 nmethods in heap region 0x000050323e23b9e0, accumulated scan time: 0.00ms I 2024-11-08T16:13:48.298087-08:00 0 [2024-11-08T16:13:48.297-0800][6423.645s][debug][gc,phases ] GC(8) Worker 43 scanned 2 nmethods in heap region 0x000050323e23b710, accumulated scan time: 0.12ms I 2024-11-08T16:13:48.298419-08:00 0 [2024-11-08T16:13:48.298-0800][6423.646s][debug][gc,phases ] GC(8) Worker 79 scanned 21 nmethods in heap region 0x000050323e497170, accumulated scan time: 0.00ms I 2024-11-08T16:13:48.308132-08:00 0 [2024-11-08T16:13:48.298-0800][6423.646s][debug][gc,phases ] GC(8) Worker 79 scanned 14 nmethods in heap region 0x000050323e4a7710, accumulated scan time: 9.96ms I 2024-11-08T16:13:48.313207-08:00 0 [2024-11-08T16:13:48.299-0800][6423.647s][debug][gc,phases ] GC(8) Worker 38 scanned 22 nmethods in heap region 0x000050323e4a75f0, accumulated scan time: 0.00ms I 2024-11-08T16:13:48.314091-08:00 0 [2024-11-08T16:13:48.302-0800][6423.650s][debug][gc,phases ] GC(8) Worker 76 scanned 9 nmethods in heap region 0x000050323e4a7320, accumulated scan time: 0.00ms I 2024-11-08T16:13:48.364385-08:00 0 [2024-11-08T16:13:48.364-0800][6423.712s][debug][gc,phases ] GC(8) Worker 45 scanned 27 nmethods in heap region 0x000050323e4a75f0, accumulated scan time: 0.00ms I 2024-11-08T16:13:48.368622-08:00 0 [2024-11-08T16:13:48.368-0800][6423.716s][debug][gc,phases ] GC(8) Worker 28 scanned 38 nmethods in heap region 0x000050323e4a75f0, accumulated scan time: 0.01ms I 2024-11-08T16:13:48.378624-08:00 0 [2024-11-08T16:13:48.378-0800][6423.726s][debug][gc,phases ] GC(8) Worker 1 scanned 15 nmethods in heap region 0x000050323e4b2360, accumulated scan time: 0.04ms I 2024-11-08T16:13:49.077898-08:00 0 [2024-11-08T16:13:49.077-0800][6424.425s][debug][gc,phases ] GC(8) Worker 78 scanned 11 nmethods in heap region 0x000050323e4a7560, accumulated scan time: 0.00ms I 2024-11-08T16:13:49.077929-08:00 0 [2024-11-08T16:13:49.077-0800][6424.425s][debug][gc,phases ] GC(8) Worker 71 scanned 15 nmethods in heap region 0x000050323e4a7200, accumulated scan time: 0.00ms I 2024-11-08T16:13:49.077931-08:00 0 [2024-11-08T16:13:49.077-0800][6424.425s][debug][gc,phases ] GC(8) Worker 53 scanned 13 nmethods in heap region 0x000050323e4a7200, accumulated scan time: 0.00ms I 2024-11-08T16:13:49.077958-08:00 0 [2024-11-08T16:13:49.077-0800][6424.425s][debug][gc,phases ] GC(8) Worker 16 scanned 25 nmethods in heap region 0x000050323e4a75f0, accumulated scan time: 0.02ms I 2024-11-08T16:13:49.079700-08:00 0 [2024-11-08T16:13:49.077-0800][6424.425s][debug][gc,phases ] GC(8) Worker 20 scanned 39 nmethods in heap region 0x000050323e4a7200, accumulated scan time: 0.01ms I 2024-11-08T16:13:49.079706-08:00 0 [2024-11-08T16:13:49.077-0800][6424.425s][debug][gc,phases ] GC(8) Worker 44 scanned 13 nmethods in heap region 0x000050323e4a7200, accumulated scan time: 11.69ms I 2024-11-08T16:13:49.079708-08:00 0 [2024-11-08T16:13:49.078-0800][6424.425s][debug][gc,phases ] GC(8) Worker 20 scanned nmethod count: 39, scan time: 786.58ms I 2024-11-08T16:13:49.079710-08:00 0 [2024-11-08T16:13:49.077-0800][6424.425s][debug][gc,phases ] GC(8) Worker 15 scanned 33 nmethods in heap region 0x000050323e4a7200, accumulated scan time: 0.04ms I 2024-11-08T16:13:49.079711-08:00 0 [2024-11-08T16:13:49.077-0800][6424.425s][debug][gc,phases ] GC(8) Worker 38 scanned 10 nmethods in heap region 0x000050323e4a7200, accumulated scan time: 27.43ms I 2024-11-08T16:13:49.079713-08:00 0 [2024-11-08T16:13:49.078-0800][6424.426s][debug][gc,phases ] GC(8) Worker 53 scanned 22 nmethods in heap region 0x000050323e4a7a70, accumulated scan time: 791.27ms I 2024-11-08T16:13:49.079715-08:00 0 [2024-11-08T16:13:49.078-0800][6424.426s][debug][gc,phases ] GC(8) Worker 28 scanned 14 nmethods in heap region 0x000050323e4b2360, accumulated scan time: 6.22ms I 2024-11-08T16:13:49.079716-08:00 0 [2024-11-08T16:13:49.077-0800][6424.425s][debug][gc,phases ] GC(8) Worker 14 scanned 40 nmethods in heap region 0x000050323e4a7200, accumulated scan time: 0.03ms I 2024-11-08T16:13:49.079721-08:00 0 [2024-11-08T16:13:49.078-0800][6424.426s][debug][gc,phases ] GC(8) Worker 28 scanned nmethod count: 52, scan time: 715.80ms I 2024-11-08T16:13:49.079723-08:00 0 [2024-11-08T16:13:49.077-0800][6424.425s][debug][gc,phases ] GC(8) Worker 10 scanned 14 nmethods in heap region 0x000050323e4a7200, accumulated scan time: 0.05ms I 2024-11-08T16:13:49.079725-08:00 0 [2024-11-08T16:13:49.077-0800][6424.425s][debug][gc,phases ] GC(8) Worker 16 scanned nmethod count: 25, scan time: 792.10ms I 2024-11-08T16:13:49.079726-08:00 0 [2024-11-08T16:13:49.078-0800][6424.426s][debug][gc,phases ] GC(8) Worker 10 scanned nmethod count: 14, scan time: 765.70ms I 2024-11-08T16:13:49.079727-08:00 0 [2024-11-08T16:13:49.077-0800][6424.425s][debug][gc,phases ] GC(8) Worker 47 scanned 13 nmethods in heap region 0x000050323e4a7200, accumulated scan time: 11.31ms I 2024-11-08T16:13:49.079729-08:00 0 [2024-11-08T16:13:49.078-0800][6424.426s][debug][gc,phases ] GC(8) Worker 44 scanned nmethod count: 19, scan time: 792.49ms I 2024-11-08T16:13:49.079730-08:00 0 [2024-11-08T16:13:49.078-0800][6424.426s][debug][gc,phases ] GC(8) Worker 47 scanned nmethod count: 35, scan time: 792.52ms I 2024-11-08T16:13:49.079731-08:00 0 [2024-11-08T16:13:49.078-0800][6424.426s][debug][gc,phases ] GC(8) Worker 80 scanned 33 nmethods in heap region 0x000050323e4a7290, accumulated scan time: 0.00ms I 2024-11-08T16:13:49.079732-08:00 0 [2024-11-08T16:13:49.077-0800][6424.425s][debug][gc,phases ] GC(8) Worker 24 scanned 40 nmethods in heap region 0x000050323e4a7200, accumulated scan time: 0.01ms I 2024-11-08T16:13:49.079734-08:00 0 [2024-11-08T16:13:49.078-0800][6424.426s][debug][gc,phases ] GC(8) Worker 24 scanned nmethod count: 40, scan time: 790.09ms I 2024-11-08T16:13:49.079735-08:00 0 [2024-11-08T16:13:49.077-0800][6424.425s][debug][gc,phases ] GC(8) Worker 69 scanned 29 nmethods in heap region 0x000050323e4a7200, accumulated scan time: 0.00ms I 2024-11-08T16:13:49.079736-08:00 0 [2024-11-08T16:13:49.078-0800][6424.426s][debug][gc,phases ] GC(8) Worker 80 scanned nmethod count: 33, scan time: 789.79ms I 2024-11-08T16:13:49.079737-08:00 0 [2024-11-08T16:13:49.078-0800][6424.426s][debug][gc,phases ] GC(8) Worker 29 scanned 44 nmethods in heap region 0x000050323e4a7200, accumulated scan time: 0.01ms I 2024-11-08T16:13:49.079739-08:00 0 [2024-11-08T16:13:49.078-0800][6424.426s][debug][gc,phases ] GC(8) Worker 29 scanned nmethod count: 44, scan time: 790.48ms I 2024-11-08T16:13:49.079740-08:00 0 [2024-11-08T16:13:49.078-0800][6424.426s][debug][gc,phases ] GC(8) Worker 58 scanned 17 nmethods in heap region 0x000050323e4a7200, accumulated scan time: 0.01ms I 2024-11-08T16:13:49.079741-08:00 0 [2024-11-08T16:13:49.078-0800][6424.426s][debug][gc,phases ] GC(8) Worker 69 scanned nmethod count: 29, scan time: 789.71ms I 2024-11-08T16:13:49.079742-08:00 0 [2024-11-08T16:13:49.078-0800][6424.426s][debug][gc,phases ] GC(8) Worker 14 scanned nmethod count: 40, scan time: 784.06ms I 2024-11-08T16:13:49.079744-08:00 0 [2024-11-08T16:13:49.078-0800][6424.426s][debug][gc,phases ] GC(8) Worker 15 scanned nmethod count: 33, scan time: 786.69ms I 2024-11-08T16:13:49.079745-08:00 0 [2024-11-08T16:13:49.078-0800][6424.426s][debug][gc,phases ] GC(8) Worker 23 scanned 52 nmethods in heap region 0x000050323e4a7200, accumulated scan time: 0.44ms I 2024-11-08T16:13:49.079746-08:00 0 [2024-11-08T16:13:49.078-0800][6424.426s][debug][gc,phases ] GC(8) Worker 45 scanned 19 nmethods in heap region 0x000050323e4b2360, accumulated scan time: 6.05ms I 2024-11-08T16:13:49.079748-08:00 0 [2024-11-08T16:13:49.078-0800][6424.426s][debug][gc,phases ] GC(8) Worker 38 scanned nmethod count: 32, scan time: 792.38ms I 2024-11-08T16:13:49.079749-08:00 0 [2024-11-08T16:13:49.078-0800][6424.426s][debug][gc,phases ] GC(8) Worker 58 scanned nmethod count: 17, scan time: 784.18ms I 2024-11-08T16:13:49.079750-08:00 0 [2024-11-08T16:13:49.078-0800][6424.426s][debug][gc,phases ] GC(8) Worker 23 scanned nmethod count: 52, scan time: 789.42ms I 2024-11-08T16:13:49.079752-08:00 0 [2024-11-08T16:13:49.078-0800][6424.426s][debug][gc,phases ] GC(8) Worker 45 scanned nmethod count: 46, scan time: 720.37ms I 2024-11-08T16:13:49.079753-08:00 0 [2024-11-08T16:13:49.077-0800][6424.425s][debug][gc,phases ] GC(8) Worker 34 scanned 14 nmethods in heap region 0x000050323e4a7200, accumulated scan time: 0.01ms I 2024-11-08T16:13:49.079754-08:00 0 [2024-11-08T16:13:49.078-0800][6424.426s][debug][gc,phases ] GC(8) Worker 34 scanned nmethod count: 14, scan time: 777.64ms I 2024-11-08T16:13:49.079755-08:00 0 [2024-11-08T16:13:49.079-0800][6424.426s][debug][gc,phases ] GC(8) Worker 41 scanned 24 nmethods in heap region 0x000050323e4a75f0, accumulated scan time: 0.00ms I 2024-11-08T16:13:49.079801-08:00 0 [2024-11-08T16:13:49.079-0800][6424.427s][debug][gc,phases ] GC(8) Worker 5 scanned 59 nmethods in heap region 0x000050323e4a7200, accumulated scan time: 1.10ms I 2024-11-08T16:13:49.079828-08:00 0 [2024-11-08T16:13:49.079-0800][6424.427s][debug][gc,phases ] GC(8) Worker 5 scanned nmethod count: 60, scan time: 793.78ms I 2024-11-08T16:13:49.079833-08:00 0 [2024-11-08T16:13:49.079-0800][6424.427s][debug][gc,phases ] GC(8) Worker 62 scanned 81 nmethods in heap region 0x000050323e4a7200, accumulated scan time: 0.00ms I 2024-11-08T16:13:49.079838-08:00 0 [2024-11-08T16:13:49.079-0800][6424.427s][debug][gc,phases ] GC(8) Worker 62 scanned nmethod count: 81, scan time: 792.49ms I 2024-11-08T16:13:49.080280-08:00 0 [2024-11-08T16:13:49.077-0800][6424.425s][debug][gc,phases ] GC(8) Worker 73 scanned 37 nmethods in heap region 0x000050323e4a7200, accumulated scan time: 0.00ms I 2024-11-08T16:13:49.080304-08:00 0 [2024-11-08T16:13:49.079-0800][6424.427s][debug][gc,phases ] GC(8) Worker 73 scanned nmethod count: 37, scan time: 791.82ms I 2024-11-08T16:13:49.080306-08:00 0 [2024-11-08T16:13:49.080-0800][6424.427s][debug][gc,phases ] GC(8) Worker 71 scanned 10 nmethods in heap region 0x000050323e4a7950, accumulated scan time: 783.55ms I 2024-11-08T16:13:49.080307-08:00 0 [2024-11-08T16:13:49.080-0800][6424.428s][debug][gc,phases ] GC(8) Worker 8 scanned 29 nmethods in heap region 0x000050323e4a7200, accumulated scan time: 0.04ms I 2024-11-08T16:13:49.080309-08:00 0 [2024-11-08T16:13:49.080-0800][6424.428s][debug][gc,phases ] GC(8) Worker 12 scanned 34 nmethods in heap region 0x000050323e4a7200, accumulated scan time: 0.04ms I 2024-11-08T16:13:49.080310-08:00 0 [2024-11-08T16:13:49.080-0800][6424.428s][debug][gc,phases ] GC(8) Worker 81 scanned 27 nmethods in heap region 0x000050323e4a7d40, accumulated scan time: 0.00ms I 2024-11-08T16:13:49.080311-08:00 0 [2024-11-08T16:13:49.080-0800][6424.428s][debug][gc,phases ] GC(8) Worker 78 scanned 6 nmethods in heap region 0x000050323e4a7d40, accumulated scan time: 789.52ms I 2024-11-08T16:13:49.080312-08:00 0 [2024-11-08T16:13:49.080-0800][6424.428s][debug][gc,phases ] GC(8) Worker 17 scanned 31 nmethods in heap region 0x000050323e4a7200, accumulated scan time: 6.42ms I 2024-11-08T16:13:49.080313-08:00 0 [2024-11-08T16:13:49.080-0800][6424.428s][debug][gc,phases ] GC(8) Worker 8 scanned nmethod count: 29, scan time: 788.69ms I 2024-11-08T16:13:49.080314-08:00 0 [2024-11-08T16:13:49.080-0800][6424.428s][debug][gc,phases ] GC(8) Worker 81 scanned nmethod count: 27, scan time: 791.47ms I 2024-11-08T16:13:49.080315-08:00 0 [2024-11-08T16:13:49.080-0800][6424.428s][debug][gc,phases ] GC(8) Worker 12 scanned nmethod count: 34, scan time: 784.13ms I 2024-11-08T16:13:49.080316-08:00 0 [2024-11-08T16:13:49.080-0800][6424.428s][debug][gc,phases ] GC(8) Worker 66 scanned 30 nmethods in heap region 0x000050323e4a7200, accumulated scan time: 0.00ms I 2024-11-08T16:13:49.080319-08:00 0 [2024-11-08T16:13:49.080-0800][6424.428s][debug][gc,phases ] GC(8) Worker 72 scanned 12 nmethods in heap region 0x000050323e4a7200, accumulated scan time: 0.00ms I 2024-11-08T16:13:49.080320-08:00 0 [2024-11-08T16:13:49.080-0800][6424.428s][debug][gc,phases ] GC(8) Worker 51 scanned 13 nmethods in heap region 0x000050323e4a7200, accumulated scan time: 0.00ms I 2024-11-08T16:13:49.080326-08:00 0 [2024-11-08T16:13:49.080-0800][6424.428s][debug][gc,phases ] GC(8) Worker 11 scanned 13 nmethods in heap region 0x000050323e4a7200, accumulated scan time: 0.03ms I 2024-11-08T16:13:49.080352-08:00 0 [2024-11-08T16:13:49.080-0800][6424.428s][debug][gc,phases ] GC(8) Worker 55 scanned 9 nmethods in heap region 0x000050323e4a7200, accumulated scan time: 0.00ms I 2024-11-08T16:13:49.080385-08:00 0 [2024-11-08T16:13:49.080-0800][6424.428s][debug][gc,phases ] GC(8) Worker 68 scanned 31 nmethods in heap region 0x000050323e4a7200, accumulated scan time: 0.00ms I 2024-11-08T16:13:49.080448-08:00 0 [2024-11-08T16:13:49.080-0800][6424.428s][debug][gc,phases ] GC(8) Worker 39 scanned 24 nmethods in heap region 0x000050323e4a7830, accumulated scan time: 0.03ms I 2024-11-08T16:13:49.080453-08:00 0 [2024-11-08T16:13:49.080-0800][6424.428s][debug][gc,phases ] GC(8) Worker 26 scanned 9 nmethods in heap region 0x000050323e4a7200, accumulated scan time: 0.01ms I 2024-11-08T16:13:49.080455-08:00 0 [2024-11-08T16:13:49.080-0800][6424.428s][debug][gc,phases ] GC(8) Worker 39 scanned nmethod count: 24, scan time: 534.23ms I 2024-11-08T16:13:49.080459-08:00 0 [2024-11-08T16:13:49.077-0800][6424.425s][debug][gc,phases ] GC(8) Worker 1 scanned 36 nmethods in heap region 0x000050323e4a7290, accumulated scan time: 0.20ms I 2024-11-08T16:13:49.080494-08:00 0 [2024-11-08T16:13:49.080-0800][6424.428s][debug][gc,phases ] GC(8) Worker 68 scanned nmethod count: 31, scan time: 785.91ms I 2024-11-08T16:13:49.080496-08:00 0 [2024-11-08T16:13:49.080-0800][6424.428s][debug][gc,phases ] GC(8) Worker 17 scanned nmethod count: 57, scan time: 794.61ms I 2024-11-08T16:13:49.080527-08:00 0 [2024-11-08T16:13:49.080-0800][6424.428s][debug][gc,phases ] GC(8) Worker 27 scanned 16 nmethods in heap region 0x000050323e4a7200, accumulated scan time: 0.01ms I 2024-11-08T16:13:49.080531-08:00 0 [2024-11-08T16:13:49.080-0800][6424.428s][debug][gc,phases ] GC(8) Worker 71 scanned nmethod count: 25, scan time: 785.69ms I 2024-11-08T16:13:49.081171-08:00 0 [2024-11-08T16:13:49.080-0800][6424.428s][debug][gc,phases ] GC(8) Worker 79 scanned 28 nmethods in heap region 0x000050323e4a7290, accumulated scan time: 24.09ms I 2024-11-08T16:13:49.081195-08:00 0 [2024-11-08T16:13:49.080-0800][6424.428s][debug][gc,phases ] GC(8) Worker 6 scanned 10 nmethods in heap region 0x000050323e4a7200, accumulated scan time: 0.05ms I 2024-11-08T16:13:49.081203-08:00 0 [2024-11-08T16:13:49.080-0800][6424.428s][debug][gc,phases ] GC(8) Worker 79 scanned nmethod count: 63, scan time: 792.12ms I 2024-11-08T16:13:49.081206-08:00 0 [2024-11-08T16:13:49.080-0800][6424.428s][debug][gc,phases ] GC(8) Worker 65 scanned 15 nmethods in heap region 0x000050323e4a7200, accumulated scan time: 0.00ms I 2024-11-08T16:13:49.081231-08:00 0 [2024-11-08T16:13:49.080-0800][6424.428s][debug][gc,phases ] GC(8) Worker 72 scanned nmethod count: 12, scan time: 792.63ms I 2024-11-08T16:13:49.081233-08:00 0 [2024-11-08T16:13:49.080-0800][6424.428s][debug][gc,phases ] GC(8) Worker 66 scanned nmethod count: 30, scan time: 791.18ms I 2024-11-08T16:13:49.081234-08:00 0 [2024-11-08T16:13:49.080-0800][6424.428s][debug][gc,phases ] GC(8) Worker 65 scanned nmethod count: 15, scan time: 792.11ms I 2024-11-08T16:13:49.081235-08:00 0 [2024-11-08T16:13:49.080-0800][6424.428s][debug][gc,phases ] GC(8) Worker 1 scanned nmethod count: 51, scan time: 702.06ms I 2024-11-08T16:13:49.081236-08:00 0 [2024-11-08T16:13:49.080-0800][6424.428s][debug][gc,phases ] GC(8) Worker 78 scanned nmethod count: 17, scan time: 791.79ms I 2024-11-08T16:13:49.081238-08:00 0 [2024-11-08T16:13:49.080-0800][6424.428s][debug][gc,phases ] GC(8) Worker 26 scanned nmethod count: 9, scan time: 789.61ms I 2024-11-08T16:13:49.081241-08:00 0 [2024-11-08T16:13:49.080-0800][6424.428s][debug][gc,phases ] GC(8) Worker 25 scanned 11 nmethods in heap region 0x000050323e4a7200, accumulated scan time: 0.01ms I 2024-11-08T16:13:49.081242-08:00 0 [2024-11-08T16:13:49.080-0800][6424.428s][debug][gc,phases ] GC(8) Worker 43 scanned 19 nmethods in heap region 0x000050323e4a7200, accumulated scan time: 12.51ms I 2024-11-08T16:13:49.081243-08:00 0 [2024-11-08T16:13:49.080-0800][6424.428s][debug][gc,phases ] GC(8) Worker 27 scanned nmethod count: 16, scan time: 791.18ms I 2024-11-08T16:13:49.081245-08:00 0 [2024-11-08T16:13:49.080-0800][6424.428s][debug][gc,phases ] GC(8) Worker 11 scanned nmethod count: 13, scan time: 785.69ms I 2024-11-08T16:13:49.081246-08:00 0 [2024-11-08T16:13:49.080-0800][6424.428s][debug][gc,phases ] GC(8) Worker 77 scanned 9 nmethods in heap region 0x000050323e4a74d0, accumulated scan time: 2.51ms I 2024-11-08T16:13:49.081248-08:00 0 [2024-11-08T16:13:49.080-0800][6424.428s][debug][gc,phases ] GC(8) Worker 6 scanned nmethod count: 10, scan time: 733.26ms I 2024-11-08T16:13:49.081249-08:00 0 [2024-11-08T16:13:49.080-0800][6424.428s][debug][gc,phases ] GC(8) Worker 77 scanned nmethod count: 10, scan time: 786.31ms I 2024-11-08T16:13:49.081250-08:00 0 [2024-11-08T16:13:49.080-0800][6424.428s][debug][gc,phases ] GC(8) Worker 19 scanned 24 nmethods in heap region 0x000050323e4a7200, accumulated scan time: 0.03ms I 2024-11-08T16:13:49.081251-08:00 0 [2024-11-08T16:13:49.080-0800][6424.428s][debug][gc,phases ] GC(8) Worker 51 scanned nmethod count: 13, scan time: 793.93ms I 2024-11-08T16:13:49.081253-08:00 0 [2024-11-08T16:13:49.081-0800][6424.429s][debug][gc,phases ] GC(8) Worker 59 scanned 15 nmethods in heap region 0x000050323e4a7200, accumulated scan time: 0.00ms I 2024-11-08T16:13:49.081254-08:00 0 [2024-11-08T16:13:49.080-0800][6424.428s][debug][gc,phases ] GC(8) Worker 43 scanned nmethod count: 22, scan time: 795.46ms I 2024-11-08T16:13:49.081255-08:00 0 [2024-11-08T16:13:49.081-0800][6424.429s][debug][gc,phases ] GC(8) Worker 59 scanned nmethod count: 15, scan time: 793.90ms I 2024-11-08T16:13:49.081531-08:00 0 [2024-11-08T16:13:49.080-0800][6424.428s][debug][gc,phases ] GC(8) Worker 19 scanned nmethod count: 24, scan time: 771.78ms I 2024-11-08T16:13:49.081537-08:00 0 [2024-11-08T16:13:49.080-0800][6424.428s][debug][gc,phases ] GC(8) Worker 76 scanned 24 nmethods in heap region 0x000050323e4a73b0, accumulated scan time: 25.10ms I 2024-11-08T16:13:49.081539-08:00 0 [2024-11-08T16:13:49.081-0800][6424.429s][debug][gc,phases ] GC(8) Worker 40 scanned 17 nmethods in heap region 0x000050323e4a7200, accumulated scan time: 0.03ms I 2024-11-08T16:13:49.081543-08:00 0 [2024-11-08T16:13:49.080-0800][6424.428s][debug][gc,phases ] GC(8) Worker 55 scanned nmethod count: 9, scan time: 793.77ms I 2024-11-08T16:13:49.081580-08:00 0 [2024-11-08T16:13:49.081-0800][6424.429s][debug][gc,phases ] GC(8) Worker 76 scanned nmethod count: 33, scan time: 793.20ms I 2024-11-08T16:13:49.081603-08:00 0 [2024-11-08T16:13:49.078-0800][6424.426s][debug][gc,phases ] GC(8) Worker 53 scanned nmethod count: 35, scan time: 791.52ms I 2024-11-08T16:13:49.081606-08:00 0 [2024-11-08T16:13:49.081-0800][6424.429s][debug][gc,phases ] GC(8) Worker 40 scanned nmethod count: 17, scan time: 756.92ms I 2024-11-08T16:13:49.081742-08:00 0 [2024-11-08T16:13:49.080-0800][6424.428s][debug][gc,phases ] GC(8) Worker 25 scanned nmethod count: 11, scan time: 790.67ms I 2024-11-08T16:13:49.081953-08:00 0 [2024-11-08T16:13:49.081-0800][6424.429s][debug][gc,phases ] GC(8) Worker 41 scanned nmethod count: 24, scan time: 757.20ms I 2024-11-08T16:13:49.082092-08:00 0 [2024-11-08T16:13:49.078-0800][6424.426s][debug][gc,phases ] GC(8) Worker 61 scanned 30 nmethods in heap region 0x000050323e4a7200, accumulated scan time: 0.00ms I 2024-11-08T16:13:49.082168-08:00 0 [2024-11-08T16:13:49.082-0800][6424.430s][debug][gc,phases ] GC(8) Worker 61 scanned nmethod count: 30, scan time: 794.90ms I 2024-11-08T16:13:49.082659-08:00 0 [2024-11-08T16:13:49.082-0800][6424.430s][debug][gc,phases ] GC(8) Worker 42 scanned 33 nmethods in heap region 0x000050323e4a7200, accumulated scan time: 0.02ms I 2024-11-08T16:13:49.082703-08:00 0 [2024-11-08T16:13:49.082-0800][6424.430s][debug][gc,phases ] GC(8) Worker 42 scanned nmethod count: 33, scan time: 788.38ms I 2024-11-08T16:13:49.082987-08:00 0 [2024-11-08T16:13:49.082-0800][6424.430s][debug][gc,phases ] GC(8) Worker 60 scanned 50 nmethods in heap region 0x000050323e4a7200, accumulated scan time: 0.00ms I 2024-11-08T16:13:49.083088-08:00 0 [2024-11-08T16:13:49.082-0800][6424.430s][debug][gc,phases ] GC(8) Worker 60 scanned nmethod count: 50, scan time: 794.74ms I 2024-11-08T16:13:49.123275-08:00 0 [2024-11-08T16:13:49.123-0800][6424.471s][debug][gc,phases ] GC(8) Worker 82 scanned 19 nmethods in heap region 0x000050323e4a7a70, accumulated scan time: 0.00ms I 2024-11-08T16:13:49.123298-08:00 0 [2024-11-08T16:13:49.123-0800][6424.471s][debug][gc,phases ] GC(8) Worker 7 scanned 61 nmethods in heap region 0x000050323e4a7200, accumulated scan time: 0.68ms I 2024-11-08T16:13:49.123327-08:00 0 [2024-11-08T16:13:49.123-0800][6424.471s][debug][gc,phases ] GC(8) Worker 4 scanned 36 nmethods in heap region 0x000050323e4a7200, accumulated scan time: 0.06ms I 2024-11-08T16:13:49.123331-08:00 0 [2024-11-08T16:13:49.123-0800][6424.471s][debug][gc,phases ] GC(8) Worker 82 scanned nmethod count: 19, scan time: 833.70ms I 2024-11-08T16:13:49.123355-08:00 0 [2024-11-08T16:13:49.123-0800][6424.471s][debug][gc,phases ] GC(8) Worker 4 scanned nmethod count: 36, scan time: 815.96ms I 2024-11-08T16:13:49.123387-08:00 0 [2024-11-08T16:13:49.123-0800][6424.471s][debug][gc,phases ] GC(8) Worker 54 scanned 21 nmethods in heap region 0x000050323e4a7200, accumulated scan time: 0.00ms I 2024-11-08T16:13:49.123420-08:00 0 [2024-11-08T16:13:49.123-0800][6424.471s][debug][gc,phases ] GC(8) Worker 63 scanned 10 nmethods in heap region 0x000050323e4a7200, accumulated scan time: 0.00ms I 2024-11-08T16:13:49.123493-08:00 0 [2024-11-08T16:13:49.123-0800][6424.471s][debug][gc,phases ] GC(8) Worker 7 scanned nmethod count: 65, scan time: 787.69ms I 2024-11-08T16:13:49.123518-08:00 0 [2024-11-08T16:13:49.123-0800][6424.471s][debug][gc,phases ] GC(8) Worker 13 scanned 64 nmethods in heap region 0x000050323e4a7200, accumulated scan time: 0.06ms I 2024-11-08T16:13:49.123551-08:00 0 [2024-11-08T16:13:49.123-0800][6424.471s][debug][gc,phases ] GC(8) Worker 13 scanned nmethod count: 64, scan time: 836.42ms I 2024-11-08T16:13:49.123568-08:00 0 [2024-11-08T16:13:49.123-0800][6424.471s][debug][gc,phases ] GC(8) Worker 2 scanned 25 nmethods in heap region 0x000050323e4a7200, accumulated scan time: 0.05ms I 2024-11-08T16:13:49.123585-08:00 0 [2024-11-08T16:13:49.123-0800][6424.471s][debug][gc,phases ] GC(8) Worker 2 scanned nmethod count: 25, scan time: 833.89ms I 2024-11-08T16:13:49.123604-08:00 0 [2024-11-08T16:13:49.123-0800][6424.471s][debug][gc,phases ] GC(8) Worker 33 scanned 41 nmethods in heap region 0x000050323e4a7200, accumulated scan time: 0.01ms I 2024-11-08T16:13:49.123655-08:00 0 [2024-11-08T16:13:49.123-0800][6424.471s][debug][gc,phases ] GC(8) Worker 22 scanned 18 nmethods in heap region 0x000050323e4a7200, accumulated scan time: 0.01ms I 2024-11-08T16:13:49.123662-08:00 0 [2024-11-08T16:13:49.123-0800][6424.471s][debug][gc,phases ] GC(8) Worker 50 scanned 34 nmethods in heap region 0x000050323e4a7200, accumulated scan time: 0.00ms I 2024-11-08T16:13:49.123696-08:00 0 [2024-11-08T16:13:49.123-0800][6424.471s][debug][gc,phases ] GC(8) Worker 63 scanned nmethod count: 10, scan time: 836.01ms I 2024-11-08T16:13:49.123711-08:00 0 [2024-11-08T16:13:49.123-0800][6424.471s][debug][gc,phases ] GC(8) Worker 18 scanned 23 nmethods in heap region 0x000050323e4b2360, accumulated scan time: 0.05ms I 2024-11-08T16:13:49.123732-08:00 0 [2024-11-08T16:13:49.123-0800][6424.471s][debug][gc,phases ] GC(8) Worker 46 scanned 32 nmethods in heap region 0x000050323e4a75f0, accumulated scan time: 0.00ms I 2024-11-08T16:13:49.123734-08:00 0 [2024-11-08T16:13:49.123-0800][6424.471s][debug][gc,phases ] GC(8) Worker 18 scanned nmethod count: 23, scan time: 747.11ms I 2024-11-08T16:13:49.123761-08:00 0 [2024-11-08T16:13:49.123-0800][6424.471s][debug][gc,phases ] GC(8) Worker 46 scanned nmethod count: 32, scan time: 838.04ms I 2024-11-08T16:13:49.123824-08:00 0 [2024-11-08T16:13:49.123-0800][6424.471s][debug][gc,phases ] GC(8) Worker 56 scanned 15 nmethods in heap region 0x000050323e4a7200, accumulated scan time: 0.00ms I 2024-11-08T16:13:49.123840-08:00 0 [2024-11-08T16:13:49.123-0800][6424.471s][debug][gc,phases ] GC(8) Worker 22 scanned nmethod count: 18, scan time: 785.81ms I 2024-11-08T16:13:49.123965-08:00 0 [2024-11-08T16:13:49.123-0800][6424.471s][debug][gc,phases ] GC(8) Worker 37 scanned 25 nmethods in heap region 0x000050323e4a7200, accumulated scan time: 0.02ms I 2024-11-08T16:13:49.123990-08:00 0 [2024-11-08T16:13:49.123-0800][6424.471s][debug][gc,phases ] GC(8) Worker 37 scanned nmethod count: 25, scan time: 825.52ms I 2024-11-08T16:13:49.124044-08:00 0 [2024-11-08T16:13:49.124-0800][6424.471s][debug][gc,phases ] GC(8) Worker 75 scanned 39 nmethods in heap region 0x000050323e4a7200, accumulated scan time: 0.00ms I 2024-11-08T16:13:49.124342-08:00 0 [2024-11-08T16:13:49.124-0800][6424.472s][debug][gc,phases ] GC(8) Worker 75 scanned nmethod count: 39, scan time: 835.90ms I 2024-11-08T16:13:49.124368-08:00 0 [2024-11-08T16:13:49.123-0800][6424.471s][debug][gc,phases ] GC(8) Worker 33 scanned nmethod count: 41, scan time: 829.13ms I 2024-11-08T16:13:49.124369-08:00 0 [2024-11-08T16:13:49.123-0800][6424.471s][debug][gc,phases ] GC(8) Worker 0 scanned 22 nmethods in heap region 0x000050323e4a7200, accumulated scan time: 0.05ms I 2024-11-08T16:13:49.124372-08:00 0 [2024-11-08T16:13:49.124-0800][6424.472s][debug][gc,phases ] GC(8) Worker 0 scanned nmethod count: 22, scan time: 829.27ms I 2024-11-08T16:13:49.124465-08:00 0 [2024-11-08T16:13:49.123-0800][6424.471s][debug][gc,phases ] GC(8) Worker 30 scanned 29 nmethods in heap region 0x000050323e4a7200, accumulated scan time: 0.03ms I 2024-11-08T16:13:49.124469-08:00 0 [2024-11-08T16:13:49.124-0800][6424.472s][debug][gc,phases ] GC(8) Worker 30 scanned nmethod count: 29, scan time: 825.65ms I 2024-11-08T16:13:49.124661-08:00 0 [2024-11-08T16:13:49.123-0800][6424.471s][debug][gc,phases ] GC(8) Worker 50 scanned nmethod count: 34, scan time: 837.40ms I 2024-11-08T16:13:49.125636-08:00 0 [2024-11-08T16:13:49.124-0800][6424.472s][debug][gc,phases ] GC(8) Worker 56 scanned nmethod count: 15, scan time: 837.81ms I 2024-11-08T16:13:49.125642-08:00 0 [2024-11-08T16:13:49.124-0800][6424.472s][debug][gc,phases ] GC(8) Worker 67 scanned 44 nmethods in heap region 0x000050323e4a7200, accumulated scan time: 0.00ms I 2024-11-08T16:13:49.125643-08:00 0 [2024-11-08T16:13:49.124-0800][6424.472s][debug][gc,phases ] GC(8) Worker 67 scanned nmethod count: 44, scan time: 837.15ms I 2024-11-08T16:13:49.125644-08:00 0 [2024-11-08T16:13:49.124-0800][6424.472s][debug][gc,phases ] GC(8) Worker 3 scanned 14 nmethods in heap region 0x000050323e4a7200, accumulated scan time: 0.05ms I 2024-11-08T16:13:49.125646-08:00 0 [2024-11-08T16:13:49.124-0800][6424.472s][debug][gc,phases ] GC(8) Worker 32 scanned 15 nmethods in heap region 0x000050323e4a7200, accumulated scan time: 0.01ms I 2024-11-08T16:13:49.125647-08:00 0 [2024-11-08T16:13:49.124-0800][6424.472s][debug][gc,phases ] GC(8) Worker 3 scanned nmethod count: 14, scan time: 789.40ms I 2024-11-08T16:13:49.125648-08:00 0 [2024-11-08T16:13:49.124-0800][6424.472s][debug][gc,phases ] GC(8) Worker 32 scanned nmethod count: 15, scan time: 821.92ms I 2024-11-08T16:13:49.125649-08:00 0 [2024-11-08T16:13:49.123-0800][6424.471s][debug][gc,phases ] GC(8) Worker 54 scanned nmethod count: 21, scan time: 837.00ms I 2024-11-08T16:13:49.125650-08:00 0 [2024-11-08T16:13:49.124-0800][6424.472s][debug][gc,phases ] GC(8) Worker 64 scanned 39 nmethods in heap region 0x000050323e4a7200, accumulated scan time: 0.00ms I 2024-11-08T16:13:49.125657-08:00 0 [2024-11-08T16:13:49.124-0800][6424.472s][debug][gc,phases ] GC(8) Worker 64 scanned nmethod count: 39, scan time: 837.47ms I 2024-11-08T16:13:49.125658-08:00 0 [2024-11-08T16:13:49.124-0800][6424.472s][debug][gc,phases ] GC(8) Worker 57 scanned 27 nmethods in heap region 0x000050323e4a7200, accumulated scan time: 0.00ms I 2024-11-08T16:13:49.125659-08:00 0 [2024-11-08T16:13:49.125-0800][6424.472s][debug][gc,phases ] GC(8) Worker 57 scanned nmethod count: 27, scan time: 837.28ms I 2024-11-08T16:13:49.125660-08:00 0 [2024-11-08T16:13:49.125-0800][6424.473s][debug][gc,phases ] GC(8) Worker 74 scanned 20 nmethods in heap region 0x000050323e4a7200, accumulated scan time: 0.00ms I 2024-11-08T16:13:49.125661-08:00 0 [2024-11-08T16:13:49.125-0800][6424.473s][debug][gc,phases ] GC(8) Worker 21 scanned 29 nmethods in heap region 0x000050323e4a7200, accumulated scan time: 0.01ms I 2024-11-08T16:13:49.125663-08:00 0 [2024-11-08T16:13:49.124-0800][6424.472s][debug][gc,phases ] GC(8) Worker 9 scanned 19 nmethods in heap region 0x000050323e4a7200, accumulated scan time: 0.05ms I 2024-11-08T16:13:49.125664-08:00 0 [2024-11-08T16:13:49.125-0800][6424.473s][debug][gc,phases ] GC(8) Worker 21 scanned nmethod count: 29, scan time: 836.95ms I 2024-11-08T16:13:49.125664-08:00 0 [2024-11-08T16:13:49.125-0800][6424.473s][debug][gc,phases ] GC(8) Worker 9 scanned nmethod count: 19, scan time: 837.58ms I 2024-11-08T16:13:49.125666-08:00 0 [2024-11-08T16:13:49.125-0800][6424.473s][debug][gc,phases ] GC(8) Worker 31 scanned 20 nmethods in heap region 0x000050323e4a7200, accumulated scan time: 0.56ms I 2024-11-08T16:13:49.125667-08:00 0 [2024-11-08T16:13:49.125-0800][6424.473s][debug][gc,phases ] GC(8) Worker 31 scanned nmethod count: 22, scan time: 840.04ms I 2024-11-08T16:13:49.125668-08:00 0 [2024-11-08T16:13:49.125-0800][6424.473s][debug][gc,phases ] GC(8) Worker 70 scanned 22 nmethods in heap region 0x000050323e4a7200, accumulated scan time: 0.00ms I 2024-11-08T16:13:49.125669-08:00 0 [2024-11-08T16:13:49.125-0800][6424.473s][debug][gc,phases ] GC(8) Worker 70 scanned nmethod count: 22, scan time: 831.12ms I 2024-11-08T16:13:49.126165-08:00 0 [2024-11-08T16:13:49.125-0800][6424.473s][debug][gc,phases ] GC(8) Worker 74 scanned nmethod count: 20, scan time: 830.55ms I 2024-11-08T16:13:49.127654-08:00 0 [2024-11-08T16:13:49.126-0800][6424.474s][debug][gc,phases ] GC(8) Worker 49 scanned 13 nmethods in heap region 0x000050323e4a7200, accumulated scan time: 0.00ms I 2024-11-08T16:13:49.127662-08:00 0 [2024-11-08T16:13:49.127-0800][6424.475s][debug][gc,phases ] GC(8) Worker 36 scanned 16 nmethods in heap region 0x000050323e4a7200, accumulated scan time: 0.01ms I 2024-11-08T16:13:49.127663-08:00 0 [2024-11-08T16:13:49.127-0800][6424.475s][debug][gc,phases ] GC(8) Worker 36 scanned nmethod count: 16, scan time: 827.61ms I 2024-11-08T16:13:49.128453-08:00 0 [2024-11-08T16:13:49.127-0800][6424.475s][debug][gc,phases ] GC(8) Worker 48 scanned 15 nmethods in heap region 0x000050323e4a7200, accumulated scan time: 0.00ms I 2024-11-08T16:13:49.128459-08:00 0 [2024-11-08T16:13:49.127-0800][6424.475s][debug][gc,phases ] GC(8) Worker 35 scanned 32 nmethods in heap region 0x000050323e4a7200, accumulated scan time: 1.58ms I 2024-11-08T16:13:49.128460-08:00 0 [2024-11-08T16:13:49.127-0800][6424.475s][debug][gc,phases ] GC(8) Worker 48 scanned nmethod count: 15, scan time: 842.06ms I 2024-11-08T16:13:49.128461-08:00 0 [2024-11-08T16:13:49.127-0800][6424.475s][debug][gc,phases ] GC(8) Worker 35 scanned nmethod count: 33, scan time: 842.55ms I 2024-11-08T16:13:49.128463-08:00 0 [2024-11-08T16:13:49.127-0800][6424.475s][debug][gc,phases ] GC(8) Worker 49 scanned nmethod count: 13, scan time: 840.81ms I 2024-11-08T16:13:49.128464-08:00 0 [2024-11-08T16:13:49.128-0800][6424.476s][debug][gc,phases ] GC(8) Worker 52 scanned 34 nmethods in heap region 0x000050323e4a7200, accumulated scan time: 0.00ms I 2024-11-08T16:13:49.128466-08:00 0 [2024-11-08T16:13:49.128-0800][6424.476s][debug][gc,phases ] GC(8) Worker 52 scanned nmethod count: 34, scan time: 841.04ms I 2024-11-08T16:13:49.156054-08:00 0 [2024-11-08T16:13:49.155-0800][6424.503s][debug][gc,ref ] GC(8) ReferenceProcessor::execute queues: 6, RefProcThreadModel::Multi, marks_oops_alive: false I 2024-11-08T16:13:49.157049-08:00 0 [2024-11-08T16:13:49.157-0800][6424.504s][debug][gc,ref ] GC(8) ReferenceProcessor::execute queues: 83, RefProcThreadModel::Multi, marks_oops_alive: true I 2024-11-08T16:13:49.160241-08:00 0 [2024-11-08T16:13:49.160-0800][6424.508s][debug][gc,ref ] GC(8) ReferenceProcessor::execute queues: 2, RefProcThreadModel::Multi, marks_oops_alive: false I 2024-11-08T16:13:49.172507-08:00 0 [2024-11-08T16:13:49.172-0800][6424.520s][debug][gc,codecache ] CodeCache: size=147456Kb used=13975Kb max_used=13989Kb free=133480Kb I 2024-11-08T16:13:49.172616-08:00 0 [2024-11-08T16:13:49.172-0800][6424.520s][info ][gc,phases ] GC(8) Pre Evacuate Collection Set: 3.4ms I 2024-11-08T16:13:49.172621-08:00 0 [2024-11-08T16:13:49.172-0800][6424.520s][debug][gc,phases ] GC(8) Pre Evacuate Prepare: 0.8ms I 2024-11-08T16:13:49.172637-08:00 0 [2024-11-08T16:13:49.172-0800][6424.520s][debug][gc,phases ] GC(8) JT Retire TLABs And Flush Logs (ms): Min: 0.0, Avg: 0.3, Max: 0.6, Diff: 0.5, Sum: 0.6, Workers: 2 I 2024-11-08T16:13:49.172727-08:00 0 [2024-11-08T16:13:49.172-0800][6424.520s][debug][gc,phases ] GC(8) Non-JT Flush Logs (ms): Min: 0.1, Avg: 0.1, Max: 0.1, Diff: 0.0, Sum: 0.1, Workers: 1 I 2024-11-08T16:13:49.172730-08:00 0 [2024-11-08T16:13:49.172-0800][6424.520s][debug][gc,phases ] GC(8) Choose Collection Set: 0.0ms I 2024-11-08T16:13:49.172731-08:00 0 [2024-11-08T16:13:49.172-0800][6424.520s][debug][gc,phases ] GC(8) Region Register: 2.6ms I 2024-11-08T16:13:49.172733-08:00 0 [2024-11-08T16:13:49.172-0800][6424.520s][debug][gc,phases ] GC(8) Prepare Heap Roots: 0.0ms I 2024-11-08T16:13:49.172734-08:00 0 [2024-11-08T16:13:49.172-0800][6424.520s][info ][gc,phases ] GC(8) Merge Heap Roots: 1.0ms I 2024-11-08T16:13:49.172735-08:00 0 [2024-11-08T16:13:49.172-0800][6424.520s][debug][gc,phases ] GC(8) Prepare Merge Heap Roots: 0.0ms I 2024-11-08T16:13:49.172736-08:00 0 [2024-11-08T16:13:49.172-0800][6424.520s][debug][gc,phases ] GC(8) Remembered Sets (ms): Min: 0.0, Avg: 0.0, Max: 0.2, Diff: 0.1, Sum: 1.3, Workers: 83 I 2024-11-08T16:13:49.172737-08:00 0 [2024-11-08T16:13:49.172-0800][6424.520s][debug][gc,phases ] GC(8) Eager Reclaim (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0, Workers: 1 I 2024-11-08T16:13:49.172738-08:00 0 [2024-11-08T16:13:49.172-0800][6424.520s][debug][gc,phases ] GC(8) Merged Inline Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0, Workers: 83 I 2024-11-08T16:13:49.172740-08:00 0 [2024-11-08T16:13:49.172-0800][6424.520s][debug][gc,phases ] GC(8) Merged ArrayOfCards Min: 0, Avg: 0.0, Max: 1, Diff: 1, Sum: 1, Workers: 83 I 2024-11-08T16:13:49.172740-08:00 0 [2024-11-08T16:13:49.172-0800][6424.520s][debug][gc,phases ] GC(8) Merged Howl Min: 0, Avg: 0.0, Max: 1, Diff: 1, Sum: 1, Workers: 83 I 2024-11-08T16:13:49.172743-08:00 0 [2024-11-08T16:13:49.172-0800][6424.520s][debug][gc,phases ] GC(8) Merged Full Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0, Workers: 83 I 2024-11-08T16:13:49.172744-08:00 0 [2024-11-08T16:13:49.172-0800][6424.520s][debug][gc,phases ] GC(8) Merged Howl Inline Min: 0, Avg: 0.1, Max: 7, Diff: 7, Sum: 7, Workers: 83 I 2024-11-08T16:13:49.172745-08:00 0 [2024-11-08T16:13:49.172-0800][6424.520s][debug][gc,phases ] GC(8) Merged Howl ArrayOfCards Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0, Workers: 83 I 2024-11-08T16:13:49.172774-08:00 0 [2024-11-08T16:13:49.172-0800][6424.520s][debug][gc,phases ] GC(8) Merged Howl BitMap Min: 0, Avg: 0.0, Max: 1, Diff: 1, Sum: 1, Workers: 83 I 2024-11-08T16:13:49.172775-08:00 0 [2024-11-08T16:13:49.172-0800][6424.520s][debug][gc,phases ] GC(8) Merged Howl Full Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0, Workers: 83 I 2024-11-08T16:13:49.172777-08:00 0 [2024-11-08T16:13:49.172-0800][6424.520s][debug][gc,phases ] GC(8) Merged Cards Min: 8, Avg: 12.7, Max: 360, Diff: 352, Sum: 1050, Workers: 83 I 2024-11-08T16:13:49.172779-08:00 0 [2024-11-08T16:13:49.172-0800][6424.520s][debug][gc,phases ] GC(8) Log Buffers (ms): Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.1, Sum: 0.2, Workers: 83 I 2024-11-08T16:13:49.172780-08:00 0 [2024-11-08T16:13:49.172-0800][6424.520s][debug][gc,phases ] GC(8) Dirty Cards: Min: 0, Avg: 5.4, Max: 372, Diff: 372, Sum: 451, Workers: 83 I 2024-11-08T16:13:49.172782-08:00 0 [2024-11-08T16:13:49.172-0800][6424.520s][debug][gc,phases ] GC(8) Skipped Cards: Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0, Workers: 83 I 2024-11-08T16:13:49.172787-08:00 0 [2024-11-08T16:13:49.172-0800][6424.520s][info ][gc,phases ] GC(8) Evacuate Collection Set: 874.0ms I 2024-11-08T16:13:49.172789-08:00 0 [2024-11-08T16:13:49.172-0800][6424.520s][debug][gc,phases ] GC(8) Ext Root Scanning (ms): Min: 0.0, Avg: 3.0, Max: 65.3, Diff: 65.3, Sum: 248.6, Workers: 83 I 2024-11-08T16:13:49.173434-08:00 0 [2024-11-08T16:13:49.172-0800][6424.520s][debug][gc,phases ] GC(8) Scan Heap Roots (ms): Min: 0.0, Avg: 0.0, Max: 0.3, Diff: 0.3, Sum: 0.8, Workers: 83 I 2024-11-08T16:13:49.173439-08:00 0 [2024-11-08T16:13:49.172-0800][6424.520s][debug][gc,phases ] GC(8) Scanned Cards: Min: 0, Avg: 4.7, Max: 149, Diff: 149, Sum: 386, Workers: 83 I 2024-11-08T16:13:49.173441-08:00 0 [2024-11-08T16:13:49.172-0800][6424.520s][debug][gc,phases ] GC(8) Scanned Blocks: Min: 0, Avg: 1.8, Max: 49, Diff: 49, Sum: 153, Workers: 83 I 2024-11-08T16:13:49.173442-08:00 0 [2024-11-08T16:13:49.172-0800][6424.520s][debug][gc,phases ] GC(8) Claimed Chunks: Min: 0, Avg: 0.1, Max: 2, Diff: 2, Sum: 9, Workers: 83 I 2024-11-08T16:13:49.173444-08:00 0 [2024-11-08T16:13:49.172-0800][6424.520s][debug][gc,phases ] GC(8) Found Roots: Min: 0, Avg: 23.7, Max: 849, Diff: 849, Sum: 1964, Workers: 83 I 2024-11-08T16:13:49.173446-08:00 0 [2024-11-08T16:13:49.172-0800][6424.520s][debug][gc,phases ] GC(8) Code Root Scan (ms): Min: 534.2, Avg: 796.5, Max: 842.5, Diff: 308.3, Sum: 66113.0, Workers: 83 I 2024-11-08T16:13:49.173448-08:00 0 [2024-11-08T16:13:49.172-0800][6424.520s][debug][gc,phases ] GC(8) Scanned Nmethods Min: 9, Avg: 29.0, Max: 81, Diff: 72, Sum: 2411, Workers: 83 I 2024-11-08T16:13:49.173449-08:00 0 [2024-11-08T16:13:49.172-0800][6424.520s][debug][gc,phases ] GC(8) Object Copy (ms): Min: 0.0, Avg: 12.5, Max: 197.0, Diff: 197.0, Sum: 1037.5, Workers: 83 I 2024-11-08T16:13:49.173451-08:00 0 [2024-11-08T16:13:49.172-0800][6424.520s][debug][gc,phases ] GC(8) Termination (ms): Min: 0.2, Avg: 31.1, Max: 74.6, Diff: 74.4, Sum: 2582.1, Workers: 83 I 2024-11-08T16:13:49.173453-08:00 0 [2024-11-08T16:13:49.173-0800][6424.520s][debug][gc,phases ] GC(8) Termination Attempts: Min: 1, Avg: 1.8, Max: 6, Diff: 5, Sum: 152, Workers: 83 I 2024-11-08T16:13:49.173454-08:00 0 [2024-11-08T16:13:49.173-0800][6424.520s][debug][gc,phases ] GC(8) GC Worker Other (ms): Min: 0.0, Avg: 1.2, Max: 13.8, Diff: 13.8, Sum: 103.2, Workers: 83 I 2024-11-08T16:13:49.173456-08:00 0 [2024-11-08T16:13:49.173-0800][6424.520s][debug][gc,phases ] GC(8) GC Worker Total (ms): Min: 839.0, Avg: 844.4, Max: 866.7, Diff: 27.8, Sum: 70085.2, Workers: 83 I 2024-11-08T16:13:49.173457-08:00 0 [2024-11-08T16:13:49.173-0800][6424.520s][info ][gc,phases ] GC(8) Post Evacuate Collection Set: 17.2ms I 2024-11-08T16:13:49.173458-08:00 0 [2024-11-08T16:13:49.173-0800][6424.521s][debug][gc,phases ] GC(8) NMethod List Cleanup: 0.3ms I 2024-11-08T16:13:49.173460-08:00 0 [2024-11-08T16:13:49.173-0800][6424.521s][debug][gc,phases ] GC(8) Reference Processing: 4.9ms I 2024-11-08T16:13:49.173461-08:00 0 [2024-11-08T16:13:49.173-0800][6424.521s][debug][gc,phases,ref] GC(8) Notify Soft/WeakReferences: 1.5ms I 2024-11-08T16:13:49.173463-08:00 0 [2024-11-08T16:13:49.173-0800][6424.521s][debug][gc,phases,ref] GC(8) Balance queues: 0.4ms I 2024-11-08T16:13:49.173464-08:00 0 [2024-11-08T16:13:49.173-0800][6424.521s][debug][gc,phases,ref] GC(8) SoftRef (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0, Workers: 6 I 2024-11-08T16:13:49.173466-08:00 0 [2024-11-08T16:13:49.173-0800][6424.521s][debug][gc,phases,ref] GC(8) WeakRef (ms): Min: 0.1, Avg: 0.3, Max: 0.5, Diff: 0.4, Sum: 2.0, Workers: 6 I 2024-11-08T16:13:49.173468-08:00 0 [2024-11-08T16:13:49.173-0800][6424.521s][debug][gc,phases,ref] GC(8) FinalRef (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0, Workers: 6 I 2024-11-08T16:13:49.173469-08:00 0 [2024-11-08T16:13:49.173-0800][6424.521s][debug][gc,phases,ref] GC(8) Total (ms): Min: 0.9, Avg: 0.9, Max: 1.0, Diff: 0.1, Sum: 5.6, Workers: 6 I 2024-11-08T16:13:49.173477-08:00 0 [2024-11-08T16:13:49.173-0800][6424.521s][debug][gc,phases,ref] GC(8) Notify and keep alive finalizable: 3.1ms I 2024-11-08T16:13:49.173487-08:00 0 [2024-11-08T16:13:49.173-0800][6424.521s][debug][gc,phases,ref] GC(8) Balance queues: 0.0ms I 2024-11-08T16:13:49.173489-08:00 0 [2024-11-08T16:13:49.173-0800][6424.521s][debug][gc,phases,ref] GC(8) FinalRef (ms): Min: 0.2, Avg: 1.4, Max: 2.6, Diff: 2.4, Sum: 116.0, Workers: 83 I 2024-11-08T16:13:49.173491-08:00 0 [2024-11-08T16:13:49.173-0800][6424.521s][debug][gc,phases,ref] GC(8) Notify PhantomReferences: 0.3ms I 2024-11-08T16:13:49.173493-08:00 0 [2024-11-08T16:13:49.173-0800][6424.521s][debug][gc,phases,ref] GC(8) Balance queues: 0.0ms I 2024-11-08T16:13:49.173494-08:00 0 [2024-11-08T16:13:49.173-0800][6424.521s][debug][gc,phases,ref] GC(8) PhantomRef (ms): Min: 0.1, Avg: 0.1, Max: 0.1, Diff: 0.0, Sum: 0.2, Workers: 2 I 2024-11-08T16:13:49.173496-08:00 0 [2024-11-08T16:13:49.173-0800][6424.521s][debug][gc,phases,ref] GC(8) SoftReference Discovered: 0, Dropped: 0, Processed: 0 I 2024-11-08T16:13:49.173498-08:00 0 [2024-11-08T16:13:49.173-0800][6424.521s][debug][gc,phases,ref] GC(8) WeakReference Discovered: 5042, Dropped: 4475, Processed: 567 I 2024-11-08T16:13:49.173500-08:00 0 [2024-11-08T16:13:49.173-0800][6424.521s][debug][gc,phases,ref] GC(8) FinalReference Discovered: 256, Dropped: 0, Processed: 256 I 2024-11-08T16:13:49.173501-08:00 0 [2024-11-08T16:13:49.173-0800][6424.521s][debug][gc,phases,ref] GC(8) PhantomReference Discovered: 1551, Dropped: 165, Processed: 1386 I 2024-11-08T16:13:49.173503-08:00 0 [2024-11-08T16:13:49.173-0800][6424.521s][debug][gc,phases ] GC(8) Weak Processing: 6.7ms I 2024-11-08T16:13:49.173505-08:00 0 [2024-11-08T16:13:49.173-0800][6424.521s][debug][gc,phases ] GC(8) VM Weak Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1, Workers: 47 I 2024-11-08T16:13:49.173506-08:00 0 [2024-11-08T16:13:49.173-0800][6424.521s][debug][gc,phases ] GC(8) Dead Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0, Workers: 47 I 2024-11-08T16:13:49.173508-08:00 0 [2024-11-08T16:13:49.173-0800][6424.521s][debug][gc,phases ] GC(8) Total Min: 0, Avg: 12.9, Max: 220, Diff: 220, Sum: 604, Workers: 47 I 2024-11-08T16:13:49.173511-08:00 0 [2024-11-08T16:13:49.173-0800][6424.521s][debug][gc,phases ] GC(8) ObjectSynchronizer Weak Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0, Workers: 47 I 2024-11-08T16:13:49.173513-08:00 0 [2024-11-08T16:13:49.173-0800][6424.521s][debug][gc,phases ] GC(8) Dead Min: 0, Avg: 0.0, Max: 2, Diff: 2, Sum: 2, Workers: 47 I 2024-11-08T16:13:49.173515-08:00 0 [2024-11-08T16:13:49.173-0800][6424.521s][debug][gc,phases ] GC(8) Total Min: 0, Avg: 1.1, Max: 36, Diff: 36, Sum: 52, Workers: 47 I 2024-11-08T16:13:49.173516-08:00 0 [2024-11-08T16:13:49.173-0800][6424.521s][debug][gc,phases ] GC(8) JVMTI Tag Weak OopStorage Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0, Workers: 47 I 2024-11-08T16:13:49.173535-08:00 0 [2024-11-08T16:13:49.173-0800][6424.521s][debug][gc,phases ] GC(8) Dead Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0, Workers: 47 I 2024-11-08T16:13:49.173537-08:00 0 [2024-11-08T16:13:49.173-0800][6424.521s][debug][gc,phases ] GC(8) Total Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0, Workers: 47 I 2024-11-08T16:13:49.173539-08:00 0 [2024-11-08T16:13:49.173-0800][6424.521s][debug][gc,phases ] GC(8) StringTable Weak Min: 0.0, Avg: 0.4, Max: 6.5, Diff: 6.5, Sum: 18.1, Workers: 47 I 2024-11-08T16:13:49.173540-08:00 0 [2024-11-08T16:13:49.173-0800][6424.521s][debug][gc,phases ] GC(8) Dead Min: 0, Avg: 5.2, Max: 47, Diff: 47, Sum: 244, Workers: 47 I 2024-11-08T16:13:49.173542-08:00 0 [2024-11-08T16:13:49.173-0800][6424.521s][debug][gc,phases ] GC(8) Total Min: 0, Avg: 835.6, Max: 2880, Diff: 2880, Sum: 39273, Workers: 47 I 2024-11-08T16:13:49.173546-08:00 0 [2024-11-08T16:13:49.173-0800][6424.521s][debug][gc,phases ] GC(8) ResolvedMethodTable Weak Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.1, Sum: 0.5, Workers: 47 I 2024-11-08T16:13:49.173549-08:00 0 [2024-11-08T16:13:49.173-0800][6424.521s][debug][gc,phases ] GC(8) Dead Min: 0, Avg: 3.7, Max: 35, Diff: 35, Sum: 174, Workers: 47 I 2024-11-08T16:13:49.173553-08:00 0 [2024-11-08T16:13:49.173-0800][6424.521s][debug][gc,phases ] GC(8) Total Min: 0, Avg: 96.8, Max: 455, Diff: 455, Sum: 4551, Workers: 47 I 2024-11-08T16:13:49.173556-08:00 0 [2024-11-08T16:13:49.173-0800][6424.521s][debug][gc,phases ] GC(8) Tsan weak OopStorage Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0, Workers: 47 I 2024-11-08T16:13:49.173563-08:00 0 [2024-11-08T16:13:49.173-0800][6424.521s][debug][gc,phases ] GC(8) Dead Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0, Workers: 47 I 2024-11-08T16:13:49.173566-08:00 0 [2024-11-08T16:13:49.173-0800][6424.521s][debug][gc,phases ] GC(8) Total Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0, Workers: 47 I 2024-11-08T16:13:49.173569-08:00 0 [2024-11-08T16:13:49.173-0800][6424.521s][debug][gc,phases ] GC(8) JNI Weak Min: 0.0, Avg: 1.0, Max: 3.6, Diff: 3.6, Sum: 47.3, Workers: 47 I 2024-11-08T16:13:49.173573-08:00 0 [2024-11-08T16:13:49.173-0800][6424.521s][debug][gc,phases ] GC(8) Dead Min: 0, Avg: 47.9, Max: 128, Diff: 128, Sum: 2250, Workers: 47 I 2024-11-08T16:13:49.173576-08:00 0 [2024-11-08T16:13:49.173-0800][6424.521s][debug][gc,phases ] GC(8) Total Min: 0, Avg: 48.7, Max: 128, Diff: 128, Sum: 2288, Workers: 47 I 2024-11-08T16:13:49.173580-08:00 0 [2024-11-08T16:13:49.173-0800][6424.521s][debug][gc,phases ] GC(8) StringDedup Table Weak Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0, Workers: 47 I 2024-11-08T16:13:49.173583-08:00 0 [2024-11-08T16:13:49.173-0800][6424.521s][debug][gc,phases ] GC(8) Dead Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0, Workers: 47 I 2024-11-08T16:13:49.173587-08:00 0 [2024-11-08T16:13:49.173-0800][6424.521s][debug][gc,phases ] GC(8) Total Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0, Workers: 47 I 2024-11-08T16:13:49.173593-08:00 0 [2024-11-08T16:13:49.173-0800][6424.521s][debug][gc,phases ] GC(8) StringDedup Requests0 Weak Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0, Workers: 47 I 2024-11-08T16:13:49.173596-08:00 0 [2024-11-08T16:13:49.173-0800][6424.521s][debug][gc,phases ] GC(8) Dead Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0, Workers: 47 I 2024-11-08T16:13:49.173598-08:00 0 [2024-11-08T16:13:49.173-0800][6424.521s][debug][gc,phases ] GC(8) Total Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0, Workers: 47 I 2024-11-08T16:13:49.173599-08:00 0 [2024-11-08T16:13:49.173-0800][6424.521s][debug][gc,phases ] GC(8) StringDedup Requests1 Weak Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0, Workers: 47 I 2024-11-08T16:13:49.173601-08:00 0 [2024-11-08T16:13:49.173-0800][6424.521s][debug][gc,phases ] GC(8) Dead Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0, Workers: 47 I 2024-11-08T16:13:49.173603-08:00 0 [2024-11-08T16:13:49.173-0800][6424.521s][debug][gc,phases ] GC(8) Total Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0, Workers: 47 I 2024-11-08T16:13:49.173608-08:00 0 [2024-11-08T16:13:49.173-0800][6424.521s][debug][gc,phases ] GC(8) Weak JFR Old Object Samples Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0, Workers: 47 I 2024-11-08T16:13:49.173609-08:00 0 [2024-11-08T16:13:49.173-0800][6424.521s][debug][gc,phases ] GC(8) Dead Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0, Workers: 47 I 2024-11-08T16:13:49.173612-08:00 0 [2024-11-08T16:13:49.173-0800][6424.521s][debug][gc,phases ] GC(8) Total Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0, Workers: 47 I 2024-11-08T16:13:49.173615-08:00 0 [2024-11-08T16:13:49.173-0800][6424.521s][debug][gc,phases ] GC(8) Post Evacuate Cleanup 1: 2.6ms I 2024-11-08T16:13:49.173616-08:00 0 [2024-11-08T16:13:49.173-0800][6424.521s][debug][gc,phases ] GC(8) Merge Per-Thread State (ms): Min: 0.2, Avg: 0.2, Max: 0.2, Diff: 0.0, Sum: 0.2, Workers: 1 I 2024-11-08T16:13:49.173621-08:00 0 [2024-11-08T16:13:49.173-0800][6424.521s][debug][gc,phases ] GC(8) Copied Bytes Min: 0, Avg: 742986.9, Max: 23568616, Diff: 23568616, Sum: 61667912, Workers: 83 I 2024-11-08T16:13:49.173632-08:00 0 [2024-11-08T16:13:49.173-0800][6424.521s][debug][gc,phases ] GC(8) LAB Waste Min: 0, Avg: 888.1, Max: 54752, Diff: 54752, Sum: 73712, Workers: 83 I 2024-11-08T16:13:49.173652-08:00 0 [2024-11-08T16:13:49.173-0800][6424.521s][debug][gc,phases ] GC(8) LAB Undo Waste Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0, Workers: 83 I 2024-11-08T16:13:49.173682-08:00 0 [2024-11-08T16:13:49.173-0800][6424.521s][debug][gc,phases ] GC(8) Clear Logged Cards (ms): Min: 0.0, Avg: 0.6, Max: 2.5, Diff: 2.5, Sum: 7.6, Workers: 12 I 2024-11-08T16:13:49.173684-08:00 0 [2024-11-08T16:13:49.173-0800][6424.521s][debug][gc,phases ] GC(8) Recalculate Used Memory (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0, Workers: 1 I 2024-11-08T16:13:49.173687-08:00 0 [2024-11-08T16:13:49.173-0800][6424.521s][debug][gc,phases ] GC(8) Post Evacuate Cleanup 2: 2.5ms I 2024-11-08T16:13:49.173690-08:00 0 [2024-11-08T16:13:49.173-0800][6424.521s][debug][gc,phases ] GC(8) Update Derived Pointers (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0, Workers: 1 I 2024-11-08T16:13:49.173698-08:00 0 [2024-11-08T16:13:49.173-0800][6424.521s][debug][gc,phases ] GC(8) Eagerly Reclaim Humongous Objects (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0, Workers: 1 I 2024-11-08T16:13:49.173705-08:00 0 [2024-11-08T16:13:49.173-0800][6424.521s][debug][gc,phases ] GC(8) Humongous Total Min: 1, Avg: 1.0, Max: 1, Diff: 0, Sum: 1, Workers: 1 I 2024-11-08T16:13:49.173711-08:00 0 [2024-11-08T16:13:49.173-0800][6424.521s][debug][gc,phases ] GC(8) Humongous Candidates Min: 1, Avg: 1.0, Max: 1, Diff: 0, Sum: 1, Workers: 1 I 2024-11-08T16:13:49.173730-08:00 0 [2024-11-08T16:13:49.173-0800][6424.521s][debug][gc,phases ] GC(8) Humongous Reclaimed Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0, Workers: 1 I 2024-11-08T16:13:49.173742-08:00 0 [2024-11-08T16:13:49.173-0800][6424.521s][debug][gc,phases ] GC(8) Redirty Logged Cards (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1, Workers: 83 I 2024-11-08T16:13:49.173745-08:00 0 [2024-11-08T16:13:49.173-0800][6424.521s][debug][gc,phases ] GC(8) Redirtied Cards: Min: 0, Avg: 4.9, Max: 305, Diff: 305, Sum: 405, Workers: 83 I 2024-11-08T16:13:49.173748-08:00 0 [2024-11-08T16:13:49.173-0800][6424.521s][debug][gc,phases ] GC(8) Resize TLABs (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0, Workers: 83 I 2024-11-08T16:13:49.173759-08:00 0 [2024-11-08T16:13:49.173-0800][6424.521s][debug][gc,phases ] GC(8) Free Collection Set (ms): Min: 0.0, Avg: 0.6, Max: 2.3, Diff: 2.3, Sum: 52.8, Workers: 83 I 2024-11-08T16:13:49.173762-08:00 0 [2024-11-08T16:13:49.173-0800][6424.521s][debug][gc,phases ] GC(8) Rebuild Free List: 0.2ms I 2024-11-08T16:13:49.173768-08:00 0 [2024-11-08T16:13:49.173-0800][6424.521s][debug][gc,phases ] GC(8) Prepare For Mutator: 0.0ms I 2024-11-08T16:13:49.173772-08:00 0 [2024-11-08T16:13:49.173-0800][6424.521s][debug][gc,phases ] GC(8) Expand Heap After Collection: 0.0ms I 2024-11-08T16:13:49.173778-08:00 0 [2024-11-08T16:13:49.173-0800][6424.521s][info ][gc,phases ] GC(8) Other: 0.6ms I 2024-11-08T16:13:49.173779-08:00 0 [2024-11-08T16:13:49.173-0800][6424.521s][trace][gc,age ] GC(8) Age table with threshold 15 (max threshold 15) I 2024-11-08T16:13:49.173782-08:00 0 [2024-11-08T16:13:49.173-0800][6424.521s][trace][gc,age ] GC(8) - age 1: 15118040 bytes, 15118040 total I 2024-11-08T16:13:49.173785-08:00 0 [2024-11-08T16:13:49.173-0800][6424.521s][trace][gc,age ] GC(8) - age 2: 19940664 bytes, 35058704 total I 2024-11-08T16:13:49.173789-08:00 0 [2024-11-08T16:13:49.173-0800][6424.521s][trace][gc,age ] GC(8) - age 3: 27560 bytes, 35086264 total I 2024-11-08T16:13:49.173800-08:00 0 [2024-11-08T16:13:49.173-0800][6424.521s][trace][gc,age ] GC(8) - age 4: 70008 bytes, 35156272 total I 2024-11-08T16:13:49.173801-08:00 0 [2024-11-08T16:13:49.173-0800][6424.521s][trace][gc,age ] GC(8) - age 5: 16933088 bytes, 52089360 total I 2024-11-08T16:13:49.173804-08:00 0 [2024-11-08T16:13:49.173-0800][6424.521s][trace][gc,age ] GC(8) - age 6: 9578552 bytes, 61667912 total I 2024-11-08T16:13:49.173848-08:00 0 [2024-11-08T16:13:49.173-0800][6424.521s][info ][gc,heap ] GC(8) Eden regions: 155->0(154) I 2024-11-08T16:13:49.173851-08:00 0 [2024-11-08T16:13:49.173-0800][6424.521s][info ][gc,heap ] GC(8) Survivor regions: 2->3(20) I 2024-11-08T16:13:49.173854-08:00 0 [2024-11-08T16:13:49.173-0800][6424.521s][info ][gc,heap ] GC(8) Old regions: 1->1 I 2024-11-08T16:13:49.173864-08:00 0 [2024-11-08T16:13:49.173-0800][6424.521s][info ][gc,heap ] GC(8) Humongous regions: 1->1 I 2024-11-08T16:13:49.173899-08:00 0 [2024-11-08T16:13:49.173-0800][6424.521s][info ][gc,metaspace ] GC(8) Metaspace: 90071K(90880K)->90071K(90880K) NonClass: 79673K(80128K)->79673K(80128K) Class: 10398K(10752K)->10398K(10752K) I 2024-11-08T16:13:49.173936-08:00 0 [2024-11-08T16:13:49.173-0800][6424.521s][info ][gc ] GC(8) Pause Young (Normal) (G1 Evacuation Pause) 5043M->101M(8384M) 897.645ms I 2024-11-08T16:13:49.174085-08:00 0 [2024-11-08T16:13:49.174-0800][6424.522s][info ][gc,cpu ] GC(8) User=4.49s Sys=13.73s Real=0.90s ``` Three worker threads had noticeable higher scanning time in following regions, however the number of scanned nmethods were not high in those cases. Worker 53 scanned 22 nmethods in heap region 0x000050323e4a7a70, accumulated scan time: 791.27ms Worker 71 scanned 10 nmethods in heap region 0x000050323e4a7950, accumulated scan time: 783.55ms Worker 78 scanned 6 nmethods in heap region 0x000050323e4a7d40, accumulated scan time: 789.52ms
05-11-2025

[~jiangli]: any feedback from your dev team? As mentioned, just the "Scanned NMethods" output would give useful information about the situation, but more complete logs of single garbage collections (with `gc+phases=debug`) as suggested above would be appreciated.
04-11-2025

Current logs with only type of collection/region info (current eden/survivor/old/humongous)/"Scanned NMethods" would already give some useful statistics to better understand the problem.
10-06-2025

Hi [~tschatzl], I'm checking with the developers to see if they are okay with sharing the detailed GC logs. I didn't capture/record the logs for GCs with non-problematic pauses, so I'm also asking the developers if they still retain logs from the old runs to get additional info. (The application has been running with increased initial code root table size for several months.) I'll update you on the bug once I hear back from them. Thanks!
04-06-2025

Hi [~jiangli]! thanks for the report, interesting. I have got lots of questions: * Since JDK-8315605 is also in that build, what does `Scanned Nmethods` show in these cases compared to other GCs? * Can you provide a log with at least one of these problematic GCs and a few similar that do not show the problem with `gc+phases=debug`? One problem could be malloc() stalling (it tends to be not scalable) - the nmethods of surviving objects are ultimately copied over to new regions, and if there are many (and there are many threads), malloc'ing the subsequently growing result code root sets could stall, and would explain what you can see. In the worst case, potentially instrumenting the add() to the code root set might show the issue as this being the largest contributor. * In the CHT add(), the use of a single scoped critical section may also be problematic - if I remember correctly, the global GlobalCounter (i.e. a single critical section object) is used for all CHTs, so maybe the application is overloading that one. * Another much less likely option could be what JDK-8316212 refers to, that making less calls to the CHT could improve the situation. * Also, is there some particular platform you are seeing this, like aarch64 or only x64? (Or tried on only one) * Does this reproduce on later JDKs? (Probably, but just to be sure) * In the worst case, replacing malloc with a manual allocator could be an option like we do for the remembered sets. That would not be my first choice though. Without statistics and measurements this is hard to gauge what the best option is. * One could also experiment with the chain length of the buckets. Thanks, Thomas
03-06-2025

> Using a very large code root hash-table increased memory usages since the code root table was per region. The memory overhead became problematic when very large Java heap was used. One can make the next base current code root set size some statistical value of the existing ones for a particular set of regions (e.g. per type/generation) to right size it, with some backpressure (e.g. from that value, always take half, or just round down) to reduce/minimize that issue. Getting this statistics for your application per GC/per region might allow simulating various heuristics. (And it would probably be nice to have for some log messages too, like for remembered sets)
03-06-2025