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

gc/g1/TestLargePageUseForAuxMemory.java intermittently times out on Windows

    Details

      Description

      Test gc/g1/TestLargePageUseForAuxMemory.java times out on Windows. It happens 1 time in about 1000 runs.

      Failure has been seen in jdk 12-12 and jdk12-13.

      Test is hanging by waiting results with child process. I haven't to find any info about child process in logs/artifacts for test run.

      The java stack for test is:
      ----------------------------------------
      [2018-09-29 21:14:45] [C:\ade\mesos\work_dir\jib-master\install\jdk\12\13\windows-x64-debug.jdk\jdk-12\fastdebug\bin\jstack.exe, 16176] timeout=20000
      ----------------------------------------
      2018-09-29 21:14:47
      Full thread dump Java HotSpot(TM) 64-Bit Server VM (12-ea+13 mixed mode):

      Threads class SMR info:
      _java_thread_list=0x00000051f9355f80, length=13, elements={
      0x00000051d368f000, 0x00000051f7ba3800, 0x00000051f7bad800, 0x00000051f7c0b000,
      0x00000051f7c0c000, 0x00000051f7c0e800, 0x00000051f7c13000, 0x00000051f7c1d000,
      0x00000051f7eb9000, 0x00000051f802b000, 0x00000051f818a800, 0x00000051f8fc6800,
      0x00000051f92bc000
      }
      _java_thread_list_alloc_cnt=42, _java_thread_list_free_cnt=41, _java_thread_list_max=13, _nested_thread_list_max=1
      _tlh_cnt=3836, _tlh_times=126, avg_tlh_time=0.03, _tlh_time_max=122
      _deleted_thread_cnt=14, _deleted_thread_times=0, avg_deleted_thread_time=0.00, _deleted_thread_time_max=0
      _delete_lock_wait_cnt=0, _delete_lock_wait_max=0
      _to_delete_list_cnt=0, _to_delete_list_max=1

      "main" #1 prio=5 os_prio=0 cpu=414015.63ms elapsed=1265.27s tid=0x00000051d368f000 nid=0x5200 in Object.wait() [0x00000051d2e2f000]
         java.lang.Thread.State: WAITING (on object monitor)
         JavaThread state: _thread_blocked
      Thread: 0x00000051d368f000 [0x5200] State: _at_safepoint _has_called_back 0 _at_poll_safepoint 0
         JavaThread state: _thread_blocked
      at java.lang.Object.wait(java.base@12-ea/Native Method)
      - waiting on <0x00000007178a7490> (a java.lang.Thread)
      at java.lang.Thread.join(java.base@12-ea/Thread.java:1308)
      - waiting to re-lock in wait() <0x00000007178a7490> (a java.lang.Thread)
      at java.lang.Thread.join(java.base@12-ea/Thread.java:1375)
      at com.sun.javatest.regtest.agent.MainWrapper.main(MainWrapper.java:74)

      "Reference Handler" #2 daemon prio=10 os_prio=2 cpu=0.00ms elapsed=677.22s tid=0x00000051f7ba3800 nid=0x7728 waiting on condition [0x00000051f848f000]
         java.lang.Thread.State: RUNNABLE
         JavaThread state: _thread_blocked
      Thread: 0x00000051f7ba3800 [0x7728] State: _at_safepoint _has_called_back 0 _at_poll_safepoint 0
         JavaThread state: _thread_blocked
      at java.lang.ref.Reference.waitForReferencePendingList(java.base@12-ea/Native Method)
      at java.lang.ref.Reference.processPendingReferences(java.base@12-ea/Reference.java:241)
      at java.lang.ref.Reference$ReferenceHandler.run(java.base@12-ea/Reference.java:213)

      "Finalizer" #3 daemon prio=8 os_prio=1 cpu=0.00ms elapsed=677.21s tid=0x00000051f7bad800 nid=0x91a0 in Object.wait() [0x00000051f858e000]
         java.lang.Thread.State: WAITING (on object monitor)
         JavaThread state: _thread_blocked
      Thread: 0x00000051f7bad800 [0x91a0] State: _at_safepoint _has_called_back 0 _at_poll_safepoint 0
         JavaThread state: _thread_blocked
      at java.lang.Object.wait(java.base@12-ea/Native Method)
      - waiting on <0x00000007178e1cc8> (a java.lang.ref.ReferenceQueue$Lock)
      at java.lang.ref.ReferenceQueue.remove(java.base@12-ea/ReferenceQueue.java:155)
      - waiting to re-lock in wait() <0x00000007178e1cc8> (a java.lang.ref.ReferenceQueue$Lock)
      at java.lang.ref.ReferenceQueue.remove(java.base@12-ea/ReferenceQueue.java:176)
      at java.lang.ref.Finalizer$FinalizerThread.run(java.base@12-ea/Finalizer.java:170)

      "Signal Dispatcher" #4 daemon prio=9 os_prio=2 cpu=0.00ms elapsed=677.11s tid=0x00000051f7c0b000 nid=0x80b8 runnable [0x0000000000000000]
         java.lang.Thread.State: RUNNABLE
         JavaThread state: _thread_blocked
      Thread: 0x00000051f7c0b000 [0x80b8] State: _at_safepoint _has_called_back 0 _at_poll_safepoint 0
         JavaThread state: _thread_blocked

      "Attach Listener" #5 daemon prio=5 os_prio=2 cpu=281.25ms elapsed=677.11s tid=0x00000051f7c0c000 nid=0x54f0 waiting on condition [0x0000000000000000]
         java.lang.Thread.State: RUNNABLE
         JavaThread state: _thread_blocked
      Thread: 0x00000051f7c0c000 [0x54f0] State: _at_safepoint _has_called_back 0 _at_poll_safepoint 0
         JavaThread state: _thread_blocked

      "C2 CompilerThread0" #6 daemon prio=9 os_prio=2 cpu=546.88ms elapsed=677.11s tid=0x00000051f7c0e800 nid=0x76c0 waiting on condition [0x0000000000000000]
         java.lang.Thread.State: RUNNABLE
         JavaThread state: _thread_blocked
      Thread: 0x00000051f7c0e800 [0x76c0] State: _at_safepoint _has_called_back 0 _at_poll_safepoint 0
         JavaThread state: _thread_blocked
         No compile task

      "C1 CompilerThread0" #9 daemon prio=9 os_prio=2 cpu=1093.75ms elapsed=677.11s tid=0x00000051f7c13000 nid=0x4d38 waiting on condition [0x0000000000000000]
         java.lang.Thread.State: RUNNABLE
         JavaThread state: _thread_blocked
      Thread: 0x00000051f7c13000 [0x4d38] State: _at_safepoint _has_called_back 0 _at_poll_safepoint 0
         JavaThread state: _thread_blocked
         No compile task

      "Sweeper thread" #10 daemon prio=9 os_prio=2 cpu=0.00ms elapsed=677.11s tid=0x00000051f7c1d000 nid=0x2928 runnable [0x0000000000000000]
         java.lang.Thread.State: RUNNABLE
         JavaThread state: _thread_blocked
      Thread: 0x00000051f7c1d000 [0x2928] State: _at_safepoint _has_called_back 0 _at_poll_safepoint 0
         JavaThread state: _thread_blocked

      "Common-Cleaner" #11 daemon prio=8 os_prio=1 cpu=0.00ms elapsed=676.86s tid=0x00000051f7eb9000 nid=0xe50 in Object.wait() [0x00000051f8b8e000]
         java.lang.Thread.State: TIMED_WAITING (on object monitor)
         JavaThread state: _thread_blocked
      Thread: 0x00000051f7eb9000 [0xe50] State: _at_safepoint _has_called_back 0 _at_poll_safepoint 0
         JavaThread state: _thread_blocked
      at java.lang.Object.wait(java.base@12-ea/Native Method)
      - waiting on <0x00000007178cc190> (a java.lang.ref.ReferenceQueue$Lock)
      at java.lang.ref.ReferenceQueue.remove(java.base@12-ea/ReferenceQueue.java:155)
      - waiting to re-lock in wait() <0x00000007178cc190> (a java.lang.ref.ReferenceQueue$Lock)
      at jdk.internal.ref.CleanerImpl.run(java.base@12-ea/CleanerImpl.java:148)
      at java.lang.Thread.run(java.base@12-ea/Thread.java:835)
      at jdk.internal.misc.InnocuousThread.run(java.base@12-ea/InnocuousThread.java:134)

      "Service Thread" #12 daemon prio=9 os_prio=0 cpu=0.00ms elapsed=676.72s tid=0x00000051f802b000 nid=0x3f98 runnable [0x0000000000000000]
         java.lang.Thread.State: RUNNABLE
         JavaThread state: _thread_blocked
      Thread: 0x00000051f802b000 [0x3f98] State: _at_safepoint _has_called_back 0 _at_poll_safepoint 0
         JavaThread state: _thread_blocked

      "MainThread" #14 prio=5 os_prio=0 cpu=546.88ms elapsed=676.54s tid=0x00000051f818a800 nid=0x92e4 waiting on condition [0x00000051f9e5e000]
         java.lang.Thread.State: WAITING (parking)
         JavaThread state: _thread_blocked
      Thread: 0x00000051f818a800 [0x92e4] State: _at_safepoint _has_called_back 0 _at_poll_safepoint 0
         JavaThread state: _thread_blocked
      at jdk.internal.misc.Unsafe.park(java.base@12-ea/Native Method)
      - parking to wait for <0x000000071817c1e8> (a java.util.concurrent.FutureTask)
      at java.util.concurrent.locks.LockSupport.park(java.base@12-ea/LockSupport.java:194)
      at java.util.concurrent.FutureTask.awaitDone(java.base@12-ea/FutureTask.java:447)
      at java.util.concurrent.FutureTask.get(java.base@12-ea/FutureTask.java:190)
      at jdk.test.lib.process.OutputBuffer$LazyOutputBuffer$StreamTask.get(OutputBuffer.java:79)
      at jdk.test.lib.process.OutputBuffer$LazyOutputBuffer.getStderr(OutputBuffer.java:107)
      at jdk.test.lib.process.OutputAnalyzer.getStderr(OutputAnalyzer.java:502)
      at jdk.test.lib.process.OutputAnalyzer.firstMatch(OutputAnalyzer.java:386)
      at TestLargePageUseForAuxMemory.checkSize(TestLargePageUseForAuxMemory.java:56)
      at TestLargePageUseForAuxMemory.checkSmallTables(TestLargePageUseForAuxMemory.java:71)
      at TestLargePageUseForAuxMemory.testVM(TestLargePageUseForAuxMemory.java:110)
      at TestLargePageUseForAuxMemory.main(TestLargePageUseForAuxMemory.java:169)
      at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(java.base@12-ea/Native Method)
      at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(java.base@12-ea/NativeMethodAccessorImpl.java:62)
      at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(java.base@12-ea/DelegatingMethodAccessorImpl.java:43)
      at java.lang.reflect.Method.invoke(java.base@12-ea/Method.java:566)
      at com.sun.javatest.regtest.agent.MainWrapper$MainThread.run(MainWrapper.java:127)
      at java.lang.Thread.run(java.base@12-ea/Thread.java:835)

      "Thread-15" #29 daemon prio=5 os_prio=0 cpu=15.63ms elapsed=0.12s tid=0x00000051f8fc6800 nid=0x7718 runnable [0x00000051f9f5e000]
         java.lang.Thread.State: RUNNABLE
         JavaThread state: _thread_in_native
      Thread: 0x00000051f8fc6800 [0x7718] State: _at_safepoint _has_called_back 0 _at_poll_safepoint 0
         JavaThread state: _thread_in_native
      at java.io.FileInputStream.readBytes(java.base@12-ea/Native Method)
      at java.io.FileInputStream.read(java.base@12-ea/FileInputStream.java:279)
      at java.io.BufferedInputStream.read1(java.base@12-ea/BufferedInputStream.java:290)
      at java.io.BufferedInputStream.read(java.base@12-ea/BufferedInputStream.java:351)
      - locked <0x0000000718179b58> (a java.io.BufferedInputStream)
      at java.io.BufferedInputStream.fill(java.base@12-ea/BufferedInputStream.java:252)
      at java.io.BufferedInputStream.read1(java.base@12-ea/BufferedInputStream.java:292)
      at java.io.BufferedInputStream.read(java.base@12-ea/BufferedInputStream.java:351)
      - locked <0x000000071817f1a8> (a java.io.BufferedInputStream)
      at java.io.FilterInputStream.read(java.base@12-ea/FilterInputStream.java:107)
      at jdk.test.lib.process.StreamPumper.run(StreamPumper.java:109)
      at java.util.concurrent.Executors$RunnableAdapter.call(java.base@12-ea/Executors.java:515)
      at java.util.concurrent.FutureTask.run(java.base@12-ea/FutureTask.java:264)
      at java.lang.Thread.run(java.base@12-ea/Thread.java:835)

      "Thread-16" #30 daemon prio=5 os_prio=0 cpu=15.63ms elapsed=0.12s tid=0x00000051f92bc000 nid=0x8fec runnable [0x00000051fa05e000]
         java.lang.Thread.State: RUNNABLE
         JavaThread state: _thread_in_native
      Thread: 0x00000051f92bc000 [0x8fec] State: _at_safepoint _has_called_back 0 _at_poll_safepoint 0
         JavaThread state: _thread_in_native
      at java.io.FileInputStream.readBytes(java.base@12-ea/Native Method)
      at java.io.FileInputStream.read(java.base@12-ea/FileInputStream.java:279)
      at java.io.BufferedInputStream.fill(java.base@12-ea/BufferedInputStream.java:252)
      at java.io.BufferedInputStream.read1(java.base@12-ea/BufferedInputStream.java:292)
      at java.io.BufferedInputStream.read(java.base@12-ea/BufferedInputStream.java:351)
      - locked <0x0000000718182f40> (a java.io.BufferedInputStream)
      at java.io.FilterInputStream.read(java.base@12-ea/FilterInputStream.java:107)
      at jdk.test.lib.process.StreamPumper.run(StreamPumper.java:109)
      at java.util.concurrent.Executors$RunnableAdapter.call(java.base@12-ea/Executors.java:515)
      at java.util.concurrent.FutureTask.run(java.base@12-ea/FutureTask.java:264)
      at java.lang.Thread.run(java.base@12-ea/Thread.java:835)

      "VM Thread" os_prio=2 cpu=703.13ms elapsed=677.26s tid=0x00000051f7b79800 nid=0x5738 runnable

      "GC Thread#0" os_prio=2 cpu=140.63ms elapsed=1265.22s tid=0x00000051d36af800 nid=0xb184 runnable

      "GC Thread#1" os_prio=2 cpu=140.63ms elapsed=11.51s tid=0x00000051f7c2c000 nid=0x9fdc runnable

      "GC Thread#2" os_prio=2 cpu=140.63ms elapsed=11.51s tid=0x00000051f7c2e800 nid=0xe58 runnable

      "GC Thread#3" os_prio=2 cpu=15.63ms elapsed=11.51s tid=0x00000051f7c2f800 nid=0xa4b4 runnable

      "GC Thread#4" os_prio=2 cpu=15.63ms elapsed=11.51s tid=0x00000051f7c30000 nid=0x7bc0 runnable

      "GC Thread#5" os_prio=2 cpu=109.38ms elapsed=11.51s tid=0x00000051f93f2800 nid=0x52dc runnable

      "GC Thread#6" os_prio=2 cpu=156.25ms elapsed=11.51s tid=0x00000051f93f3000 nid=0xbaa8 runnable

      "GC Thread#7" os_prio=2 cpu=125.00ms elapsed=11.51s tid=0x00000051f93f5800 nid=0x31b0 runnable

      "G1 Main Marker" os_prio=2 cpu=15.63ms elapsed=677.48s tid=0x00000051d36e4800 nid=0x4034 runnable

      "G1 Conc#0" os_prio=2 cpu=0.00ms elapsed=677.47s tid=0x00000051d36e6000 nid=0x2b58 runnable

      "G1 Refine#0" os_prio=2 cpu=0.00ms elapsed=677.38s tid=0x00000051f6c84000 nid=0x1e24 runnable

      "G1 Young RemSet Sampling" os_prio=2 cpu=62.50ms elapsed=677.38s tid=0x00000051f6c86800 nid=0x20a0 runnable
      "VM Periodic Task Thread" os_prio=2 cpu=421.88ms elapsed=676.71s tid=0x00000051f805d800 nid=0xb2f4 waiting on condition

      JNI global refs: 8, weak refs: 0

      ----------------------------------------
      [2018-09-29 21:14:47] exit code: 0 time: 1854 ms
      ----------------------------------------

        Attachments

          Issue Links

            Activity

              People

              • Assignee:
                rriggs Roger Riggs
                Reporter:
                lmesnik Leonid Mesnik
              • Votes:
                0 Vote for this issue
                Watchers:
                8 Start watching this issue

                Dates

                • Created:
                  Updated: