Uploaded image for project: 'JDK'
  1. JDK
  2. JDK-8318668

java/lang/management/MemoryMXBean/CollectionUsageThreshold.java fails with Xcomp

XMLWordPrintable

      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]

        There are no Sub-Tasks for this issue.

            rsunderbabu Ramkumar Sunderbabu
            lmesnik Leonid Mesnik
            Votes:
            0 Vote for this issue
            Watchers:
            3 Start watching this issue

              Created:
              Updated: