-
Bug
-
Resolution: Fixed
-
P4
-
22
Test
java/lang/management/MemoryMXBean/CollectionUsageThreshold.java
fails with Xcomp.
Log:
stdout: [[0.005s][info][gc,init] CardTable entry size: 512
[0.005s][debug][gc,heap] Minimum heap 8388608 Initial heap 390070272 Maximum heap 805306368
[0.005s][info ][gc ] Using Serial
[0.044s][info ][gc,init] Version: 22-ea+21-1619 (fastdebug)
[0.044s][info ][gc,init] CPUs: 12 total, 12 available
[0.044s][info ][gc,init] Memory: 23726M
[0.044s][info ][gc,init] Large Page Support: Disabled
[0.044s][info ][gc,init] NUMA Support: Disabled
[0.044s][info ][gc,init] Compressed Oops: Disabled
[0.045s][info ][gc,init] Heap Min Capacity: 8M
[0.045s][info ][gc,init] Heap Initial Capacity: 372M
[0.045s][info ][gc,init] Heap Max Capacity: 768M
[0.045s][info ][gc,init] Pre-touch: Disabled
[0.055s][info ][gc,metaspace] CDS archive(s) mapped at: [0x00007fd31f000000-0x00007fd31fd39000-0x00007fd31fd39000), size 13864960, SharedBaseAddress: 0x00007fd31f000000, ArchiveRelocationMode: 1.
[0.055s][info ][gc,metaspace] Compressed class space mapped at: 0x00007fd320000000-0x00007fd360000000, reserved size: 1073741824
[0.055s][info ][gc,metaspace] Narrow klass base: 0x00007fd31f000000, Narrow klass shift: 0, Narrow klass range: 0x100000000
[13.402s][info ][gc,start ] GC(0) Pause Full (CodeCache GC Threshold)
[13.402s][debug][gc,heap ] GC(0) Heap before GC invocations=0 (full 0):
[13.402s][debug][gc,heap ] GC(0) def new generation total 114304K, used 14229K [0x00007fd360a00000, 0x00007fd368600000, 0x00007fd370a00000)
[13.402s][debug][gc,heap ] GC(0) eden space 101632K, 14% used [0x00007fd360a00000, 0x00007fd3617e5668, 0x00007fd366d40000)
[13.402s][debug][gc,heap ] GC(0) from space 12672K, 0% used [0x00007fd366d40000, 0x00007fd366d40000, 0x00007fd3679a0000)
[13.402s][debug][gc,heap ] GC(0) to space 12672K, 0% used [0x00007fd3679a0000, 0x00007fd3679a0000, 0x00007fd368600000)
[13.402s][debug][gc,heap ] GC(0) tenured generation total 253952K, used 0K [0x00007fd370a00000, 0x00007fd380200000, 0x00007fd390a00000)
[13.402s][debug][gc,heap ] GC(0) the space 253952K, 0% used [0x00007fd370a00000, 0x00007fd370a00000, 0x00007fd370a00200, 0x00007fd380200000)
[13.403s][debug][gc,heap ] GC(0) Metaspace used 2486K, committed 2624K, reserved 1114112K
[13.403s][debug][gc,heap ] GC(0) class space used 96K, committed 192K, reserved 1048576K
[13.403s][debug][gc,tlab ] GC(0) TLAB totals: thrds: 6 refills: 7 max: 2 slow allocs: 0 max 0 waste: 84.8% gc: 12350920B max: 2081392B slow: 696B max: 696B
[13.403s][info ][gc,phases,start] GC(0) Phase 1: Mark live objects
[13.411s][debug][gc,phases,start] GC(0) Reference Processing
[13.411s][debug][gc,ref ] GC(0) ReferenceProcessor::execute queues: 1, RefProcThreadModel::Single, marks_oops_alive: false
[13.411s][debug][gc,ref ] GC(0) Skipped KeepAliveFinalRefsPhase of Reference Processing: no references
[13.412s][debug][gc,ref ] GC(0) ReferenceProcessor::execute queues: 1, RefProcThreadModel::Single, marks_oops_alive: false
[13.412s][debug][gc,phases,ref ] GC(0) Reference Processing: 0.2ms
[13.412s][debug][gc,phases,ref ] GC(0) Notify Soft/WeakReferences: 0.1ms
[13.412s][debug][gc,phases,ref ] GC(0) SoftRef: 0.0ms
[13.412s][debug][gc,phases,ref ] GC(0) WeakRef: 0.0ms
[13.412s][debug][gc,phases,ref ] GC(0) FinalRef: 0.0ms
[13.412s][debug][gc,phases,ref ] GC(0) Total: 0.0ms
[13.412s][debug][gc,phases,ref ] GC(0) Notify and keep alive finalizable: 0.1ms
[13.412s][debug][gc,phases,ref ] GC(0) FinalRef: skipped
[13.412s][debug][gc,phases,ref ] GC(0) Notify PhantomReferences: 0.0ms
[13.412s][debug][gc,phases,ref ] GC(0) PhantomRef: 0.0ms
[13.412s][debug][gc,phases,ref ] GC(0) SoftReference Discovered: 0, Dropped: 0, Processed: 0
[13.412s][debug][gc,phases,ref ] GC(0) WeakReference Discovered: 64, Dropped: 2, Processed: 62
[13.412s][debug][gc,phases,ref ] GC(0) FinalReference Discovered: 0, Dropped: 0, Processed: 0
[13.412s][debug][gc,phases,ref ] GC(0) PhantomReference Discovered: 31, Dropped: 0, Processed: 31
[13.412s][debug][gc,phases ] GC(0) Reference Processing 0.376ms
[13.412s][debug][gc,phases,start] GC(0) Weak Processing
[13.412s][debug][gc,phases ] GC(0) Weak Processing 0.106ms
[13.412s][debug][gc,phases,start] GC(0) Class Unloading
[13.412s][debug][gc,phases,start] GC(0) ClassLoaderData
[13.412s][debug][gc,phases ] GC(0) ClassLoaderData 0.008ms
[13.412s][debug][gc,phases,start] GC(0) Trigger cleanups
[13.412s][debug][gc,phases ] GC(0) Trigger cleanups 0.004ms
[13.425s][debug][gc,phases ] GC(0) Class Unloading 13.159ms
[13.425s][debug][gc,phases,start] GC(0) Report Object Count
[13.425s][debug][gc,phases ] GC(0) Report Object Count 0.010ms
[13.425s][info ][gc,phases ] GC(0) Phase 1: Mark live objects 21.783ms
[13.425s][info ][gc,phases,start] GC(0) Phase 2: Compute new object addresses
[13.427s][info ][gc,phases ] GC(0) Phase 2: Compute new object addresses 2.361ms
[13.427s][info ][gc,phases,start] GC(0) Phase 3: Adjust pointers
[13.441s][info ][gc,phases ] GC(0) Phase 3: Adjust pointers 13.790ms
[13.441s][info ][gc,phases,start] GC(0) Phase 4: Move objects
[13.443s][info ][gc,phases ] GC(0) Phase 4: Move objects 2.267ms
[13.447s][debug][gc,ergo,heap ] GC(0) New generation size 126976K->127040K [eden=101696K,survivor=12672K]
[13.447s][info ][gc,heap ] GC(0) DefNew: 14229K(114304K)->0K(114368K) Eden: 14229K(101632K)->0K(101696K) From: 0K(12672K)->0K(12672K)
[13.447s][info ][gc,heap ] GC(0) Tenured: 0K(253952K)->1166K(253952K)
[13.447s][info ][gc,metaspace ] GC(0) Metaspace: 2486K(2624K)->2486K(2624K) NonClass: 2389K(2432K)->2389K(2432K) Class: 96K(192K)->96K(192K)
[13.447s][debug][gc,heap ] GC(0) Heap after GC invocations=1 (full 1):
[13.447s][debug][gc,heap ] GC(0) def new generation total 114368K, used 0K [0x00007fd360a00000, 0x00007fd368610000, 0x00007fd370a00000)
[13.447s][debug][gc,heap ] GC(0) eden space 101696K, 0% used [0x00007fd360a00000, 0x00007fd360a00000, 0x00007fd366d50000)
[13.447s][debug][gc,heap ] GC(0) from space 12672K, 0% used [0x00007fd366d50000, 0x00007fd366d50000, 0x00007fd3679b0000)
[13.447s][debug][gc,heap ] GC(0) to space 12672K, 0% used [0x00007fd3679b0000, 0x00007fd3679b0000, 0x00007fd368610000)
[13.447s][debug][gc,heap ] GC(0) tenured generation total 253952K, used 1166K [0x00007fd370a00000, 0x00007fd380200000, 0x00007fd390a00000)
[13.447s][debug][gc,heap ] GC(0) the space 253952K, 0% used [0x00007fd370a00000, 0x00007fd370b238a8, 0x00007fd370b23a00, 0x00007fd380200000)
[13.447s][debug][gc,heap ] GC(0) Metaspace used 2486K, committed 2624K, reserved 1114112K
[13.447s][debug][gc,heap ] GC(0) class space used 96K, committed 192K, reserved 1048576K
[13.447s][info ][gc ] GC(0) Pause Full (CodeCache GC Threshold) 13M->1M(359M) 44.429ms
[13.447s][info ][gc,cpu ] GC(0) User=0.04s Sys=0.00s Real=0.05s
Collection usage threshold of Tenured Gen set to 10
Calling System.gc()
[13.524s][info ][gc,start ] GC(1) Pause Full (System.gc())
[13.524s][debug][gc,heap ] GC(1) Heap before GC invocations=1 (full 1):
[13.524s][debug][gc,heap ] GC(1) def new generation total 114368K, used 4067K [0x00007fd360a00000, 0x00007fd368610000, 0x00007fd370a00000)
[13.524s][debug][gc,heap ] GC(1) eden space 101696K, 4% used [0x00007fd360a00000, 0x00007fd360df8f90, 0x00007fd366d50000)
[13.524s][debug][gc,heap ] GC(1) from space 12672K, 0% used [0x00007fd366d50000, 0x00007fd366d50000, 0x00007fd3679b0000)
[13.524s][debug][gc,heap ] GC(1) to space 12672K, 0% used [0x00007fd3679b0000, 0x00007fd3679b0000, 0x00007fd368610000)
[13.524s][debug][gc,heap ] GC(1) tenured generation total 253952K, used 1166K [0x00007fd370a00000, 0x00007fd380200000, 0x00007fd390a00000)
[13.524s][debug][gc,heap ] GC(1) the space 253952K, 0% used [0x00007fd370a00000, 0x00007fd370b238a8, 0x00007fd370b23a00, 0x00007fd380200000)
[13.524s][debug][gc,heap ] GC(1) Metaspace used 2517K, committed 2688K, reserved 1114112K
[13.524s][debug][gc,heap ] GC(1) class space used 99K, committed 192K, reserved 1048576K
[13.525s][debug][gc,tlab ] GC(1) TLAB totals: thrds: 2 refills: 2 max: 1 slow allocs: 0 max 0 waste: 99.7% gc: 4152352B max: 2079456B slow: 0B max: 0B
[13.525s][info ][gc,phases,start] GC(1) Phase 1: Mark live objects
[13.536s][debug][gc,phases,start] GC(1) Reference Processing
[13.536s][debug][gc,ref ] GC(1) ReferenceProcessor::execute queues: 1, RefProcThreadModel::Single, marks_oops_alive: false
[13.536s][debug][gc,ref ] GC(1) Skipped KeepAliveFinalRefsPhase of Reference Processing: no references
[13.536s][debug][gc,ref ] GC(1) Skipped PhantomRefsPhase of Reference Processing: no references
[13.536s][debug][gc,phases,ref ] GC(1) Reference Processing: 0.1ms
[13.536s][debug][gc,phases,ref ] GC(1) Notify Soft/WeakReferences: 0.1ms
[13.536s][debug][gc,phases,ref ] GC(1) SoftRef: 0.0ms
[13.536s][debug][gc,phases,ref ] GC(1) WeakRef: 0.0ms
[13.536s][debug][gc,phases,ref ] GC(1) FinalRef: 0.0ms
[13.536s][debug][gc,phases,ref ] GC(1) Total: 0.0ms
[13.536s][debug][gc,phases,ref ] GC(1) Notify and keep alive finalizable: 0.0ms
[13.536s][debug][gc,phases,ref ] GC(1) FinalRef: skipped
[13.536s][debug][gc,phases,ref ] GC(1) Notify PhantomReferences: 0.0ms
[13.536s][debug][gc,phases,ref ] GC(1) PhantomRef: skipped
[13.536s][debug][gc,phases,ref ] GC(1) SoftReference Discovered: 0, Dropped: 0, Processed: 0
[13.536s][debug][gc,phases,ref ] GC(1) WeakReference Discovered: 2, Dropped: 2, Processed: 0
[13.536s][debug][gc,phases,ref ] GC(1) FinalReference Discovered: 0, Dropped: 0, Processed: 0
[13.536s][debug][gc,phases,ref ] GC(1) PhantomReference Discovered: 0, Dropped: 0, Processed: 0
[13.536s][debug][gc,phases ] GC(1) Reference Processing 0.226ms
[13.536s][debug][gc,phases,start] GC(1) Weak Processing
[13.536s][debug][gc,phases ] GC(1) Weak Processing 0.102ms
[13.536s][debug][gc,phases,start] GC(1) Class Unloading
[13.536s][debug][gc,phases,start] GC(1) ClassLoaderData
[13.536s][debug][gc,phases ] GC(1) ClassLoaderData 0.010ms
[13.536s][debug][gc,phases,start] GC(1) Trigger cleanups
[13.536s][debug][gc,phases ] GC(1) Trigger cleanups 0.004ms
[13.551s][debug][gc,phases ] GC(1) Class Unloading 15.533ms
[13.551s][debug][gc,phases,start] GC(1) Report Object Count
[13.551s][debug][gc,phases ] GC(1) Report Object Count 0.005ms
[13.551s][info ][gc,phases ] GC(1) Phase 1: Mark live objects 26.903ms
[13.552s][info ][gc,phases,start] GC(1) Phase 2: Compute new object addresses
[13.552s][info ][gc,phases ] GC(1) Phase 2: Compute new object addresses 0.944ms
[13.552s][info ][gc,phases,start] GC(1) Phase 3: Adjust pointers
[13.561s][info ][gc,phases ] GC(1) Phase 3: Adjust pointers 8.199ms
[13.561s][info ][gc,phases,start] GC(1) Phase 4: Move objects
[13.561s][info ][gc,phases ] GC(1) Phase 4: Move objects 0.714ms
[13.563s][info ][gc,heap ] GC(1) DefNew: 4067K(114368K)->0K(114368K) Eden: 4067K(101696K)->0K(101696K) From: 0K(12672K)->0K(12672K)
[13.563s][info ][gc,heap ] GC(1) Tenured: 1166K(253952K)->1169K(253952K)
[13.563s][info ][gc,metaspace ] GC(1) Metaspace: 2517K(2688K)->2517K(2688K) NonClass: 2417K(2496K)->2417K(2496K) Class: 99K(192K)->99K(192K)
[13.563s][debug][gc,heap ] GC(1) Heap after GC invocations=2 (full 2):
[13.563s][debug][gc,heap ] GC(1) def new generation total 114368K, used 0K [0x00007fd360a00000, 0x00007fd368610000, 0x00007fd370a00000)
[13.563s][debug][gc,heap ] GC(1) eden space 101696K, 0% used [0x00007fd360a00000, 0x00007fd360a00000, 0x00007fd366d50000)
[13.563s][debug][gc,heap ] GC(1) from space 12672K, 0% used [0x00007fd366d50000, 0x00007fd366d50000, 0x00007fd3679b0000)
[13.563s][debug][gc,heap ] GC(1) to space 12672K, 0% used [0x00007fd3679b0000, 0x00007fd3679b0000, 0x00007fd368610000)
[13.563s][debug][gc,heap ] GC(1) tenured generation total 253952K, used 1169K [0x00007fd370a00000, 0x00007fd380200000, 0x00007fd390a00000)
[13.563s][debug][gc,heap ] GC(1) the space 253952K, 0% used [0x00007fd370a00000, 0x00007fd370b246f0, 0x00007fd370b24800, 0x00007fd380200000)
[13.563s][debug][gc,heap ] GC(1) Metaspace used 2517K, committed 2688K, reserved 1114112K
[13.563s][debug][gc,heap ] GC(1) class space used 99K, committed 192K, reserved 1048576K
[13.563s][info ][gc ] GC(1) Pause Full (System.gc()) 5M->1M(359M) 38.603ms
[13.563s][info ][gc,cpu ] GC(1) User=0.04s Sys=0.00s Real=0.04s
Notification for Tenured Gen [type = java.management.memory.collection.threshold.exceeded count = 1]
usage = init = 260046848(253952K) used = 1194152(1166K) committed = 260046848(253952K) max = 536870912(524288K)
notifying the checker thread to check result
Notification for Tenured Gen [type = java.management.memory.collection.threshold.exceeded count = 2]
usage = init = 260046848(253952K) used = 1197808(1169K) committed = 260046848(253952K) max = 536870912(524288K)
notifying the checker thread to check result
[15.728s][info ][gc,heap,exit ] Heap
[15.728s][info ][gc,heap,exit ] def new generation total 114368K, used 10848K [0x00007fd360a00000, 0x00007fd368610000, 0x00007fd370a00000)
[15.728s][info ][gc,heap,exit ] eden space 101696K, 10% used [0x00007fd360a00000, 0x00007fd361498018, 0x00007fd366d50000)
[15.728s][info ][gc,heap,exit ] from space 12672K, 0% used [0x00007fd366d50000, 0x00007fd366d50000, 0x00007fd3679b0000)
[15.728s][info ][gc,heap,exit ] to space 12672K, 0% used [0x00007fd3679b0000, 0x00007fd3679b0000, 0x00007fd368610000)
[15.728s][info ][gc,heap,exit ] tenured generation total 253952K, used 1169K [0x00007fd370a00000, 0x00007fd380200000, 0x00007fd390a00000)
[15.728s][info ][gc,heap,exit ] the space 253952K, 0% used [0x00007fd370a00000, 0x00007fd370b246f0, 0x00007fd370b24800, 0x00007fd380200000)
[15.728s][info ][gc,heap,exit ] Metaspace used 3223K, committed 3328K, reserved 1114112K
[15.728s][info ][gc,heap,exit ] class space used 159K, committed 192K, reserved 1048576K
[15.728s][debug][gc,heap,exit ] Accumulated young generation GC time 0.0000000 secs, 0 GC's, avg GC time 0.0000000
[15.728s][debug][gc,heap,exit ] Accumulated old generation GC time 0.0809754 secs, 2 GC's, avg GC time 0.0404877
[15.729s][info ][gc,verify,start] Verifying
[15.729s][debug][gc,verify ] Threads
[15.729s][debug][gc,verify ] Heap
[15.729s][debug][gc,verify ] tenured generation
[15.738s][debug][gc,verify ] def new generation
[15.742s][debug][gc,verify ] RemSet
[15.746s][debug][gc,verify ] SymbolTable
[15.747s][debug][gc,verify ] StringTable
[15.749s][debug][gc,verify ] CodeCache
[15.766s][debug][gc,verify ] SystemDictionary
[15.770s][debug][gc,verify ] ClassLoaderDataGraph
[15.770s][debug][gc,verify ] MetaspaceUtils
[15.770s][debug][gc,verify ] JNIHandles
[15.770s][debug][gc,verify ] CodeCache Oops
[15.773s][debug][gc,verify ] ResolvedMethodTable Oops
[15.773s][debug][gc,verify ] String Deduplication
[15.773s][info ][gc,verify ] Verifying 44.143ms
];
stderr: [Exception in thread "Checker thread" Exception in thread "main" java.lang.RuntimeException: CollectionUsageThresholdCount = 2 expected to be 1
at CollectionUsageThreshold$Checker.fail(CollectionUsageThreshold.java:264)
at CollectionUsageThreshold$Checker.checkResult(CollectionUsageThreshold.java:248)
at CollectionUsageThreshold$Checker.run(CollectionUsageThreshold.java:227)
java.util.concurrent.BrokenBarrierException
at java.base/java.util.concurrent.CyclicBarrier.dowait(CyclicBarrier.java:252)
at java.base/java.util.concurrent.CyclicBarrier.await(CyclicBarrier.java:364)
at CollectionUsageThreshold$TestMain.main(CollectionUsageThreshold.java:192)
]
exitValue = 1
java.lang.RuntimeException: Expected to get exit value of [0], exit value is: [1]
at jdk.test.lib.process.OutputAnalyzer.shouldHaveExitValue(OutputAnalyzer.java:490)
at RunUtil.runTest(RunUtil.java:78)
at RunUtil.runTestClearGcOpts(RunUtil.java:42)
at CollectionUsageThreshold.main(CollectionUsageThreshold.java:76)
at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103)
at java.base/java.lang.reflect.Method.invoke(Method.java:580)
at com.sun.javatest.regtest.agent.MainWrapper$MainTask.run(MainWrapper.java:138)
at java.base/java.lang.Thread.run(Thread.java:1570)
JavaTest Message: Test threw exception: java.lang.RuntimeException: Expected to get exit value of [0], exit value is: [1]
JavaTest Message: shutting down test
STATUS:Failed.`main' threw exception: java.lang.RuntimeException: Expected to get exit value of [0], exit value is: [1]
java/lang/management/MemoryMXBean/CollectionUsageThreshold.java
fails with Xcomp.
Log:
stdout: [[0.005s][info][gc,init] CardTable entry size: 512
[0.005s][debug][gc,heap] Minimum heap 8388608 Initial heap 390070272 Maximum heap 805306368
[0.005s][info ][gc ] Using Serial
[0.044s][info ][gc,init] Version: 22-ea+21-1619 (fastdebug)
[0.044s][info ][gc,init] CPUs: 12 total, 12 available
[0.044s][info ][gc,init] Memory: 23726M
[0.044s][info ][gc,init] Large Page Support: Disabled
[0.044s][info ][gc,init] NUMA Support: Disabled
[0.044s][info ][gc,init] Compressed Oops: Disabled
[0.045s][info ][gc,init] Heap Min Capacity: 8M
[0.045s][info ][gc,init] Heap Initial Capacity: 372M
[0.045s][info ][gc,init] Heap Max Capacity: 768M
[0.045s][info ][gc,init] Pre-touch: Disabled
[0.055s][info ][gc,metaspace] CDS archive(s) mapped at: [0x00007fd31f000000-0x00007fd31fd39000-0x00007fd31fd39000), size 13864960, SharedBaseAddress: 0x00007fd31f000000, ArchiveRelocationMode: 1.
[0.055s][info ][gc,metaspace] Compressed class space mapped at: 0x00007fd320000000-0x00007fd360000000, reserved size: 1073741824
[0.055s][info ][gc,metaspace] Narrow klass base: 0x00007fd31f000000, Narrow klass shift: 0, Narrow klass range: 0x100000000
[13.402s][info ][gc,start ] GC(0) Pause Full (CodeCache GC Threshold)
[13.402s][debug][gc,heap ] GC(0) Heap before GC invocations=0 (full 0):
[13.402s][debug][gc,heap ] GC(0) def new generation total 114304K, used 14229K [0x00007fd360a00000, 0x00007fd368600000, 0x00007fd370a00000)
[13.402s][debug][gc,heap ] GC(0) eden space 101632K, 14% used [0x00007fd360a00000, 0x00007fd3617e5668, 0x00007fd366d40000)
[13.402s][debug][gc,heap ] GC(0) from space 12672K, 0% used [0x00007fd366d40000, 0x00007fd366d40000, 0x00007fd3679a0000)
[13.402s][debug][gc,heap ] GC(0) to space 12672K, 0% used [0x00007fd3679a0000, 0x00007fd3679a0000, 0x00007fd368600000)
[13.402s][debug][gc,heap ] GC(0) tenured generation total 253952K, used 0K [0x00007fd370a00000, 0x00007fd380200000, 0x00007fd390a00000)
[13.402s][debug][gc,heap ] GC(0) the space 253952K, 0% used [0x00007fd370a00000, 0x00007fd370a00000, 0x00007fd370a00200, 0x00007fd380200000)
[13.403s][debug][gc,heap ] GC(0) Metaspace used 2486K, committed 2624K, reserved 1114112K
[13.403s][debug][gc,heap ] GC(0) class space used 96K, committed 192K, reserved 1048576K
[13.403s][debug][gc,tlab ] GC(0) TLAB totals: thrds: 6 refills: 7 max: 2 slow allocs: 0 max 0 waste: 84.8% gc: 12350920B max: 2081392B slow: 696B max: 696B
[13.403s][info ][gc,phases,start] GC(0) Phase 1: Mark live objects
[13.411s][debug][gc,phases,start] GC(0) Reference Processing
[13.411s][debug][gc,ref ] GC(0) ReferenceProcessor::execute queues: 1, RefProcThreadModel::Single, marks_oops_alive: false
[13.411s][debug][gc,ref ] GC(0) Skipped KeepAliveFinalRefsPhase of Reference Processing: no references
[13.412s][debug][gc,ref ] GC(0) ReferenceProcessor::execute queues: 1, RefProcThreadModel::Single, marks_oops_alive: false
[13.412s][debug][gc,phases,ref ] GC(0) Reference Processing: 0.2ms
[13.412s][debug][gc,phases,ref ] GC(0) Notify Soft/WeakReferences: 0.1ms
[13.412s][debug][gc,phases,ref ] GC(0) SoftRef: 0.0ms
[13.412s][debug][gc,phases,ref ] GC(0) WeakRef: 0.0ms
[13.412s][debug][gc,phases,ref ] GC(0) FinalRef: 0.0ms
[13.412s][debug][gc,phases,ref ] GC(0) Total: 0.0ms
[13.412s][debug][gc,phases,ref ] GC(0) Notify and keep alive finalizable: 0.1ms
[13.412s][debug][gc,phases,ref ] GC(0) FinalRef: skipped
[13.412s][debug][gc,phases,ref ] GC(0) Notify PhantomReferences: 0.0ms
[13.412s][debug][gc,phases,ref ] GC(0) PhantomRef: 0.0ms
[13.412s][debug][gc,phases,ref ] GC(0) SoftReference Discovered: 0, Dropped: 0, Processed: 0
[13.412s][debug][gc,phases,ref ] GC(0) WeakReference Discovered: 64, Dropped: 2, Processed: 62
[13.412s][debug][gc,phases,ref ] GC(0) FinalReference Discovered: 0, Dropped: 0, Processed: 0
[13.412s][debug][gc,phases,ref ] GC(0) PhantomReference Discovered: 31, Dropped: 0, Processed: 31
[13.412s][debug][gc,phases ] GC(0) Reference Processing 0.376ms
[13.412s][debug][gc,phases,start] GC(0) Weak Processing
[13.412s][debug][gc,phases ] GC(0) Weak Processing 0.106ms
[13.412s][debug][gc,phases,start] GC(0) Class Unloading
[13.412s][debug][gc,phases,start] GC(0) ClassLoaderData
[13.412s][debug][gc,phases ] GC(0) ClassLoaderData 0.008ms
[13.412s][debug][gc,phases,start] GC(0) Trigger cleanups
[13.412s][debug][gc,phases ] GC(0) Trigger cleanups 0.004ms
[13.425s][debug][gc,phases ] GC(0) Class Unloading 13.159ms
[13.425s][debug][gc,phases,start] GC(0) Report Object Count
[13.425s][debug][gc,phases ] GC(0) Report Object Count 0.010ms
[13.425s][info ][gc,phases ] GC(0) Phase 1: Mark live objects 21.783ms
[13.425s][info ][gc,phases,start] GC(0) Phase 2: Compute new object addresses
[13.427s][info ][gc,phases ] GC(0) Phase 2: Compute new object addresses 2.361ms
[13.427s][info ][gc,phases,start] GC(0) Phase 3: Adjust pointers
[13.441s][info ][gc,phases ] GC(0) Phase 3: Adjust pointers 13.790ms
[13.441s][info ][gc,phases,start] GC(0) Phase 4: Move objects
[13.443s][info ][gc,phases ] GC(0) Phase 4: Move objects 2.267ms
[13.447s][debug][gc,ergo,heap ] GC(0) New generation size 126976K->127040K [eden=101696K,survivor=12672K]
[13.447s][info ][gc,heap ] GC(0) DefNew: 14229K(114304K)->0K(114368K) Eden: 14229K(101632K)->0K(101696K) From: 0K(12672K)->0K(12672K)
[13.447s][info ][gc,heap ] GC(0) Tenured: 0K(253952K)->1166K(253952K)
[13.447s][info ][gc,metaspace ] GC(0) Metaspace: 2486K(2624K)->2486K(2624K) NonClass: 2389K(2432K)->2389K(2432K) Class: 96K(192K)->96K(192K)
[13.447s][debug][gc,heap ] GC(0) Heap after GC invocations=1 (full 1):
[13.447s][debug][gc,heap ] GC(0) def new generation total 114368K, used 0K [0x00007fd360a00000, 0x00007fd368610000, 0x00007fd370a00000)
[13.447s][debug][gc,heap ] GC(0) eden space 101696K, 0% used [0x00007fd360a00000, 0x00007fd360a00000, 0x00007fd366d50000)
[13.447s][debug][gc,heap ] GC(0) from space 12672K, 0% used [0x00007fd366d50000, 0x00007fd366d50000, 0x00007fd3679b0000)
[13.447s][debug][gc,heap ] GC(0) to space 12672K, 0% used [0x00007fd3679b0000, 0x00007fd3679b0000, 0x00007fd368610000)
[13.447s][debug][gc,heap ] GC(0) tenured generation total 253952K, used 1166K [0x00007fd370a00000, 0x00007fd380200000, 0x00007fd390a00000)
[13.447s][debug][gc,heap ] GC(0) the space 253952K, 0% used [0x00007fd370a00000, 0x00007fd370b238a8, 0x00007fd370b23a00, 0x00007fd380200000)
[13.447s][debug][gc,heap ] GC(0) Metaspace used 2486K, committed 2624K, reserved 1114112K
[13.447s][debug][gc,heap ] GC(0) class space used 96K, committed 192K, reserved 1048576K
[13.447s][info ][gc ] GC(0) Pause Full (CodeCache GC Threshold) 13M->1M(359M) 44.429ms
[13.447s][info ][gc,cpu ] GC(0) User=0.04s Sys=0.00s Real=0.05s
Collection usage threshold of Tenured Gen set to 10
Calling System.gc()
[13.524s][info ][gc,start ] GC(1) Pause Full (System.gc())
[13.524s][debug][gc,heap ] GC(1) Heap before GC invocations=1 (full 1):
[13.524s][debug][gc,heap ] GC(1) def new generation total 114368K, used 4067K [0x00007fd360a00000, 0x00007fd368610000, 0x00007fd370a00000)
[13.524s][debug][gc,heap ] GC(1) eden space 101696K, 4% used [0x00007fd360a00000, 0x00007fd360df8f90, 0x00007fd366d50000)
[13.524s][debug][gc,heap ] GC(1) from space 12672K, 0% used [0x00007fd366d50000, 0x00007fd366d50000, 0x00007fd3679b0000)
[13.524s][debug][gc,heap ] GC(1) to space 12672K, 0% used [0x00007fd3679b0000, 0x00007fd3679b0000, 0x00007fd368610000)
[13.524s][debug][gc,heap ] GC(1) tenured generation total 253952K, used 1166K [0x00007fd370a00000, 0x00007fd380200000, 0x00007fd390a00000)
[13.524s][debug][gc,heap ] GC(1) the space 253952K, 0% used [0x00007fd370a00000, 0x00007fd370b238a8, 0x00007fd370b23a00, 0x00007fd380200000)
[13.524s][debug][gc,heap ] GC(1) Metaspace used 2517K, committed 2688K, reserved 1114112K
[13.524s][debug][gc,heap ] GC(1) class space used 99K, committed 192K, reserved 1048576K
[13.525s][debug][gc,tlab ] GC(1) TLAB totals: thrds: 2 refills: 2 max: 1 slow allocs: 0 max 0 waste: 99.7% gc: 4152352B max: 2079456B slow: 0B max: 0B
[13.525s][info ][gc,phases,start] GC(1) Phase 1: Mark live objects
[13.536s][debug][gc,phases,start] GC(1) Reference Processing
[13.536s][debug][gc,ref ] GC(1) ReferenceProcessor::execute queues: 1, RefProcThreadModel::Single, marks_oops_alive: false
[13.536s][debug][gc,ref ] GC(1) Skipped KeepAliveFinalRefsPhase of Reference Processing: no references
[13.536s][debug][gc,ref ] GC(1) Skipped PhantomRefsPhase of Reference Processing: no references
[13.536s][debug][gc,phases,ref ] GC(1) Reference Processing: 0.1ms
[13.536s][debug][gc,phases,ref ] GC(1) Notify Soft/WeakReferences: 0.1ms
[13.536s][debug][gc,phases,ref ] GC(1) SoftRef: 0.0ms
[13.536s][debug][gc,phases,ref ] GC(1) WeakRef: 0.0ms
[13.536s][debug][gc,phases,ref ] GC(1) FinalRef: 0.0ms
[13.536s][debug][gc,phases,ref ] GC(1) Total: 0.0ms
[13.536s][debug][gc,phases,ref ] GC(1) Notify and keep alive finalizable: 0.0ms
[13.536s][debug][gc,phases,ref ] GC(1) FinalRef: skipped
[13.536s][debug][gc,phases,ref ] GC(1) Notify PhantomReferences: 0.0ms
[13.536s][debug][gc,phases,ref ] GC(1) PhantomRef: skipped
[13.536s][debug][gc,phases,ref ] GC(1) SoftReference Discovered: 0, Dropped: 0, Processed: 0
[13.536s][debug][gc,phases,ref ] GC(1) WeakReference Discovered: 2, Dropped: 2, Processed: 0
[13.536s][debug][gc,phases,ref ] GC(1) FinalReference Discovered: 0, Dropped: 0, Processed: 0
[13.536s][debug][gc,phases,ref ] GC(1) PhantomReference Discovered: 0, Dropped: 0, Processed: 0
[13.536s][debug][gc,phases ] GC(1) Reference Processing 0.226ms
[13.536s][debug][gc,phases,start] GC(1) Weak Processing
[13.536s][debug][gc,phases ] GC(1) Weak Processing 0.102ms
[13.536s][debug][gc,phases,start] GC(1) Class Unloading
[13.536s][debug][gc,phases,start] GC(1) ClassLoaderData
[13.536s][debug][gc,phases ] GC(1) ClassLoaderData 0.010ms
[13.536s][debug][gc,phases,start] GC(1) Trigger cleanups
[13.536s][debug][gc,phases ] GC(1) Trigger cleanups 0.004ms
[13.551s][debug][gc,phases ] GC(1) Class Unloading 15.533ms
[13.551s][debug][gc,phases,start] GC(1) Report Object Count
[13.551s][debug][gc,phases ] GC(1) Report Object Count 0.005ms
[13.551s][info ][gc,phases ] GC(1) Phase 1: Mark live objects 26.903ms
[13.552s][info ][gc,phases,start] GC(1) Phase 2: Compute new object addresses
[13.552s][info ][gc,phases ] GC(1) Phase 2: Compute new object addresses 0.944ms
[13.552s][info ][gc,phases,start] GC(1) Phase 3: Adjust pointers
[13.561s][info ][gc,phases ] GC(1) Phase 3: Adjust pointers 8.199ms
[13.561s][info ][gc,phases,start] GC(1) Phase 4: Move objects
[13.561s][info ][gc,phases ] GC(1) Phase 4: Move objects 0.714ms
[13.563s][info ][gc,heap ] GC(1) DefNew: 4067K(114368K)->0K(114368K) Eden: 4067K(101696K)->0K(101696K) From: 0K(12672K)->0K(12672K)
[13.563s][info ][gc,heap ] GC(1) Tenured: 1166K(253952K)->1169K(253952K)
[13.563s][info ][gc,metaspace ] GC(1) Metaspace: 2517K(2688K)->2517K(2688K) NonClass: 2417K(2496K)->2417K(2496K) Class: 99K(192K)->99K(192K)
[13.563s][debug][gc,heap ] GC(1) Heap after GC invocations=2 (full 2):
[13.563s][debug][gc,heap ] GC(1) def new generation total 114368K, used 0K [0x00007fd360a00000, 0x00007fd368610000, 0x00007fd370a00000)
[13.563s][debug][gc,heap ] GC(1) eden space 101696K, 0% used [0x00007fd360a00000, 0x00007fd360a00000, 0x00007fd366d50000)
[13.563s][debug][gc,heap ] GC(1) from space 12672K, 0% used [0x00007fd366d50000, 0x00007fd366d50000, 0x00007fd3679b0000)
[13.563s][debug][gc,heap ] GC(1) to space 12672K, 0% used [0x00007fd3679b0000, 0x00007fd3679b0000, 0x00007fd368610000)
[13.563s][debug][gc,heap ] GC(1) tenured generation total 253952K, used 1169K [0x00007fd370a00000, 0x00007fd380200000, 0x00007fd390a00000)
[13.563s][debug][gc,heap ] GC(1) the space 253952K, 0% used [0x00007fd370a00000, 0x00007fd370b246f0, 0x00007fd370b24800, 0x00007fd380200000)
[13.563s][debug][gc,heap ] GC(1) Metaspace used 2517K, committed 2688K, reserved 1114112K
[13.563s][debug][gc,heap ] GC(1) class space used 99K, committed 192K, reserved 1048576K
[13.563s][info ][gc ] GC(1) Pause Full (System.gc()) 5M->1M(359M) 38.603ms
[13.563s][info ][gc,cpu ] GC(1) User=0.04s Sys=0.00s Real=0.04s
Notification for Tenured Gen [type = java.management.memory.collection.threshold.exceeded count = 1]
usage = init = 260046848(253952K) used = 1194152(1166K) committed = 260046848(253952K) max = 536870912(524288K)
notifying the checker thread to check result
Notification for Tenured Gen [type = java.management.memory.collection.threshold.exceeded count = 2]
usage = init = 260046848(253952K) used = 1197808(1169K) committed = 260046848(253952K) max = 536870912(524288K)
notifying the checker thread to check result
[15.728s][info ][gc,heap,exit ] Heap
[15.728s][info ][gc,heap,exit ] def new generation total 114368K, used 10848K [0x00007fd360a00000, 0x00007fd368610000, 0x00007fd370a00000)
[15.728s][info ][gc,heap,exit ] eden space 101696K, 10% used [0x00007fd360a00000, 0x00007fd361498018, 0x00007fd366d50000)
[15.728s][info ][gc,heap,exit ] from space 12672K, 0% used [0x00007fd366d50000, 0x00007fd366d50000, 0x00007fd3679b0000)
[15.728s][info ][gc,heap,exit ] to space 12672K, 0% used [0x00007fd3679b0000, 0x00007fd3679b0000, 0x00007fd368610000)
[15.728s][info ][gc,heap,exit ] tenured generation total 253952K, used 1169K [0x00007fd370a00000, 0x00007fd380200000, 0x00007fd390a00000)
[15.728s][info ][gc,heap,exit ] the space 253952K, 0% used [0x00007fd370a00000, 0x00007fd370b246f0, 0x00007fd370b24800, 0x00007fd380200000)
[15.728s][info ][gc,heap,exit ] Metaspace used 3223K, committed 3328K, reserved 1114112K
[15.728s][info ][gc,heap,exit ] class space used 159K, committed 192K, reserved 1048576K
[15.728s][debug][gc,heap,exit ] Accumulated young generation GC time 0.0000000 secs, 0 GC's, avg GC time 0.0000000
[15.728s][debug][gc,heap,exit ] Accumulated old generation GC time 0.0809754 secs, 2 GC's, avg GC time 0.0404877
[15.729s][info ][gc,verify,start] Verifying
[15.729s][debug][gc,verify ] Threads
[15.729s][debug][gc,verify ] Heap
[15.729s][debug][gc,verify ] tenured generation
[15.738s][debug][gc,verify ] def new generation
[15.742s][debug][gc,verify ] RemSet
[15.746s][debug][gc,verify ] SymbolTable
[15.747s][debug][gc,verify ] StringTable
[15.749s][debug][gc,verify ] CodeCache
[15.766s][debug][gc,verify ] SystemDictionary
[15.770s][debug][gc,verify ] ClassLoaderDataGraph
[15.770s][debug][gc,verify ] MetaspaceUtils
[15.770s][debug][gc,verify ] JNIHandles
[15.770s][debug][gc,verify ] CodeCache Oops
[15.773s][debug][gc,verify ] ResolvedMethodTable Oops
[15.773s][debug][gc,verify ] String Deduplication
[15.773s][info ][gc,verify ] Verifying 44.143ms
];
stderr: [Exception in thread "Checker thread" Exception in thread "main" java.lang.RuntimeException: CollectionUsageThresholdCount = 2 expected to be 1
at CollectionUsageThreshold$Checker.fail(CollectionUsageThreshold.java:264)
at CollectionUsageThreshold$Checker.checkResult(CollectionUsageThreshold.java:248)
at CollectionUsageThreshold$Checker.run(CollectionUsageThreshold.java:227)
java.util.concurrent.BrokenBarrierException
at java.base/java.util.concurrent.CyclicBarrier.dowait(CyclicBarrier.java:252)
at java.base/java.util.concurrent.CyclicBarrier.await(CyclicBarrier.java:364)
at CollectionUsageThreshold$TestMain.main(CollectionUsageThreshold.java:192)
]
exitValue = 1
java.lang.RuntimeException: Expected to get exit value of [0], exit value is: [1]
at jdk.test.lib.process.OutputAnalyzer.shouldHaveExitValue(OutputAnalyzer.java:490)
at RunUtil.runTest(RunUtil.java:78)
at RunUtil.runTestClearGcOpts(RunUtil.java:42)
at CollectionUsageThreshold.main(CollectionUsageThreshold.java:76)
at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103)
at java.base/java.lang.reflect.Method.invoke(Method.java:580)
at com.sun.javatest.regtest.agent.MainWrapper$MainTask.run(MainWrapper.java:138)
at java.base/java.lang.Thread.run(Thread.java:1570)
JavaTest Message: Test threw exception: java.lang.RuntimeException: Expected to get exit value of [0], exit value is: [1]
JavaTest Message: shutting down test
STATUS:Failed.`main' threw exception: java.lang.RuntimeException: Expected to get exit value of [0], exit value is: [1]
- links to
-
Commit(master) openjdk/jdk/162d66ad
-
Review(master) openjdk/jdk/22180