Since jdk-24 x64Windows we have been seeing sanity.openjdk GC outOfMemory failures: Ref: #6555 (comment)
09:54:39 REASON: User specified action: run main/othervm -XX:+UseZGC -Xlog:gc*,gc+stats=off -Xmx256M -XX:+UnlockDiagnosticVMOptions -XX:+ZStressRelocateInPlace gc.z.TestRelocateInPlace
09:54:39 TIME: 0.422 seconds
09:54:39 messages:
09:54:39 command: main -XX:+UseZGC -Xlog:gc*,gc+stats=off -Xmx256M -XX:+UnlockDiagnosticVMOptions -XX:+ZStressRelocateInPlace gc.z.TestRelocateInPlace
09:54:39 reason: User specified action: run main/othervm -XX:+UseZGC -Xlog:gc*,gc+stats=off -Xmx256M -XX:+UnlockDiagnosticVMOptions -XX:+ZStressRelocateInPlace gc.z.TestRelocateInPlace
09:54:39 started: Tue Sep 16 08:54:38 UTC 2025
09:54:39 Mode: othervm [/othervm specified]
09:54:39 Process id: 12116
09:54:39 finished: Tue Sep 16 08:54:39 UTC 2025
09:54:39 elapsed time (seconds): 0.422
09:54:39 configuration:
09:54:39 STDOUT:
09:54:39 [0.015s][info][gc,init] Initializing The Z Garbage Collector
09:54:39 [0.015s][info][gc,init] Version: 25-beta+36-ea (release)
09:54:39 [0.015s][info][gc,init] NUMA Support: Disabled
09:54:39 [0.015s][info][gc,init] CPUs: 4 total, 4 available
09:54:39 [0.015s][info][gc,init] Memory: 8140M
09:54:39 [0.016s][info][gc,init] Large Page Support: Disabled
09:54:39 [0.016s][info][gc,init] Address Space Size: limited (137434267212K)
09:54:39 [0.016s][info][gc,init] Reserved Space Type: Contiguous/Unrestricted/Complete
09:54:39 [0.016s][info][gc,init] Reserved Space Size: 4G
09:54:39 [0.016s][info][gc,init] Min Capacity: 8M
09:54:39 [0.016s][info][gc,init] Initial Capacity: 128M
09:54:39 [0.016s][info][gc,init] Max Capacity: 256M
09:54:39 [0.016s][info][gc,init] Soft Max Capacity: 256M
09:54:39 [0.016s][info][gc,init] Page Size Medium: Range [2M, 8M]
09:54:39 [0.016s][info][gc,init] Pre-touch: Disabled
09:54:39 [0.016s][info][gc,init] Uncommit: Enabled
09:54:39 [0.016s][info][gc,init] Uncommit Delay: 300s
09:54:39 [0.016s][info][gc,init] GC Workers for Old Generation: 1 (dynamic)
09:54:39 [0.017s][info][gc,init] GC Workers for Young Generation: 1 (dynamic)
09:54:39 [0.021s][info][gc,init] GC Workers Max: 1 (dynamic)
09:54:39 [0.022s][info][gc,init] Runtime Workers: 2
09:54:39 [0.022s][info][gc ] Using The Z Garbage Collector
09:54:39 [0.051s][info][gc,metaspace] CDS archive(s) mapped at: [0x000000001c000000-0x000000001cdd0000-0x000000001cdd0000), size 14483456, SharedBaseAddress: 0x000000001c000000, ArchiveRelocationMode: 1.
09:54:39 [0.051s][info][gc,metaspace] Compressed class space mapped at: 0x000000001d000000-0x000000005d000000, reserved size: 1073741824
09:54:39 [0.051s][info][gc,metaspace] UseCompressedClassPointers 1, UseCompactObjectHeaders 0
09:54:39 [0.051s][info][gc,metaspace] Narrow klass pointer bits 32, Max shift 3
09:54:39 [0.051s][info][gc,metaspace] Narrow klass base: 0x000000001c000000, Narrow klass shift: 0
09:54:39 [0.051s][info][gc,metaspace] Encoding Range: [0x000000001c000000 - 0x000000011c000000), (4294967296 bytes)
09:54:39 [0.051s][info][gc,metaspace] Klass Range: [0x000000001c010000 - 0x000000005d000000), (1090453504 bytes)
09:54:39 [0.051s][info][gc,metaspace] Klass ID Range: [65536 - 1090519033) (1090453497)
09:54:39 [0.051s][info][gc,metaspace] Protection zone: [0x000000001c000000 - 0x000000001c010000), (65536 bytes)
09:54:39 Iteration 0
09:54:39 Allocating
09:54:39 [0.192s][info][gc ] GC(0) Major Collection (Warmup)
09:54:39 [0.192s][info][gc,task ] GC(0) Using 1 Workers for Young Generation
09:54:39 [0.192s][info][gc,task ] GC(0) Using 1 Workers for Old Generation
09:54:39 [0.192s][info][gc,phases ] GC(0) Y: Young Generation
09:54:39 [0.193s][info][gc,phases ] GC(0) Y: Pause Mark Start (Major) 0.048ms
09:54:39 [0.200s][info][gc,phases ] GC(0) Y: Concurrent Mark 7.074ms
09:54:39 [0.200s][info][gc,phases ] GC(0) Y: Pause Mark End 0.028ms
09:54:39 [0.200s][info][gc,phases ] GC(0) Y: Concurrent Mark Free 0.003ms
09:54:39 [0.200s][info][gc,phases ] GC(0) Y: Concurrent Reset Relocation Set 0.027ms
09:54:39 [0.200s][info][gc,reloc ] GC(0) Y: Using tenuring threshold: 1 (Computed)
09:54:39 [0.201s][info][gc,phases ] GC(0) Y: Concurrent Select Relocation Set 0.550ms
09:54:39 [0.201s][info][gc,phases ] GC(0) Y: Pause Relocate Start 0.013ms
09:54:39 [0.204s][info][gc,phases ] GC(0) Y: Concurrent Relocate 3.282ms
09:54:39 [0.204s][info][gc,alloc ] GC(0) Y: Mark Start Mark End Relocate Start Relocate End
09:54:39 [0.204s][info][gc,alloc ] GC(0) Y: Allocation Stalls: 0 0 0 0
09:54:39 [0.204s][info][gc,load ] GC(0) Y: Load: 0.00 (0%) / 0.00 (0%) / 0.00 (0%)
09:54:39 [0.204s][info][gc,mmu ] GC(0) Y: MMU: 2ms/97.6%, 5ms/99.0%, 10ms/99.1%, 20ms/99.6%, 50ms/99.8%, 100ms/99.9%
09:54:39 [0.204s][info][gc,marking ] GC(0) Y: Mark: 1 stripe(s), 2 proactive flush(es), 1 terminate flush(es), 0 completion(s), 0 continuation(s)
09:54:39 [0.204s][info][gc,nmethod ] GC(0) Y: NMethods: 239 registered, 0 unregistered
09:54:39 [0.204s][info][gc,metaspace] GC(0) Y: Metaspace: 0M used, 0M committed, 1088M reserved
09:54:39 [0.204s][info][gc,reloc ] GC(0) Y: Candidates Selected In-Place Size Empty Relocated
09:54:39 [0.204s][info][gc,reloc ] GC(0) Y: Small Pages: 13 2 1 26M 0M 1M
09:54:39 [0.204s][info][gc,reloc ] GC(0) Y: Medium Pages: 0 0 0 0M 0M 0M
09:54:39 [0.204s][info][gc,reloc ] GC(0) Y: Large Pages: 0 0 0 0M 0M 0M
09:54:39 [0.204s][info][gc,reloc ] GC(0) Y: Forwarding Usage: 0M
09:54:39 [0.204s][info][gc,reloc ] GC(0) Y: Age Table:
09:54:39 [0.204s][info][gc,reloc ] GC(0) Y: Live Garbage Small Medium Large
09:54:39 [0.204s][info][gc,reloc ] GC(0) Y: Eden 20M (8%) 5M (2%) 13 / 2 0 / 0 0 / 0
09:54:39 [0.204s][info][gc,heap ] GC(0) Y: Min Capacity: 8M(3%)
09:54:39 [0.204s][info][gc,heap ] GC(0) Y: Max Capacity: 256M(100%)
09:54:39 [0.204s][info][gc,heap ] GC(0) Y: Soft Max Capacity: 256M(100%)
09:54:39 [0.204s][info][gc,heap ] GC(0) Y: Heap Statistics:
09:54:39 [0.204s][info][gc,heap ] GC(0) Y: Mark Start Mark End Relocate Start Relocate End High Low
09:54:39 [0.204s][info][gc,heap ] GC(0) Y: Capacity: 128M (50%) 128M (50%) 128M (50%) 128M (50%) 128M (50%) 128M (50%)
09:54:39 [0.204s][info][gc,heap ] GC(0) Y: Free: 230M (90%) 222M (87%) 222M (87%) 218M (85%) 230M (90%) 216M (84%)
09:54:39 [0.204s][info][gc,heap ] GC(0) Y: Used: 26M (10%) 34M (13%) 34M (13%) 38M (15%) 40M (16%) 26M (10%)
09:54:39 [0.204s][info][gc,heap ] GC(0) Y: Young Generation Statistics:
09:54:39 [0.204s][info][gc,heap ] GC(0) Y: Mark Start Mark End Relocate Start Relocate End
09:54:39 [0.204s][info][gc,heap ] GC(0) Y: Used: 26M (10%) 34M (13%) 34M (13%) 38M (15%)
09:54:39 [0.204s][info][gc,heap ] GC(0) Y: Live: - 20M (8%) 20M (8%) 20M (8%)
09:54:39 [0.204s][info][gc,heap ] GC(0) Y: Garbage: - 5M (2%) 5M (2%) 0M (0%)
09:54:39 [0.204s][info][gc,heap ] GC(0) Y: Allocated: - 8M (3%) 8M (3%) 16M (6%)
09:54:39 [0.204s][info][gc,heap ] GC(0) Y: Reclaimed: - - 0M (0%) 4M (2%)
09:54:39 [0.204s][info][gc,heap ] GC(0) Y: Promoted: - - 0M (0%) 0M (0%)
09:54:39 [0.204s][info][gc,heap ] GC(0) Y: Compacted: - - - 1M (1%)
09:54:39 [0.204s][info][gc,phases ] GC(0) Y: Young Generation 26M(10%)->38M(15%) 0.012s
09:54:39 [0.204s][info][gc,phases ] GC(0) O: Old Generation
09:54:39 [0.205s][info][gc,phases ] GC(0) O: Concurrent Mark 0.451ms
09:54:39 [0.205s][info][gc,phases ] GC(0) O: Pause Mark End 0.018ms
09:54:39 [0.205s][info][gc,phases ] GC(0) O: Concurrent Mark Free 0.001ms
09:54:39 [0.206s][info][gc,phases ] GC(0) O: Concurrent Process Non-Strong 0.991ms
09:54:39 [0.206s][info][gc,phases ] GC(0) O: Concurrent Reset Relocation Set 0.001ms
09:54:39 [0.206s][info][gc,phases ] GC(0) O: Concurrent Select Relocation Set 0.058ms
09:54:39 [0.206s][info][gc,task ] GC(0) O: Using 1 Workers for Old Generation
09:54:39 [0.206s][info][gc,task ] GC(0) O: Using 1 Workers for Old Generation
09:54:39 [0.207s][info][gc,phases ] GC(0) O: Concurrent Remap Roots 0.390ms
09:54:39 [0.207s][info][gc,phases ] GC(0) O: Pause Relocate Start 0.057ms
09:54:39 [0.207s][info][gc,phases ] GC(0) O: Concurrent Relocate 0.098ms
09:54:39 [0.207s][info][gc,alloc ] GC(0) O: Mark Start Mark End Relocate Start Relocate End
09:54:39 [0.207s][info][gc,alloc ] GC(0) O: Allocation Stalls: 0 0 0 0
09:54:39 [0.207s][info][gc,load ] GC(0) O: Load: 0.00 (0%) / 0.00 (0%) / 0.00 (0%)
09:54:39 [0.207s][info][gc,mmu ] GC(0) O: MMU: 2ms/96.3%, 5ms/98.5%, 10ms/98.8%, 20ms/99.2%, 50ms/99.7%, 100ms/99.8%
09:54:39 [0.207s][info][gc,marking ] GC(0) O: Mark: 1 stripe(s), 1 proactive flush(es), 1 terminate flush(es), 0 completion(s), 0 continuation(s)
09:54:39 [0.207s][info][gc,nmethod ] GC(0) O: NMethods: 223 registered, 16 unregistered
09:54:39 [0.207s][info][gc,metaspace] GC(0) O: Metaspace: 0M used, 0M committed, 1088M reserved
09:54:39 [0.207s][info][gc,ref ] GC(0) O: Encountered Discovered Enqueued
09:54:39 [0.207s][info][gc,ref ] GC(0) O: Soft References: 33 0 0
09:54:39 [0.207s][info][gc,ref ] GC(0) O: Weak References: 76 0 0
09:54:39 [0.207s][info][gc,ref ] GC(0) O: Final References: 0 0 0
09:54:39 [0.207s][info][gc,ref ] GC(0) O: Phantom References: 9 0 0
09:54:39 [0.207s][info][gc,heap ] GC(0) O: Min Capacity: 8M(3%)
09:54:39 [0.207s][info][gc,heap ] GC(0) O: Max Capacity: 256M(100%)
09:54:39 [0.207s][info][gc,heap ] GC(0) O: Soft Max Capacity: 256M(100%)
09:54:39 [0.207s][info][gc,heap ] GC(0) O: Heap Statistics:
09:54:39 [0.207s][info][gc,heap ] GC(0) O: Mark Start Mark End Relocate Start Relocate End High Low
09:54:39 [0.207s][info][gc,heap ] GC(0) O: Capacity: 128M (50%) 128M (50%) 128M (50%) 128M (50%) 128M (50%) 128M (50%)
09:54:39 [0.207s][info][gc,heap ] GC(0) O: Free: 230M (90%) 218M (85%) 214M (84%) 214M (84%) 230M (90%) 214M (84%)
09:54:39 [0.207s][info][gc,heap ] GC(0) O: Used: 26M (10%) 38M (15%) 42M (16%) 42M (16%) 42M (16%) 26M (10%)
09:54:39 [0.207s][info][gc,heap ] GC(0) O: Old Generation Statistics:
09:54:39 [0.207s][info][gc,heap ] GC(0) O: Mark Start Mark End Relocate Start Relocate End
09:54:39 [0.207s][info][gc,heap ] GC(0) O: Used: 0M (0%) 0M (0%) 0M (0%) 0M (0%)
09:54:39 [0.207s][info][gc,heap ] GC(0) O: Live: - 0M (0%) 0M (0%) 0M (0%)
09:54:39 [0.207s][info][gc,heap ] GC(0) O: Garbage: - 0M (0%) 0M (0%) 0M (0%)
09:54:39 [0.207s][info][gc,heap ] GC(0) O: Allocated: - 0M (0%) 0M (0%) 0M (0%)
09:54:39 [0.207s][info][gc,heap ] GC(0) O: Reclaimed: - - 0M (0%) 0M (0%)
09:54:39 [0.207s][info][gc,heap ] GC(0) O: Compacted: - - - 0M (0%)
09:54:39 [0.207s][info][gc,phases ] GC(0) O: Old Generation 38M(15%)->42M(16%) 0.002s
09:54:39 [0.207s][info][gc ] GC(0) Major Collection (Warmup) 26M(10%)->42M(16%) 0.015s
09:54:39 [0.216s][info][gc ] GC(1) Major Collection (Warmup)
09:54:39 [0.216s][info][gc,task ] GC(1) Using 1 Workers for Young Generation
09:54:39 [0.216s][info][gc,task ] GC(1) Using 1 Workers for Old Generation
09:54:39 [0.216s][info][gc,phases ] GC(1) Y: Young Generation
09:54:39 [0.216s][info][gc,phases ] GC(1) Y: Pause Mark Start (Major) 0.022ms
09:54:39 [0.226s][info][gc,phases ] GC(1) Y: Concurrent Mark 9.030ms
09:54:39 [0.226s][info][gc,phases ] GC(1) Y: Pause Mark End 0.018ms
09:54:39 [0.226s][info][gc,phases ] GC(1) Y: Concurrent Mark Free 0.002ms
09:54:39 [0.226s][info][gc,phases ] GC(1) Y: Concurrent Reset Relocation Set 0.001ms
09:54:39 [0.226s][info][gc,reloc ] GC(1) Y: Using tenuring threshold: 1 (Computed)
09:54:39 [0.229s][info][gc,phases ] GC(1) Y: Concurrent Select Relocation Set 3.321ms
09:54:39 [0.229s][info][gc,phases ] GC(1) Y: Pause Relocate Start 0.016ms
09:54:39 [0.235s][info][gc,phases ] GC(1) Y: Concurrent Relocate 5.993ms
09:54:39 [0.235s][info][gc,alloc ] GC(1) Y: Mark Start Mark End Relocate Start Relocate End
09:54:39 [0.235s][info][gc,alloc ] GC(1) Y: Allocation Stalls: 0 0 0 0
09:54:39 [0.235s][info][gc,load ] GC(1) Y: Load: 0.00 (0%) / 0.00 (0%) / 0.00 (0%)
09:54:39 [0.235s][info][gc,mmu ] GC(1) Y: MMU: 2ms/96.3%, 5ms/98.5%, 10ms/98.8%, 20ms/99.2%, 50ms/99.6%, 100ms/99.8%
09:54:39 [0.235s][info][gc,marking ] GC(1) Y: Mark: 1 stripe(s), 2 proactive flush(es), 1 terminate flush(es), 0 completion(s), 0 continuation(s)
09:54:39 [0.235s][info][gc,nmethod ] GC(1) Y: NMethods: 223 registered, 16 unregistered
09:54:39 [0.235s][info][gc,metaspace] GC(1) Y: Metaspace: 0M used, 0M committed, 1088M reserved
09:54:39 [0.235s][info][gc,reloc ] GC(1) Y: Candidates Selected In-Place Size Empty Relocated
09:54:39 [0.235s][info][gc,reloc ] GC(1) Y: Small Pages: 24 2 2 48M 0M 1M
09:54:39 [0.235s][info][gc,reloc ] GC(1) Y: Medium Pages: 0 0 0 0M 0M 0M
09:54:39 [0.235s][info][gc,reloc ] GC(1) Y: Large Pages: 0 0 0 0M 0M 0M
09:54:39 [0.235s][info][gc,reloc ] GC(1) Y: Forwarding Usage: 0M
09:54:39 [0.235s][info][gc,reloc ] GC(1) Y: Age Table:
09:54:39 [0.235s][info][gc,reloc ] GC(1) Y: Live Garbage Small Medium Large
09:54:39 [0.235s][info][gc,reloc ] GC(1) Y: Eden 21M (9%) 2M (1%) 12 / 1 0 / 0 0 / 0
09:54:39 [0.235s][info][gc,reloc ] GC(1) Y: Survivor 1 20M (8%) 3M (1%) 12 / 1 0 / 0 0 / 0
09:54:39 [0.235s][info][gc,heap ] GC(1) Y: Min Capacity: 8M(3%)
09:54:39 [0.235s][info][gc,heap ] GC(1) Y: Max Capacity: 256M(100%)
09:54:39 [0.235s][info][gc,heap ] GC(1) Y: Soft Max Capacity: 256M(100%)
09:54:39 [0.235s][info][gc,heap ] GC(1) Y: Heap Statistics:
09:54:39 [0.235s][info][gc,heap ] GC(1) Y: Mark Start Mark End Relocate Start Relocate End High Low
09:54:39 [0.235s][info][gc,heap ] GC(1) Y: Capacity: 128M (50%) 128M (50%) 128M (50%) 128M (50%) 128M (50%) 128M (50%)
09:54:39 [0.235s][info][gc,heap ] GC(1) Y: Free: 204M (80%) 194M (76%) 190M (74%) 184M (72%) 204M (80%) 184M (72%)
09:54:39 [0.235s][info][gc,heap ] GC(1) Y: Used: 52M (20%) 62M (24%) 66M (26%) 72M (28%) 72M (28%) 52M (20%)
09:54:39 [0.236s][info][gc,heap ] GC(1) Y: Young Generation Statistics:
09:54:39 [0.236s][info][gc,heap ] GC(1) Y: Mark Start Mark End Relocate Start Relocate End
09:54:39 [0.236s][info][gc,heap ] GC(1) Y: Used: 52M (20%) 62M (24%) 46M (18%) 50M (20%)
09:54:39 [0.236s][info][gc,heap ] GC(1) Y: Live: - 42M (16%) 23M (9%) 21M (9%)
09:54:39 [0.236s][info][gc,heap ] GC(1) Y: Garbage: - 9M (4%) 8M (3%) 4M (2%)
09:54:39 [0.236s][info][gc,heap ] GC(1) Y: Allocated: - 10M (4%) 14M (5%) 23M (9%)
09:54:39 [0.236s][info][gc,heap ] GC(1) Y: Reclaimed: - - 0M (0%) 5M (2%)
09:54:39 [0.236s][info][gc,heap ] GC(1) Y: Promoted: - - 19M (7%) 20M (8%)
09:54:39 [0.236s][info][gc,heap ] GC(1) Y: Compacted: - - - 0M (0%)
09:54:39 [0.236s][info][gc,phases ] GC(1) Y: Young Generation 52M(20%)->72M(28%) 0.019s
09:54:39 [0.236s][info][gc,phases ] GC(1) O: Old Generation
09:54:39 [0.236s][info][gc,phases ] GC(1) O: Concurrent Mark 0.499ms
09:54:39 [0.236s][info][gc,phases ] GC(1) O: Pause Mark End 0.016ms
09:54:39 [0.236s][info][gc,phases ] GC(1) O: Concurrent Mark Free 0.001ms
09:54:39 [0.237s][info][gc,phases ] GC(1) O: Concurrent Process Non-Strong 1.146ms
09:54:39 [0.237s][info][gc,phases ] GC(1) O: Concurrent Reset Relocation Set 0.001ms
09:54:39 [0.237s][info][gc,phases ] GC(1) O: Concurrent Select Relocation Set 0.069ms
09:54:39 [0.238s][info][gc,task ] GC(1) O: Using 1 Workers for Old Generation
09:54:39 [0.239s][info][gc,task ] GC(1) O: Using 1 Workers for Old Generation
09:54:39 [0.239s][info][gc,phases ] GC(1) O: Concurrent Remap Roots 1.055ms
09:54:39 [0.239s][info][gc,phases ] GC(1) O: Pause Relocate Start 0.014ms
09:54:39 [0.239s][info][gc,phases ] GC(1) O: Concurrent Relocate 0.086ms
09:54:39 [0.239s][info][gc,alloc ] GC(1) O: Mark Start Mark End Relocate Start Relocate End
09:54:39 [0.239s][info][gc,alloc ] GC(1) O: Allocation Stalls: 0 0 0 0
09:54:39 [0.239s][info][gc,load ] GC(1) O: Load: 0.00 (0%) / 0.00 (0%) / 0.00 (0%)
09:54:39 [0.239s][info][gc,mmu ] GC(1) O: MMU: 2ms/96.3%, 5ms/98.5%, 10ms/98.8%, 20ms/99.2%, 50ms/99.5%, 100ms/99.8%
09:54:39 [0.239s][info][gc,marking ] GC(1) O: Mark: 1 stripe(s), 1 proactive flush(es), 1 terminate flush(es), 0 completion(s), 0 continuation(s)
09:54:39 [0.239s][info][gc,nmethod ] GC(1) O: NMethods: 222 registered, 17 unregistered
09:54:39 [0.239s][info][gc,metaspace] GC(1) O: Metaspace: 0M used, 0M committed, 1088M reserved
09:54:39 [0.239s][info][gc,ref ] GC(1) O: Encountered Discovered Enqueued
09:54:39 [0.239s][info][gc,ref ] GC(1) O: Soft References: 33 0 0
09:54:39 [0.239s][info][gc,ref ] GC(1) O: Weak References: 76 0 0
09:54:39 [0.239s][info][gc,ref ] GC(1) O: Final References: 0 0 0
09:54:39 [0.239s][info][gc,ref ] GC(1) O: Phantom References: 9 0 0
09:54:39 [0.239s][info][gc,heap ] GC(1) O: Min Capacity: 8M(3%)
09:54:39 [0.239s][info][gc,heap ] GC(1) O: Max Capacity: 256M(100%)
09:54:39 [0.239s][info][gc,heap ] GC(1) O: Soft Max Capacity: 256M(100%)
09:54:39 [0.239s][info][gc,heap ] GC(1) O: Heap Statistics:
09:54:39 [0.239s][info][gc,heap ] GC(1) O: Mark Start Mark End Relocate Start Relocate End High Low
09:54:39 [0.239s][info][gc,heap ] GC(1) O: Capacity: 128M (50%) 128M (50%) 128M (50%) 128M (50%) 128M (50%) 128M (50%)
09:54:39 [0.239s][info][gc,heap ] GC(1) O: Free: 204M (80%) 182M (71%) 180M (70%) 180M (70%) 204M (80%) 180M (70%)
09:54:39 [0.239s][info][gc,heap ] GC(1) O: Used: 52M (20%) 74M (29%) 76M (30%) 76M (30%) 76M (30%) 52M (20%)
09:54:39 [0.239s][info][gc,heap ] GC(1) O: Old Generation Statistics:
09:54:39 [0.239s][info][gc,heap ] GC(1) O: Mark Start Mark End Relocate Start Relocate End
09:54:39 [0.239s][info][gc,heap ] GC(1) O: Used: 0M (0%) 22M (9%) 22M (9%) 22M (9%)
09:54:39 [0.239s][info][gc,heap ] GC(1) O: Live: - 0M (0%) 0M (0%) 0M (0%)
09:54:39 [0.239s][info][gc,heap ] GC(1) O: Garbage: - 0M (0%) 0M (0%) 0M (0%)
09:54:39 [0.239s][info][gc,heap ] GC(1) O: Allocated: - 22M (9%) 22M (9%) 22M (9%)
09:54:39 [0.239s][info][gc,heap ] GC(1) O: Reclaimed: - - 0M (0%) 0M (0%)
09:54:39 [0.239s][info][gc,heap ] GC(1) O: Compacted: - - - 0M (0%)
09:54:39 [0.239s][info][gc,phases ] GC(1) O: Old Generation 72M(28%)->76M(30%) 0.003s
09:54:39 [0.239s][info][gc ] GC(1) Major Collection (Warmup) 52M(20%)->76M(30%) 0.023s
09:54:39 [0.240s][info][gc ] GC(2) Major Collection (Warmup)
09:54:39 [0.240s][info][gc,task ] GC(2) Using 1 Workers for Young Generation
09:54:39 [0.240s][info][gc,task ] GC(2) Using 1 Workers for Old Generation
09:54:39 [0.240s][info][gc,phases ] GC(2) Y: Young Generation
09:54:39 [0.240s][info][gc,phases ] GC(2) Y: Pause Mark Start (Major) 0.014ms
09:54:39 [0.246s][info][gc,phases ] GC(2) Y: Concurrent Mark 5.957ms
09:54:39 [0.246s][info][gc,phases ] GC(2) Y: Pause Mark End 0.016ms
09:54:39 [0.246s][info][gc,phases ] GC(2) Y: Concurrent Mark Free 0.001ms
09:54:39 [0.247s][info][gc,phases ] GC(2) Y: Concurrent Reset Relocation Set 0.154ms
09:54:39 [0.247s][info][gc,reloc ] GC(2) Y: Using tenuring threshold: 1 (Computed)
09:54:39 [0.248s][info][gc,phases ] GC(2) Y: Concurrent Select Relocation Set 1.782ms
09:54:39 [0.249s][info][gc,phases ] GC(2) Y: Pause Relocate Start 0.015ms
09:54:39 [0.251s][info][gc,phases ] GC(2) Y: Concurrent Relocate 2.393ms
09:54:39 [0.251s][info][gc,alloc ] GC(2) Y: Mark Start Mark End Relocate Start Relocate End
09:54:39 [0.251s][info][gc,alloc ] GC(2) Y: Allocation Stalls: 0 0 0 0
09:54:39 [0.251s][info][gc,load ] GC(2) Y: Load: 0.00 (0%) / 0.00 (0%) / 0.00 (0%)
09:54:39 [0.251s][info][gc,mmu ] GC(2) Y: MMU: 2ms/96.3%, 5ms/98.5%, 10ms/98.8%, 20ms/99.2%, 50ms/99.5%, 100ms/99.7%
09:54:39 [0.251s][info][gc,marking ] GC(2) Y: Mark: 1 stripe(s), 2 proactive flush(es), 1 terminate flush(es), 0 completion(s), 0 continuation(s)
09:54:39 [0.251s][info][gc,nmethod ] GC(2) Y: NMethods: 222 registered, 17 unregistered
09:54:39 [0.251s][info][gc,metaspace] GC(2) Y: Metaspace: 0M used, 0M committed, 1088M reserved
09:54:39 [0.251s][info][gc,reloc ] GC(2) Y: Candidates Selected In-Place Size Empty Relocated
09:54:39 [0.251s][info][gc,reloc ] GC(2) Y: Small Pages: 25 3 2 50M 0M 1M
09:54:39 [0.251s][info][gc,reloc ] GC(2) Y: Medium Pages: 0 0 0 0M 0M 0M
09:54:39 [0.251s][info][gc,reloc ] GC(2) Y: Large Pages: 0 0 0 0M 0M 0M
09:54:39 [0.251s][info][gc,reloc ] GC(2) Y: Forwarding Usage: 0M
09:54:39 [0.251s][info][gc,reloc ] GC(2) Y: Age Table:
09:54:39 [0.251s][info][gc,reloc ] GC(2) Y: Live Garbage Small Medium Large
09:54:39 [0.251s][info][gc,reloc ] GC(2) Y: Eden 20M (8%) 5M (2%) 13 / 2 0 / 0 0 / 0
09:54:39 [0.251s][info][gc,reloc ] GC(2) Y: Survivor 1 21M (8%) 2M (1%) 12 / 1 0 / 0 0 / 0
09:54:39 [0.251s][info][gc,heap ] GC(2) Y: Min Capacity: 8M(3%)
09:54:39 [0.251s][info][gc,heap ] GC(2) Y: Max Capacity: 256M(100%)
09:54:39 [0.251s][info][gc,heap ] GC(2) Y: Soft Max Capacity: 256M(100%)
09:54:39 [0.251s][info][gc,heap ] GC(2) Y: Heap Statistics:
09:54:39 [0.251s][info][gc,heap ] GC(2) Y: Mark Start Mark End Relocate Start Relocate End High Low
09:54:39 [0.251s][info][gc,heap ] GC(2) Y: Capacity: 128M (50%) 128M (50%) 128M (50%) 128M (50%) 128M (50%) 128M (50%)
09:54:39 [0.251s][info][gc,heap ] GC(2) Y: Free: 178M (70%) 172M (67%) 168M (66%) 170M (66%) 178M (70%) 168M (66%)
09:54:39 [0.251s][info][gc,heap ] GC(2) Y: Used: 78M (30%) 84M (33%) 88M (34%) 86M (34%) 88M (34%) 78M (30%)
09:54:39 [0.251s][info][gc,heap ] GC(2) Y: Young Generation Statistics:
09:54:39 [0.251s][info][gc,heap ] GC(2) Y: Mark Start Mark End Relocate Start Relocate End
09:54:39 [0.251s][info][gc,heap ] GC(2) Y: Used: 56M (22%) 62M (24%) 44M (17%) 40M (16%)
09:54:39 [0.251s][info][gc,heap ] GC(2) Y: Live: - 42M (17%) 21M (8%) 20M (8%)
09:54:39 [0.251s][info][gc,heap ] GC(2) Y: Garbage: - 13M (5%) 12M (5%) 6M (2%)
09:54:39 [0.251s][info][gc,heap ] GC(2) Y: Allocated: - 6M (2%) 10M (4%) 12M (5%)
09:54:39 [0.251s][info][gc,heap ] GC(2) Y: Reclaimed: - - 0M (0%) 7M (3%)
09:54:39 [0.251s][info][gc,heap ] GC(2) Y: Promoted: - - 21M (8%) 21M (8%)
09:54:39 [0.251s][info][gc,heap ] GC(2) Y: Compacted: - - - 1M (0%)
09:54:39 [0.251s][info][gc,phases ] GC(2) Y: Young Generation 78M(30%)->86M(34%) 0.011s
09:54:39 [0.251s][info][gc,phases ] GC(2) O: Old Generation
09:54:39 [0.257s][info][gc,phases ] GC(2) O: Concurrent Mark 5.251ms
09:54:39 [0.257s][info][gc,phases ] GC(2) O: Pause Mark End 0.020ms
09:54:39 [0.257s][info][gc,phases ] GC(2) O: Concurrent Mark Free 0.003ms
09:54:39 [0.258s][info][gc,phases ] GC(2) O: Concurrent Process Non-Strong 0.817ms
09:54:39 [0.258s][info][gc,phases ] GC(2) O: Concurrent Reset Relocation Set 0.001ms
09:54:39 [0.258s][info][gc,phases ] GC(2) O: Concurrent Select Relocation Set 0.048ms
09:54:39 [0.258s][info][gc,task ] GC(2) O: Using 1 Workers for Old Generation
09:54:39 [0.258s][info][gc,task ] GC(2) O: Using 1 Workers for Old Generation
09:54:39 [0.258s][info][gc,phases ] GC(2) O: Concurrent Remap Roots 0.520ms
09:54:39 [0.258s][info][gc,phases ] GC(2) O: Pause Relocate Start 0.014ms
09:54:39 [0.258s][info][gc,phases ] GC(2) O: Concurrent Relocate 0.108ms
09:54:39 [0.259s][info][gc,alloc ] GC(2) O: Mark Start Mark End Relocate Start Relocate End
09:54:39 [0.259s][info][gc,alloc ] GC(2) O: Allocation Stalls: 0 0 0 0
09:54:39 [0.259s][info][gc,load ] GC(2) O: Load: 0.00 (0%) / 0.00 (0%) / 0.00 (0%)
09:54:39 [0.259s][info][gc,mmu ] GC(2) O: MMU: 2ms/96.3%, 5ms/98.5%, 10ms/98.8%, 20ms/99.2%, 50ms/99.5%, 100ms/99.7%
09:54:39 [0.259s][info][gc,marking ] GC(2) O: Mark: 1 stripe(s), 2 proactive flush(es), 1 terminate flush(es), 0 completion(s), 0 continuation(s)
09:54:39 [0.259s][info][gc,nmethod ] GC(2) O: NMethods: 222 registered, 17 unregistered
09:54:39 [0.259s][info][gc,metaspace] GC(2) O: Metaspace: 0M used, 0M committed, 1088M reserved
09:54:39 [0.259s][info][gc,ref ] GC(2) O: Encountered Discovered Enqueued
09:54:39 [0.259s][info][gc,ref ] GC(2) O: Soft References: 33 0 0
09:54:39 [0.259s][info][gc,ref ] GC(2) O: Weak References: 76 30 1
09:54:39 [0.259s][info][gc,ref ] GC(2) O: Final References: 0 0 0
09:54:39 [0.259s][info][gc,ref ] GC(2) O: Phantom References: 9 7 0
09:54:39 [0.259s][info][gc,reloc ] GC(2) O: Candidates Selected In-Place Size Empty Relocated
09:54:39 [0.259s][info][gc,reloc ] GC(2) O: Small Pages: 11 0 0 22M 0M 0M
09:54:39 [0.259s][info][gc,reloc ] GC(2) O: Medium Pages: 0 0 0 0M 0M 0M
09:54:39 [0.259s][info][gc,reloc ] GC(2) O: Large Pages: 0 0 0 0M 0M 0M
09:54:39 [0.259s][info][gc,reloc ] GC(2) O: Forwarding Usage: 0M
09:54:39 [0.259s][info][gc,heap ] GC(2) O: Min Capacity: 8M(3%)
09:54:39 [0.259s][info][gc,heap ] GC(2) O: Max Capacity: 256M(100%)
09:54:39 [0.259s][info][gc,heap ] GC(2) O: Soft Max Capacity: 256M(100%)
09:54:39 [0.259s][info][gc,heap ] GC(2) O: Heap Statistics:
09:54:39 [0.259s][info][gc,heap ] GC(2) O: Mark Start Mark End Relocate Start Relocate End High Low
09:54:39 [0.259s][info][gc,heap ] GC(2) O: Capacity: 128M (50%) 128M (50%) 128M (50%) 128M (50%) 128M (50%) 128M (50%)
09:54:39 [0.259s][info][gc,heap ] GC(2) O: Free: 178M (70%) 162M (63%) 160M (62%) 160M (62%) 178M (70%) 160M (62%)
09:54:39 [0.259s][info][gc,heap ] GC(2) O: Used: 78M (30%) 94M (37%) 96M (38%) 96M (38%) 96M (38%) 78M (30%)
09:54:39 [0.259s][info][gc,heap ] GC(2) O: Old Generation Statistics:
09:54:39 [0.259s][info][gc,heap ] GC(2) O: Mark Start Mark End Relocate Start Relocate End
09:54:39 [0.259s][info][gc,heap ] GC(2) O: Used: 22M (9%) 46M (18%) 46M (18%) 46M (18%)
09:54:39 [0.259s][info][gc,heap ] GC(2) O: Live: - 20M (8%) 20M (8%) 20M (8%)
09:54:39 [0.259s][info][gc,heap ] GC(2) O: Garbage: - 1M (1%) 1M (1%) 1M (1%)
09:54:39 [0.259s][info][gc,heap ] GC(2) O: Allocated: - 24M (9%) 24M (9%) 24M (9%)
09:54:39 [0.259s][info][gc,heap ] GC(2) O: Reclaimed: - - 0M (0%) 0M (0%)
09:54:39 [0.259s][info][gc,heap ] GC(2) O: Compacted: - - - 0M (0%)
09:54:39 [0.259s][info][gc,phases ] GC(2) O: Old Generation 86M(34%)->96M(38%) 0.007s
09:54:39 [0.259s][info][gc ] GC(2) Major Collection (Warmup) 78M(30%)->96M(38%) 0.019s
09:54:39 Fragmenting
09:54:39 Reclaiming
09:54:39 [0.281s][info][gc ] GC(3) Major Collection (System.gc())
09:54:39 [0.281s][info][gc,task ] GC(3) Using 1 Workers for Young Generation
09:54:39 [0.281s][info][gc,task ] GC(3) Using 1 Workers for Old Generation
09:54:39 [0.281s][info][gc,phases ] GC(3) Y: Young Generation (Promote All)
09:54:39 [0.281s][info][gc,phases ] GC(3) Y: Pause Mark Start 0.017ms
09:54:39 [0.285s][info][gc,phases ] GC(3) Y: Concurrent Mark 4.027ms
09:54:39 [0.285s][info][gc,phases ] GC(3) Y: Pause Mark End 0.017ms
09:54:39 [0.285s][info][gc,phases ] GC(3) Y: Concurrent Mark Free 0.003ms
09:54:39 [0.285s][info][gc,phases ] GC(3) Y: Concurrent Reset Relocation Set 0.109ms
09:54:39 [0.285s][info][gc,reloc ] GC(3) Y: Using tenuring threshold: 0 (Promote All)
09:54:39 [0.288s][info][gc,phases ] GC(3) Y: Concurrent Select Relocation Set 2.476ms
09:54:39 [0.288s][info][gc,phases ] GC(3) Y: Pause Relocate Start 0.015ms
09:54:39 [0.297s][info][gc,phases ] GC(3) Y: Concurrent Relocate 9.236ms
09:54:39 [0.297s][info][gc,alloc ] GC(3) Y: Mark Start Mark End Relocate Start Relocate End
09:54:39 [0.297s][info][gc,alloc ] GC(3) Y: Allocation Stalls: 0 0 0 0
09:54:39 [0.297s][info][gc,load ] GC(3) Y: Load: 0.00 (0%) / 0.00 (0%) / 0.00 (0%)
09:54:39 [0.297s][info][gc,mmu ] GC(3) Y: MMU: 2ms/96.3%, 5ms/98.5%, 10ms/98.8%, 20ms/99.2%, 50ms/99.5%, 100ms/99.6%
09:54:39 [0.297s][info][gc,marking ] GC(3) Y: Mark: 1 stripe(s), 1 proactive flush(es), 1 terminate flush(es), 0 completion(s), 0 continuation(s)
09:54:39 [0.297s][info][gc,nmethod ] GC(3) Y: NMethods: 230 registered, 17 unregistered
09:54:39 [0.297s][info][gc,metaspace] GC(3) Y: Metaspace: 0M used, 0M committed, 1088M reserved
09:54:39 [0.297s][info][gc,reloc ] GC(3) Y: Candidates Selected In-Place Size Empty Relocated
09:54:39 [0.297s][info][gc,reloc ] GC(3) Y: Small Pages: 31 13 14 62M 0M 12M
09:54:39 [0.297s][info][gc,reloc ] GC(3) Y: Medium Pages: 0 0 0 0M 0M 0M
09:54:39 [0.297s][info][gc,reloc ] GC(3) Y: Large Pages: 0 0 0 0M 0M 0M
09:54:39 [0.297s][info][gc,reloc ] GC(3) Y: Forwarding Usage: 0M
09:54:39 [0.297s][info][gc,reloc ] GC(3) Y: Age Table:
09:54:39 [0.297s][info][gc,reloc ] GC(3) Y: Live Garbage Small Medium Large
09:54:39 [0.297s][info][gc,reloc ] GC(3) Y: Eden 19M (8%) 20M (8%) 20 / 9 0 / 0 0 / 0
09:54:39 [0.297s][info][gc,reloc ] GC(3) Y: Survivor 1 10M (4%) 11M (5%) 11 / 4 0 / 0 0 / 0
09:54:39 [0.297s][info][gc,heap ] GC(3) Y: Min Capacity: 8M(3%)
09:54:39 [0.297s][info][gc,heap ] GC(3) Y: Max Capacity: 256M(100%)
09:54:39 [0.297s][info][gc,heap ] GC(3) Y: Soft Max Capacity: 256M(100%)
09:54:39 [0.297s][info][gc,heap ] GC(3) Y: Heap Statistics:
09:54:39 [0.297s][info][gc,heap ] GC(3) Y: Mark Start Mark End Relocate Start Relocate End High Low
09:54:39 [0.297s][info][gc,heap ] GC(3) Y: Capacity: 128M (50%) 128M (50%) 128M (50%) 128M (50%) 128M (50%) 128M (50%)
09:54:39 [0.297s][info][gc,heap ] GC(3) Y: Free: 140M (55%) 140M (55%) 140M (55%) 170M (66%) 170M (66%) 140M (55%)
09:54:39 [0.297s][info][gc,heap ] GC(3) Y: Used: 116M (45%) 116M (45%) 116M (45%) 86M (34%) 116M (45%) 86M (34%)
09:54:39 [0.297s][info][gc,heap ] GC(3) Y: Young Generation Statistics:
09:54:39 [0.297s][info][gc,heap ] GC(3) Y: Mark Start Mark End Relocate Start Relocate End
09:54:39 [0.297s][info][gc,heap ] GC(3) Y: Used: 70M (27%) 70M (27%) 66M (26%) 8M (3%)
09:54:39 [0.297s][info][gc,heap ] GC(3) Y: Live: - 29M (12%) 27M (11%) 0M (0%)
09:54:39 [0.297s][info][gc,heap ] GC(3) Y: Garbage: - 40M (16%) 38M (15%) 8M (3%)
09:54:39 [0.297s][info][gc,heap ] GC(3) Y: Allocated: - 0M (0%) 0M (0%) 0M (0%)
09:54:39 [0.297s][info][gc,heap ] GC(3) Y: Reclaimed: - - 1M (1%) 32M (13%)
09:54:39 [0.297s][info][gc,heap ] GC(3) Y: Promoted: - - 2M (1%) 29M (12%)
09:54:39 [0.297s][info][gc,heap ] GC(3) Y: Compacted: - - - 0M (0%)
09:54:39 [0.297s][info][gc,phases ] GC(3) Y: Young Generation (Promote All) 116M(45%)->86M(34%) 0.016s
09:54:39 [0.297s][info][gc,phases ] GC(3) Y: Young Generation (Collect Roots)
09:54:39 [0.298s][info][gc,phases ] GC(3) Y: Pause Mark Start (Major) 0.024ms
09:54:39 [0.299s][info][gc,phases ] GC(3) Y: Concurrent Mark 0.997ms
09:54:39 [0.299s][info][gc,phases ] GC(3) Y: Pause Mark End 0.018ms
09:54:39 [0.299s][info][gc,phases ] GC(3) Y: Concurrent Mark Free 0.001ms
09:54:39 [0.299s][info][gc,phases ] GC(3) Y: Concurrent Reset Relocation Set 0.165ms
09:54:39 [0.299s][info][gc,reloc ] GC(3) Y: Using tenuring threshold: 0 (Computed)
09:54:39 [0.299s][info][gc,phases ] GC(3) Y: Concurrent Select Relocation Set 0.198ms
09:54:39 [0.299s][info][gc,phases ] GC(3) Y: Pause Relocate Start 0.014ms
09:54:39 [0.299s][info][gc,phases ] GC(3) Y: Concurrent Relocate 0.145ms
09:54:39 [0.300s][info][gc,alloc ] GC(3) Y: Mark Start Mark End Relocate Start Relocate End
09:54:39 [0.300s][info][gc,alloc ] GC(3) Y: Allocation Stalls: 0 0 0 0
09:54:39 [0.300s][info][gc,load ] GC(3) Y: Load: 0.00 (0%) / 0.00 (0%) / 0.00 (0%)
09:54:39 [0.300s][info][gc,mmu ] GC(3) Y: MMU: 2ms/96.3%, 5ms/98.5%, 10ms/98.8%, 20ms/99.2%, 50ms/99.5%, 100ms/99.6%
09:54:39 [0.300s][info][gc,marking ] GC(3) Y: Mark: 1 stripe(s), 1 proactive flush(es), 1 terminate flush(es), 0 completion(s), 0 continuation(s)
09:54:39 [0.300s][info][gc,nmethod ] GC(3) Y: NMethods: 230 registered, 17 unregistered
09:54:39 [0.300s][info][gc,metaspace] GC(3) Y: Metaspace: 0M used, 0M committed, 1088M reserved
09:54:39 [0.300s][info][gc,heap ] GC(3) Y: Min Capacity: 8M(3%)
09:54:39 [0.300s][info][gc,heap ] GC(3) Y: Max Capacity: 256M(100%)
09:54:39 [0.300s][info][gc,heap ] GC(3) Y: Soft Max Capacity: 256M(100%)
09:54:39 [0.300s][info][gc,heap ] GC(3) Y: Heap Statistics:
09:54:39 [0.300s][info][gc,heap ] GC(3) Y: Mark Start Mark End Relocate Start Relocate End High Low
09:54:39 [0.300s][info][gc,heap ] GC(3) Y: Capacity: 128M (50%) 128M (50%) 128M (50%) 128M (50%) 128M (50%) 128M (50%)
09:54:39 [0.300s][info][gc,heap ] GC(3) Y: Free: 170M (66%) 170M (66%) 170M (66%) 170M (66%) 170M (66%) 170M (66%)
09:54:39 [0.300s][info][gc,heap ] GC(3) Y: Used: 86M (34%) 86M (34%) 86M (34%) 86M (34%) 86M (34%) 86M (34%)
09:54:39 [0.300s][info][gc,heap ] GC(3) Y: Young Generation Statistics:
09:54:39 [0.300s][info][gc,heap ] GC(3) Y: Mark Start Mark End Relocate Start Relocate End
09:54:39 [0.300s][info][gc,heap ] GC(3) Y: Used: 8M (3%) 8M (3%) 8M (3%) 8M (3%)
09:54:39 [0.300s][info][gc,heap ] GC(3) Y: Live: - 0M (0%) 0M (0%) 0M (0%)
09:54:39 [0.300s][info][gc,heap ] GC(3) Y: Garbage: - 8M (3%) 8M (3%) 8M (3%)
09:54:39 [0.300s][info][gc,heap ] GC(3) Y: Allocated: - 0M (0%) 0M (0%) 0M (0%)
09:54:39 [0.300s][info][gc,heap ] GC(3) Y: Reclaimed: - - 0M (0%) 0M (0%)
09:54:39 [0.300s][info][gc,heap ] GC(3) Y: Promoted: - - 0M (0%) 0M (0%)
09:54:39 [0.300s][info][gc,heap ] GC(3) Y: Compacted: - - - 0M (0%)
09:54:39 [0.300s][info][gc,phases ] GC(3) Y: Young Generation (Collect Roots) 86M(34%)->86M(34%) 0.002s
09:54:39 [0.300s][info][gc,phases ] GC(3) O: Old Generation
09:54:39 [0.308s][info][gc,phases ] GC(3) O: Concurrent Mark 7.791ms
09:54:39 [0.308s][info][gc,phases ] GC(3) O: Pause Mark End 0.034ms
09:54:39 [0.308s][info][gc,phases ] GC(3) O: Concurrent Mark Free 0.003ms
09:54:39 [0.309s][info][gc,phases ] GC(3) O: Concurrent Process Non-Strong 0.822ms
09:54:39 [0.309s][info][gc,phases ] GC(3) O: Concurrent Reset Relocation Set 0.001ms
09:54:39 [0.309s][info][gc,phases ] GC(3) O: Concurrent Select Relocation Set 0.257ms
09:54:39 [0.309s][info][gc,task ] GC(3) O: Using 1 Workers for Old Generation
09:54:39 [0.309s][info][gc,task ] GC(3) O: Using 1 Workers for Old Generation
09:54:39 [0.309s][info][gc,phases ] GC(3) O: Concurrent Remap Roots 0.483ms
09:54:39 [0.309s][info][gc,phases ] GC(3) O: Pause Relocate Start 0.017ms
09:54:39 [0.317s][info][gc,phases ] GC(3) O: Concurrent Relocate 7.924ms
09:54:39 [0.318s][info][gc,alloc ] GC(3) O: Mark Start Mark End Relocate Start Relocate End
09:54:39 [0.318s][info][gc,alloc ] GC(3) O: Allocation Stalls: 0 0 0 0
09:54:39 [0.318s][info][gc,load ] GC(3) O: Load: 0.00 (0%) / 0.00 (0%) / 0.00 (0%)
09:54:39 [0.318s][info][gc,mmu ] GC(3) O: MMU: 2ms/96.3%, 5ms/98.5%, 10ms/98.8%, 20ms/99.2%, 50ms/99.5%, 100ms/99.6%
09:54:39 [0.318s][info][gc,marking ] GC(3) O: Mark: 1 stripe(s), 1 proactive flush(es), 1 terminate flush(es), 0 completion(s), 0 continuation(s)
09:54:39 [0.318s][info][gc,nmethod ] GC(3) O: NMethods: 227 registered, 20 unregistered
09:54:39 [0.318s][info][gc,metaspace] GC(3) O: Metaspace: 0M used, 0M committed, 1088M reserved
09:54:39 [0.318s][info][gc,ref ] GC(3) O: Encountered Discovered Enqueued
09:54:39 [0.318s][info][gc,ref ] GC(3) O: Soft References: 33 0 0
09:54:39 [0.318s][info][gc,ref ] GC(3) O: Weak References: 75 29 0
09:54:39 [0.318s][info][gc,ref ] GC(3) O: Final References: 0 0 0
09:54:39 [0.318s][info][gc,ref ] GC(3) O: Phantom References: 9 7 0
09:54:39 [0.318s][info][gc,reloc ] GC(3) O: Candidates Selected In-Place Size Empty Relocated
09:54:39 [0.318s][info][gc,reloc ] GC(3) O: Small Pages: 39 11 12 78M 0M 10M
09:54:39 [0.318s][info][gc,reloc ] GC(3) O: Medium Pages: 0 0 0 0M 0M 0M
09:54:39 [0.318s][info][gc,reloc ] GC(3) O: Large Pages: 0 0 0 0M 0M 0M
09:54:39 [0.318s][info][gc,reloc ] GC(3) O: Forwarding Usage: 0M
09:54:39 [0.318s][info][gc,heap ] GC(3) O: Min Capacity: 8M(3%)
09:54:39 [0.318s][info][gc,heap ] GC(3) O: Max Capacity: 256M(100%)
09:54:39 [0.318s][info][gc,heap ] GC(3) O: Soft Max Capacity: 256M(100%)
09:54:39 [0.318s][info][gc,heap ] GC(3) O: Heap Statistics:
09:54:39 [0.318s][info][gc,heap ] GC(3) O: Mark Start Mark End Relocate Start Relocate End High Low
09:54:39 [0.318s][info][gc,heap ] GC(3) O: Capacity: 128M (50%) 128M (50%) 128M (50%) 128M (50%) 128M (50%) 128M (50%)
09:54:39 [0.318s][info][gc,heap ] GC(3) O: Free: 170M (66%) 170M (66%) 170M (66%) 194M (76%) 194M (76%) 170M (66%)
09:54:39 [0.318s][info][gc,heap ] GC(3) O: Used: 86M (34%) 86M (34%) 86M (34%) 62M (24%) 86M (34%) 62M (24%)
09:54:39 [0.318s][info][gc,heap ] GC(3) O: Old Generation Statistics:
09:54:39 [0.318s][info][gc,heap ] GC(3) O: Mark Start Mark End Relocate Start Relocate End
09:54:39 [0.318s][info][gc,heap ] GC(3) O: Used: 78M (30%) 78M (30%) 78M (30%) 54M (21%)
09:54:39 [0.318s][info][gc,heap ] GC(3) O: Live: - 51M (20%) 51M (20%) 51M (20%)
09:54:39 [0.318s][info][gc,heap ] GC(3) O: Garbage: - 26M (10%) 26M (10%) 0M (0%)
09:54:39 [0.318s][info][gc,heap ] GC(3) O: Allocated: - 0M (0%) 0M (0%) 1M (1%)
09:54:39 [0.318s][info][gc,heap ] GC(3) O: Reclaimed: - - 0M (0%) 25M (10%)
09:54:39 [0.318s][info][gc,heap ] GC(3) O: Compacted: - - - 22M (9%)
09:54:39 [0.318s][info][gc,phases ] GC(3) O: Old Generation 86M(34%)->62M(24%) 0.018s
09:54:39 [0.318s][info][gc ] GC(3) Major Collection (System.gc()) 116M(45%)->62M(24%) 0.037s
09:54:39 Allocating
09:54:39 [0.318s][info][gc ] Out Of Memory (MainThread)
09:54:39 [0.336s][info][gc,exit ] Stopping ZGC
09:54:39 [0.336s][info][gc,exit ] Heap
09:54:39 [0.336s][info][gc,exit ] ZHeap used 70M, capacity 128M, max capacity 256M
09:54:39 [0.336s][info][gc,exit ] Cache 58M (17)
09:54:39 [0.336s][info][gc,exit ] size classes 2M (14), 4M (1), 8M (1), 16M (1)
09:54:39 [0.336s][info][gc,exit ] Metaspace used 612K, committed 768K, reserved 1114112K
09:54:39 [0.336s][info][gc,exit ] class space used 38K, committed 128K, reserved 1048576K
09:54:39 STDERR:
09:54:39 java.lang.OutOfMemoryError: Java heap space
09:54:39 at gc.z.TestRelocateInPlace.allocate(TestRelocateInPlace.java:45)
09:54:39 at gc.z.TestRelocateInPlace.test(TestRelocateInPlace.java:58)
09:54:39 at gc.z.TestRelocateInPlace.main(TestRelocateInPlace.java:71)
09:54:39 at java.base/java.lang.invoke.LambdaForm$DMH/0x000000001d041000.invokeStatic(LambdaForm$DMH)
09:54:39 at java.base/java.lang.invoke.LambdaForm$MH/0x000000001d042400.invoke(LambdaForm$MH)
09:54:39 at java.base/java.lang.invoke.Invokers$Holder.invokeExact_MT(Invokers$Holder)
09:54:39 at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invokeImpl(DirectMethodHandleAccessor.java:155)
09:54:39 at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:104)
09:54:39 at java.base/java.lang.reflect.Method.invoke(Method.java:565)
09:54:39 at com.sun.javatest.regtest.agent.MainWrapper$MainTask.run(MainWrapper.java:138)
09:54:39 at java.base/java.lang.Thread.runWith(Thread.java:1487)
09:54:39 at java.base/java.lang.Thread.run(Thread.java:1474)
Since jdk-24 x64Windows we have been seeing sanity.openjdk GC outOfMemory failures: Ref: #6555 (comment)
Isolated one particular testcase as an example: gc/z/TestRelocateInPlace.java
https://ci.adoptium.net/job/Grinder/14486/consoleFull
The testcase fails here: https://github.com/openjdk/jdk/blob/6c48f4ed707bf0b15f9b6098de30db8aae6fa40f/test/hotspot/jtreg/gc/z/TestRelocateInPlace.java#L45
Where it is progressively allocating in 4K chunks up to a maximum of 100M, the above log shows (ZHeap used 70M, capacity 128M, max capacity 256M), which means there is enough capacity to expand, however Out Of Memory (MainThread) occurs...?
The problem does not occur using upstream openjdk jdk-25+36 rc candidate build: https://ci.adoptium.net/job/Grinder/14490/