JDK-8197590 : Test serviceability/dcmd/gc/HeapDumpAllTest.java - Agent timeout
  • Type: Bug
  • Component: hotspot
  • Sub-Component: svc
  • Affected Version: 11
  • Priority: P4
  • Status: Resolved
  • Resolution: Cannot Reproduce
  • OS: solaris
  • CPU: sparc
  • Submitted: 2018-02-12
  • Updated: 2020-01-28
  • Resolved: 2019-06-18
Related Reports
Relates :  
JDK-8197591 - Tests failing with App waiting timeout
Description
Test failed with error:
Agent error: java.lang.Exception: Agent 21 timed out with a timeout of 1200 seconds
Comments
We are seeing timeouts with this test on JDK 11 very often. The thread dump looks like this: ACTION: testng -- Error. Agent error: java.lang.Exception: Agent 8 timed out with a timeout of 480 seconds; check console log for any additional details REASON: User specified action: run testng HeapDumpAllTest TIME: 482.286 seconds messages: command: testng HeapDumpAllTest reason: User specified action: run testng HeapDumpAllTest Mode: agentvm Agent id: 8 Additional exports to unnamed modules from @modules: java.base/jdk.internal.misc jdk.internal.jvmstat/sun.jvmstat.monitor Timeout refired 480 times Timeout information: Running jstack on process 28242 2020-01-28 04:57:27 Full thread dump OpenJDK 64-Bit Server VM (11.0.5.0.3-internal+0-TwitterJDK mixed mode): Threads class SMR info: _java_thread_list=0x00007f89a00c1230, length=13, elements={ 0x00007f8b2001e800, 0x00007f8b2017e800, 0x00007f8b20181000, 0x00007f8b201a4000, 0x00007f8b201a6800, 0x00007f8b201a9000, 0x00007f8b201ab800, 0x00007f8b201b6000, 0x00007f8b2023d000, 0x00007f8b2040c000, 0x00007f8b2051a800, 0x00007f8b2059e800, 0x00007f8ac8001000 } _java_thread_list_alloc_cnt=126, _java_thread_list_free_cnt=125, _java_thread_list_max=32, _nested_thread_list_max=1 _tlh_cnt=10074, _tlh_times=69, avg_tlh_time=0.01, _tlh_time_max=27 _deleted_thread_cnt=56, _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=2094.46ms elapsed=487.32s tid=0x00007f8b2001e800 nid=0x6e56 in Object.wait() [0x00007f8b27c10000] java.lang.Thread.State: WAITING (on object monitor) JavaThread state: _thread_blocked Thread: 0x00007f8b2001e800 [0x6e56] State: _at_safepoint _has_called_back 0 _at_poll_safepoint 0 JavaThread state: _thread_blocked at java.lang.Object.wait(java.base@11.0.5.0.3-internal/Native Method) - waiting on <0x00000005f2bb81f8> (a java.lang.Thread) at java.lang.Thread.join(java.base@11.0.5.0.3-internal/Thread.java:1305) - waiting to re-lock in wait() <0x00000005f2bb81f8> (a java.lang.Thread) at java.lang.Thread.join(java.base@11.0.5.0.3-internal/Thread.java:1379) at com.sun.javatest.regtest.agent.MainActionHelper.runClass(MainActionHelper.java:184) at com.sun.javatest.regtest.agent.AgentServer.doMain(AgentServer.java:257) at com.sun.javatest.regtest.agent.AgentServer.run(AgentServer.java:193) at com.sun.javatest.regtest.agent.AgentServer.main(AgentServer.java:65) "Reference Handler" #2 daemon prio=10 os_prio=0 cpu=5.66ms elapsed=485.80s tid=0x00007f8b2017e800 nid=0x6e89 waiting on condition [0x00007f8ae1fda000] java.lang.Thread.State: RUNNABLE JavaThread state: _thread_blocked Thread: 0x00007f8b2017e800 [0x6e89] State: _at_safepoint _has_called_back 0 _at_poll_safepoint 0 JavaThread state: _thread_blocked at java.lang.ref.Reference.waitForReferencePendingList(java.base@11.0.5.0.3-internal/Native Method) at java.lang.ref.Reference.processPendingReferences(java.base@11.0.5.0.3-internal/Reference.java:241) at java.lang.ref.Reference$ReferenceHandler.run(java.base@11.0.5.0.3-internal/Reference.java:213) "Finalizer" #3 daemon prio=8 os_prio=0 cpu=2.33ms elapsed=485.80s tid=0x00007f8b20181000 nid=0x6e8a in Object.wait() [0x00007f8ae1ed9000] java.lang.Thread.State: WAITING (on object monitor) JavaThread state: _thread_blocked Thread: 0x00007f8b20181000 [0x6e8a] State: _at_safepoint _has_called_back 0 _at_poll_safepoint 0 JavaThread state: _thread_blocked at java.lang.Object.wait(java.base@11.0.5.0.3-internal/Native Method) - waiting on <0x00000005d4603b00> (a java.lang.ref.ReferenceQueue$Lock) at java.lang.ref.ReferenceQueue.remove(java.base@11.0.5.0.3-internal/ReferenceQueue.java:155) - waiting to re-lock in wait() <0x00000005d4603b00> (a java.lang.ref.ReferenceQueue$Lock) at java.lang.ref.ReferenceQueue.remove(java.base@11.0.5.0.3-internal/ReferenceQueue.java:176) at java.lang.ref.Finalizer$FinalizerThread.run(java.base@11.0.5.0.3-internal/Finalizer.java:170) "Signal Dispatcher" #4 daemon prio=9 os_prio=0 cpu=2.25ms elapsed=485.77s tid=0x00007f8b201a4000 nid=0x6e8b runnable [0x0000000000000000] java.lang.Thread.State: RUNNABLE JavaThread state: _thread_blocked Thread: 0x00007f8b201a4000 [0x6e8b] State: _at_safepoint _has_called_back 0 _at_poll_safepoint 0 JavaThread state: _thread_blocked "Async Ops Thread 0" #5 daemon prio=9 os_prio=0 cpu=0.08ms elapsed=485.77s tid=0x00007f8b201a6800 nid=0x6e8c runnable [0x0000000000000000] java.lang.Thread.State: RUNNABLE JavaThread state: _thread_in_native Thread: 0x00007f8b201a6800 [0x6e8c] State: _at_safepoint _has_called_back 0 _at_poll_safepoint 0 JavaThread state: _thread_in_native "JVMCI CompilerThread0" #6 daemon prio=9 os_prio=0 cpu=3233.61ms elapsed=485.77s tid=0x00007f8b201a9000 nid=0x6e8d waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE JavaThread state: _thread_blocked Thread: 0x00007f8b201a9000 [0x6e8d] State: _at_safepoint _has_called_back 0 _at_poll_safepoint 0 JavaThread state: _thread_blocked No compile task "C1 CompilerThread0" #18 daemon prio=9 os_prio=0 cpu=3897.99ms elapsed=485.77s tid=0x00007f8b201ab800 nid=0x6e8e waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE JavaThread state: _thread_blocked Thread: 0x00007f8b201ab800 [0x6e8e] State: _at_safepoint _has_called_back 0 _at_poll_safepoint 0 JavaThread state: _thread_blocked No compile task "Sweeper thread" #24 daemon prio=9 os_prio=0 cpu=17.27ms elapsed=485.77s tid=0x00007f8b201b6000 nid=0x6e8f runnable [0x0000000000000000] java.lang.Thread.State: RUNNABLE JavaThread state: _thread_blocked Thread: 0x00007f8b201b6000 [0x6e8f] State: _at_safepoint _has_called_back 0 _at_poll_safepoint 0 JavaThread state: _thread_blocked "Common-Cleaner" #25 daemon prio=8 os_prio=0 cpu=6.13ms elapsed=485.70s tid=0x00007f8b2023d000 nid=0x6e95 in Object.wait() [0x00007f8ae18d3000] java.lang.Thread.State: TIMED_WAITING (on object monitor) JavaThread state: _thread_blocked Thread: 0x00007f8b2023d000 [0x6e95] State: _at_safepoint _has_called_back 0 _at_poll_safepoint 0 JavaThread state: _thread_blocked at java.lang.Object.wait(java.base@11.0.5.0.3-internal/Native Method) - waiting on <0x00000005d4628ec0> (a java.lang.ref.ReferenceQueue$Lock) at java.lang.ref.ReferenceQueue.remove(java.base@11.0.5.0.3-internal/ReferenceQueue.java:155) - waiting to re-lock in wait() <0x00000005d4628ec0> (a java.lang.ref.ReferenceQueue$Lock) at jdk.internal.ref.CleanerImpl.run(java.base@11.0.5.0.3-internal/CleanerImpl.java:148) at java.lang.Thread.run(java.base@11.0.5.0.3-internal/Thread.java:834) at jdk.internal.misc.InnocuousThread.run(java.base@11.0.5.0.3-internal/InnocuousThread.java:134) "Service Thread" #26 daemon prio=9 os_prio=0 cpu=0.07ms elapsed=485.56s tid=0x00007f8b2040c000 nid=0x6e9f runnable [0x0000000000000000] java.lang.Thread.State: RUNNABLE JavaThread state: _thread_blocked Thread: 0x00007f8b2040c000 [0x6e9f] State: _at_safepoint _has_called_back 0 _at_poll_safepoint 0 JavaThread state: _thread_blocked "pool-1-thread-1" #27 daemon prio=5 os_prio=0 cpu=18.01ms elapsed=485.32s tid=0x00007f8b2051a800 nid=0x6eac waiting on condition [0x00007f8ace169000] java.lang.Thread.State: TIMED_WAITING (parking) JavaThread state: _thread_blocked Thread: 0x00007f8b2051a800 [0x6eac] State: _at_safepoint _has_called_back 0 _at_poll_safepoint 0 JavaThread state: _thread_blocked at jdk.internal.misc.Unsafe.park(java.base@11.0.5.0.3-internal/Native Method) - parking to wait for <0x00000005d4649980> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject) at java.util.concurrent.locks.LockSupport.parkNanos(java.base@11.0.5.0.3-internal/LockSupport.java:234) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(java.base@11.0.5.0.3-internal/AbstractQueuedSynchronizer.java:2123) at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(java.base@11.0.5.0.3-internal/ScheduledThreadPoolExecutor.java:1182) at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(java.base@11.0.5.0.3-internal/ScheduledThreadPoolExecutor.java:899) at java.util.concurrent.ThreadPoolExecutor.getTask(java.base@11.0.5.0.3-internal/ThreadPoolExecutor.java:1054) at java.util.concurrent.ThreadPoolExecutor.runWorker(java.base@11.0.5.0.3-internal/ThreadPoolExecutor.java:1114) at java.util.concurrent.ThreadPoolExecutor$Worker.run(java.base@11.0.5.0.3-internal/ThreadPoolExecutor.java:628) at java.lang.Thread.run(java.base@11.0.5.0.3-internal/Thread.java:834) "AgentVMThread" #31 prio=5 os_prio=0 cpu=454952.15ms elapsed=480.77s tid=0x00007f8b2059e800 nid=0x6fe5 runnable [0x00007f8acd90c000] java.lang.Thread.State: RUNNABLE JavaThread state: _thread_blocked Thread: 0x00007f8b2059e800 [0x6fe5] State: _call_back _has_called_back 1 _at_poll_safepoint 0 JavaThread state: _thread_blocked at java.io.RandomAccessFile.read0(java.base@11.0.5.0.3-internal/Native Method) at java.io.RandomAccessFile.read(java.base@11.0.5.0.3-internal/RandomAccessFile.java:366) at java.io.RandomAccessFile.readInt(java.base@11.0.5.0.3-internal/RandomAccessFile.java:832) at java.io.RandomAccessFile.readLong(java.base@11.0.5.0.3-internal/RandomAccessFile.java:870) at jdk.test.lib.hprof.parser.FileReadBuffer.getLong(FileReadBuffer.java:87) - locked <0x00000005f31260d8> (a jdk.test.lib.hprof.parser.FileReadBuffer) at jdk.test.lib.hprof.model.JavaLazyReadObject.longAt(JavaLazyReadObject.java:156) at jdk.test.lib.hprof.model.JavaLazyReadObject.objectIdAt(JavaLazyReadObject.java:130) at jdk.test.lib.hprof.model.JavaObject.parseFields(JavaObject.java:263) at jdk.test.lib.hprof.model.JavaObject.getFields(JavaObject.java:117) at jdk.test.lib.hprof.model.JavaObject.visitReferencedObjects(JavaObject.java:142) at jdk.test.lib.hprof.model.Snapshot.calculateReferencesToObjects(Snapshot.java:323) at jdk.test.lib.hprof.model.Snapshot.resolve(Snapshot.java:291) at jdk.test.lib.hprof.HprofParser.parse(HprofParser.java:87) at jdk.test.lib.hprof.HprofParser.parse(HprofParser.java:54) at HeapDumpTest.verifyHeapDump(HeapDumpTest.java:69) at HeapDumpTest.run(HeapDumpTest.java:62) at HeapDumpTest.pid(HeapDumpTest.java:88) at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(java.base@11.0.5.0.3-internal/Native Method) at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(java.base@11.0.5.0.3-internal/NativeMethodAccessorImpl.java:62) at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(java.base@11.0.5.0.3-internal/DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(java.base@11.0.5.0.3-internal/Method.java:566) at org.testng.internal.MethodInvocationHelper.invokeMethod(MethodInvocationHelper.java:85) at org.testng.internal.Invoker.invokeMethod(Invoker.java:639) at org.testng.internal.Invoker.invokeTestMethod(Invoker.java:821) at org.testng.internal.Invoker.invokeTestMethods(Invoker.java:1131) at org.testng.internal.TestMethodWorker.invokeTestMethods(TestMethodWorker.java:125) at org.testng.internal.TestMethodWorker.run(TestMethodWorker.java:108) at org.testng.TestRunner.privateRun(TestRunner.java:773) at org.testng.TestRunner.run(TestRunner.java:623) at org.testng.SuiteRunner.runTest(SuiteRunner.java:357) at org.testng.SuiteRunner.runSequentially(SuiteRunner.java:352) at org.testng.SuiteRunner.privateRun(SuiteRunner.java:310) at org.testng.SuiteRunner.run(SuiteRunner.java:259) at org.testng.SuiteRunnerWorker.runSuite(SuiteRunnerWorker.java:52) at org.testng.SuiteRunnerWorker.run(SuiteRunnerWorker.java:86) at org.testng.TestNG.runSuitesSequentially(TestNG.java:1185) at org.testng.TestNG.runSuitesLocally(TestNG.java:1110) at org.testng.TestNG.run(TestNG.java:1018) at com.sun.javatest.regtest.agent.TestNGRunner.main(TestNGRunner.java:94) at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(java.base@11.0.5.0.3-internal/Native Method) at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(java.base@11.0.5.0.3-internal/NativeMethodAccessorImpl.java:62) at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(java.base@11.0.5.0.3-internal/DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(java.base@11.0.5.0.3-internal/Method.java:566) at com.sun.javatest.regtest.agent.MainActionHelper$AgentVMRunnable.run(MainActionHelper.java:298) at java.lang.Thread.run(java.base@11.0.5.0.3-internal/Thread.java:834) "Attach Listener" #35 daemon prio=9 os_prio=0 cpu=8.63ms elapsed=479.52s tid=0x00007f8ac8001000 nid=0x7185 waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE JavaThread state: _thread_blocked Thread: 0x00007f8ac8001000 [0x7185] State: _at_safepoint _has_called_back 0 _at_poll_safepoint 0 JavaThread state: _thread_blocked "VM Thread" os_prio=0 cpu=20955.45ms elapsed=485.81s tid=0x00007f8b20168000 nid=0x6e86 runnable "ParGC Thread#0" os_prio=0 cpu=2386.86ms elapsed=486.00s tid=0x00007f8b2003e800 nid=0x6e67 runnable "ParGC Thread#1" os_prio=0 cpu=2364.03ms elapsed=484.50s tid=0x00007f8adc041000 nid=0x6f0c runnable "ParGC Thread#2" os_prio=0 cpu=2335.13ms elapsed=484.50s tid=0x00007f8adc043000 nid=0x6f0d runnable "ParGC Thread#3" os_prio=0 cpu=2284.42ms elapsed=484.50s tid=0x00007f8adc044800 nid=0x6f0e runnable "ParGC Thread#4" os_prio=0 cpu=2339.37ms elapsed=484.50s tid=0x00007f8adc046800 nid=0x6f0f runnable "ParGC Thread#5" os_prio=0 cpu=2323.67ms elapsed=484.50s tid=0x00007f8adc048800 nid=0x6f10 runnable "ParGC Thread#6" os_prio=0 cpu=2289.03ms elapsed=484.50s tid=0x00007f8adc04a800 nid=0x6f11 runnable "ParGC Thread#7" os_prio=0 cpu=2384.34ms elapsed=484.50s tid=0x00007f8adc04c000 nid=0x6f12 runnable "ParGC Thread#8" os_prio=0 cpu=2361.85ms elapsed=484.50s tid=0x00007f8adc04e000 nid=0x6f13 runnable "ParGC Thread#9" os_prio=0 cpu=2353.48ms elapsed=484.50s tid=0x00007f8adc050000 nid=0x6f14 runnable "ParGC Thread#10" os_prio=0 cpu=2316.70ms elapsed=484.49s tid=0x00007f8adc052000 nid=0x6f15 runnable "ParGC Thread#11" os_prio=0 cpu=2386.57ms elapsed=484.49s tid=0x00007f8adc054000 nid=0x6f16 runnable "ParGC Thread#12" os_prio=0 cpu=2351.77ms elapsed=484.49s tid=0x00007f8adc056000 nid=0x6f17 runnable "ParGC Thread#13" os_prio=0 cpu=2348.56ms elapsed=484.49s tid=0x00007f8adc058800 nid=0x6f18 runnable "ParGC Thread#14" os_prio=0 cpu=2313.49ms elapsed=484.49s tid=0x00007f8adc05a800 nid=0x6f19 runnable "ParGC Thread#15" os_prio=0 cpu=2272.22ms elapsed=484.49s tid=0x00007f8adc05c800 nid=0x6f1a runnable "ParGC Thread#16" os_prio=0 cpu=2322.86ms elapsed=484.49s tid=0x00007f8adc05e800 nid=0x6f1b runnable "ParGC Thread#17" os_prio=0 cpu=2346.47ms elapsed=484.49s tid=0x00007f8adc061000 nid=0x6f1c runnable "ParGC Thread#18" os_prio=0 cpu=2321.72ms elapsed=484.49s tid=0x00007f8adc063000 nid=0x6f1d runnable "ParGC Thread#19" os_prio=0 cpu=2298.91ms elapsed=484.49s tid=0x00007f8adc065000 nid=0x6f1e runnable "ParGC Thread#20" os_prio=0 cpu=2367.53ms elapsed=484.49s tid=0x00007f8adc067000 nid=0x6f1f runnable "ParGC Thread#21" os_prio=0 cpu=2352.01ms elapsed=484.49s tid=0x00007f8adc069800 nid=0x6f20 runnable "ParGC Thread#22" os_prio=0 cpu=2307.53ms elapsed=484.49s tid=0x00007f8adc06b800 nid=0x6f21 runnable "ParGC Thread#23" os_prio=0 cpu=2360.68ms elapsed=484.49s tid=0x00007f8adc06d800 nid=0x6f22 runnable "ParGC Thread#24" os_prio=0 cpu=2313.14ms elapsed=484.49s tid=0x00007f8adc06f800 nid=0x6f23 runnable "ParGC Thread#25" os_prio=0 cpu=2315.38ms elapsed=484.49s tid=0x00007f8adc072000 nid=0x6f24 runnable "ParGC Thread#26" os_prio=0 cpu=2316.11ms elapsed=484.49s tid=0x00007f8adc074000 nid=0x6f25 runnable "ParGC Thread#27" os_prio=0 cpu=2353.33ms elapsed=484.49s tid=0x00007f8adc076000 nid=0x6f26 runnable "ParGC Thread#28" os_prio=0 cpu=2298.17ms elapsed=484.49s tid=0x00007f8adc078000 nid=0x6f27 runnable "ParGC Thread#29" os_prio=0 cpu=2363.28ms elapsed=484.49s tid=0x00007f8adc07a800 nid=0x6f28 runnable "ParGC Thread#30" os_prio=0 cpu=2329.29ms elapsed=484.48s tid=0x00007f8adc07c800 nid=0x6f29 runnable "ParGC Thread#31" os_prio=0 cpu=2314.66ms elapsed=484.48s tid=0x00007f8adc07e800 nid=0x6f2a runnable "ParGC Thread#32" os_prio=0 cpu=2364.16ms elapsed=484.48s tid=0x00007f8adc080800 nid=0x6f2b runnable "ParGC Thread#33" os_prio=0 cpu=2329.51ms elapsed=484.48s tid=0x00007f8adc083000 nid=0x6f2c runnable "ParGC Thread#34" os_prio=0 cpu=2342.10ms elapsed=484.48s tid=0x00007f8adc085000 nid=0x6f2d runnable "ParGC Thread#35" os_prio=0 cpu=2389.54ms elapsed=484.48s tid=0x00007f8adc087000 nid=0x6f2e runnable "ParGC Thread#36" os_prio=0 cpu=2304.56ms elapsed=484.48s tid=0x00007f8adc089000 nid=0x6f2f runnable "ParGC Thread#37" os_prio=0 cpu=2389.58ms elapsed=484.48s tid=0x00007f8adc08b800 nid=0x6f30 runnable "ParGC Thread#38" os_prio=0 cpu=2353.00ms elapsed=484.48s tid=0x00007f8adc08d800 nid=0x6f31 runnable "ParGC Thread#39" os_prio=0 cpu=2287.29ms elapsed=484.48s tid=0x00007f8adc08f800 nid=0x6f32 runnable "ParGC Thread#40" os_prio=0 cpu=2284.89ms elapsed=484.48s tid=0x00007f8adc091800 nid=0x6f33 runnable "ParGC Thread#41" os_prio=0 cpu=2345.59ms elapsed=484.48s tid=0x00007f8adc093800 nid=0x6f34 runnable "ParGC Thread#42" os_prio=0 cpu=2341.99ms elapsed=484.48s tid=0x00007f8adc096000 nid=0x6f35 runnable "ParGC Thread#43" os_prio=0 cpu=2332.23ms elapsed=484.48s tid=0x00007f8adc098000 nid=0x6f36 runnable "ParGC Thread#44" os_prio=0 cpu=2354.77ms elapsed=484.48s tid=0x00007f8adc09a000 nid=0x6f37 runnable "ParGC Thread#45" os_prio=0 cpu=2365.50ms elapsed=484.48s tid=0x00007f8adc09c000 nid=0x6f38 runnable "ParGC Thread#46" os_prio=0 cpu=2339.79ms elapsed=484.48s tid=0x00007f8adc09e800 nid=0x6f39 runnable "ParGC Thread#47" os_prio=0 cpu=1219.63ms elapsed=268.65s tid=0x00007f8adc021000 nid=0xa860 runnable "ParGC Thread#48" os_prio=0 cpu=1274.08ms elapsed=268.65s tid=0x00007f8adc022000 nid=0xa861 runnable "ParGC Thread#49" os_prio=0 cpu=1250.29ms elapsed=268.65s tid=0x00007f8adc023000 nid=0xa862 runnable "ParGC Thread#50" os_prio=0 cpu=1273.30ms elapsed=268.65s tid=0x00007f8adc024800 nid=0xa863 runnable "ParGC Thread#51" os_prio=0 cpu=1250.24ms elapsed=268.65s tid=0x00007f8adc025800 nid=0xa864 runnable "ParGC Thread#52" os_prio=0 cpu=1251.38ms elapsed=268.65s tid=0x00007f8adc026800 nid=0xa865 runnable "VM Periodic Task Thread" os_prio=0 cpu=108.15ms elapsed=485.56s tid=0x00007f8b2040f000 nid=0x6ea0 waiting on condition JNI global refs: 31, weak refs: 548
28-01-2020
I also do not see any clue in both the log and the stack trace. The only idea is that there can be something wrong with the sockets or tmp on this Solaris machine. Temporarily targeting this issue to 11, at least, for initial evaluation/investigation.
03-04-2018
I don't think HeapDumpAllTest.java uses LingeredApp. It calls into HeapDumpTest which is the serviceability/dcmd/gc/HeapDumpTest.java and it does not use LingeredApp.
21-02-2018
harness.trace contains: Test finished: serviceability/dcmd/gc/HeapDumpAllTest.java: Error. Agent error: java.lang.Exception: Agent 21 timed out with a timeout of 1200 seconds; check console log for any additional details I'm not sure which console log it is referring to. But in any case, the agent has timed out and there is a core file for the agent that appears to have been forced due to the timeout. Here's the jstack output: ---------------------------------------- [2018-02-11 12:23:01] [/scratch/opt/mach5/mesos/work_dir/jib-master/install/2018-02-10-1400083.vm-sqe-notifications_ww_grp.pit180208/solaris-sparcv9-debug.jdk/jdk-11/fastdebug/bin/jstack, 54733] timeout=20000 ---------------------------------------- 2018-02-11 12:23:06 Full thread dump Java HotSpot(TM) 64-Bit Server VM (11-internal+0-2018-02-10-1400083.vm-sqe-notificationswwgrp.pit180208 mixed mode): Threads class SMR info: _java_thread_list=0x0000000101fee130, length=24, elements={ 0x0000000100130000, 0x0000000100941000, 0x0000000100954800, 0x0000000100972000, 0x0000000100974800, 0x0000000100977800, 0x0000000100979800, 0x0000000100981000, 0x0000000100982800, 0x000000010098d000, 0x000000010098f800, 0x0000000100999800, 0x000000010099c000, 0x000000010099e800, 0x00000001009a9000, 0x00000001009ab800, 0x00000001009ad800, 0x0000000100a2c000, 0x0000000100a38000, 0x0000000100a43000, 0x0000000100c31000, 0x0000000100ef0000, 0x00000001011d7800, 0x0000000100d3e800 } _java_thread_list_alloc_cnt=33,_java_thread_list_free_cnt=32,_java_thread_list_max=28, _nested_thread_list_max=1 _tlh_cnt=7041, _tlh_times=49, avg_tlh_time=0.01, _tlh_time_max=42 _deleted_thread_cnt=4, _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=64 tid=0x0000000100130000 nid=0x2 runnable [0xffffffff7d2fe000] java.lang.Thread.State: RUNNABLE JavaThread state: _thread_in_native Thread: 0x0000000100130000 [0x 2] State: _at_safepoint _has_called_back 0 _at_poll_safepoint 0 JavaThread state: _thread_in_native at java.net.SocketInputStream.socketRead0(java.base@11-internal/Native Method) at java.net.SocketInputStream.socketRead(java.base@11-internal/SocketInputStream.java:116) at java.net.SocketInputStream.read(java.base@11-internal/SocketInputStream.java:171) at java.net.SocketInputStream.read(java.base@11-internal/SocketInputStream.java:141) at java.io.BufferedInputStream.fill(java.base@11-internal/BufferedInputStream.java:252) at java.io.BufferedInputStream.read(java.base@11-internal/BufferedInputStream.java:271) - locked <0x000000078ed1e9e0> (a java.io.BufferedInputStream) at java.io.FilterInputStream.read(java.base@11-internal/FilterInputStream.java:83) at com.sun.javatest.regtest.agent.AgentServer.run(AgentServer.java:177) at com.sun.javatest.regtest.agent.AgentServer.main(AgentServer.java:59) "Reference Handler" #2 daemon prio=10 os_prio=64 tid=0x0000000100941000 nid=0x22 waiting on condition [0xffffffff540ff000] java.lang.Thread.State: RUNNABLE JavaThread state: _thread_blocked Thread: 0x0000000100941000 [0x22] State: _at_safepoint _has_called_back 0 _at_poll_safepoint 0 JavaThread state: _thread_blocked at java.lang.ref.Reference.waitForReferencePendingList(java.base@11-internal/Native Method) at java.lang.ref.Reference.processPendingReferences(java.base@11-internal/Reference.java:166) at java.lang.ref.Reference.access$000(java.base@11-internal/Reference.java:44) at java.lang.ref.Reference$ReferenceHandler.run(java.base@11-internal/Reference.java:138) "Finalizer" #3 daemon prio=8 os_prio=64 tid=0x0000000100954800 nid=0x23 in Object.wait() [0xffffffff53dfe000] java.lang.Thread.State: WAITING (on object monitor) JavaThread state: _thread_blocked Thread: 0x0000000100954800 [0x23] State: _at_safepoint _has_called_back 0 _at_poll_safepoint 0 JavaThread state: _thread_blocked at java.lang.Object.wait(java.base@11-internal/Native Method) - waiting on <0x000000078ec08f08> (a java.lang.ref.ReferenceQueue$Lock) at java.lang.ref.ReferenceQueue.remove(java.base@11-internal/ReferenceQueue.java:151) - waiting to re-lock in wait() <0x000000078ec08f08> (a java.lang.ref.ReferenceQueue$Lock) at java.lang.ref.ReferenceQueue.remove(java.base@11-internal/ReferenceQueue.java:172) at java.lang.ref.Finalizer$FinalizerThread.run(java.base@11-internal/Finalizer.java:216) "Signal Dispatcher" #4 daemon prio=9 os_prio=64 tid=0x0000000100972000 nid=0x24 runnable [0x0000000000000000] java.lang.Thread.State: RUNNABLE JavaThread state: _thread_blocked Thread: 0x0000000100972000 [0x24] State: _at_safepoint _has_called_back 0 _at_poll_safepoint 0 JavaThread state: _thread_blocked "C2 CompilerThread0" #5 daemon prio=9 os_prio=64 tid=0x0000000100974800 nid=0x25 waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE JavaThread state: _thread_blocked Thread: 0x0000000100974800 [0x25] State: _at_safepoint _has_called_back 0 _at_poll_safepoint 0 JavaThread state: _thread_blocked No compile task "C2 CompilerThread1" #6 daemon prio=9 os_prio=64 tid=0x0000000100977800 nid=0x26 waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE JavaThread state: _thread_blocked Thread: 0x0000000100977800 [0x26] State: _at_safepoint _has_called_back 0 _at_poll_safepoint 0 JavaThread state: _thread_blocked No compile task "C2 CompilerThread2" #7 daemon prio=9 os_prio=64 tid=0x0000000100979800 nid=0x27 waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE JavaThread state: _thread_blocked Thread: 0x0000000100979800 [0x27] State: _at_safepoint _has_called_back 0 _at_poll_safepoint 0 JavaThread state: _thread_blocked No compile task "C2 CompilerThread3" #8 daemon prio=9 os_prio=64 tid=0x0000000100981000 nid=0x28 waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE JavaThread state: _thread_blocked Thread: 0x0000000100981000 [0x28] State: _at_safepoint _has_called_back 0 _at_poll_safepoint 0 JavaThread state: _thread_blocked No compile task "C2 CompilerThread4" #9 daemon prio=9 os_prio=64 tid=0x0000000100982800 nid=0x29 waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE JavaThread state: _thread_blocked Thread: 0x0000000100982800 [0x29] State: _at_safepoint _has_called_back 0 _at_poll_safepoint 0 JavaThread state: _thread_blocked No compile task "C2 CompilerThread5" #10 daemon prio=9 os_prio=64 tid=0x000000010098d000 nid=0x2a waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE JavaThread state: _thread_blocked Thread: 0x000000010098d000 [0x2a] State: _at_safepoint _has_called_back 0 _at_poll_safepoint 0 JavaThread state: _thread_blocked No compile task "C2 CompilerThread6" #11 daemon prio=9 os_prio=64 tid=0x000000010098f800 nid=0x2b waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE JavaThread state: _thread_blocked Thread: 0x000000010098f800 [0x2b] State: _at_safepoint _has_called_back 0 _at_poll_safepoint 0 JavaThread state: _thread_blocked No compile task "C2 CompilerThread7" #12 daemon prio=9 os_prio=64 tid=0x0000000100999800 nid=0x2c waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE JavaThread state: _thread_blocked Thread: 0x0000000100999800 [0x2c] State: _at_safepoint _has_called_back 0 _at_poll_safepoint 0 JavaThread state: _thread_blocked No compile task "C2 CompilerThread8" #13 daemon prio=9 os_prio=64 tid=0x000000010099c000 nid=0x2d waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE JavaThread state: _thread_blocked Thread: 0x000000010099c000 [0x2d] State: _at_safepoint _has_called_back 0 _at_poll_safepoint 0 JavaThread state: _thread_blocked No compile task "C2 CompilerThread9" #14 daemon prio=9 os_prio=64 tid=0x000000010099e800 nid=0x2e waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE JavaThread state: _thread_blocked Thread: 0x000000010099e800 [0x2e] State: _at_safepoint _has_called_back 0 _at_poll_safepoint 0 JavaThread state: _thread_blocked No compile task "C1 CompilerThread10" #15 daemon prio=9 os_prio=64 tid=0x00000001009a9000 nid=0x2f waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE JavaThread state: _thread_blocked Thread: 0x00000001009a9000 [0x2f] State: _at_safepoint _has_called_back 0 _at_poll_safepoint 0 JavaThread state: _thread_blocked No compile task "C1 CompilerThread11" #16 daemon prio=9 os_prio=64 tid=0x00000001009ab800 nid=0x30 waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE JavaThread state: _thread_blocked Thread: 0x00000001009ab800 [0x30] State: _at_safepoint _has_called_back 0 _at_poll_safepoint 0 JavaThread state: _thread_blocked No compile task "C1 CompilerThread12" #17 daemon prio=9 os_prio=64 tid=0x00000001009ad800 nid=0x31 waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE JavaThread state: _thread_blocked Thread: 0x00000001009ad800 [0x31] State: _at_safepoint _has_called_back 0 _at_poll_safepoint 0 JavaThread state: _thread_blocked No compile task "C1 CompilerThread13" #18 daemon prio=9 os_prio=64 tid=0x0000000100a2c000 nid=0x32 waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE JavaThread state: _thread_blocked Thread: 0x0000000100a2c000 [0x32] State: _at_safepoint _has_called_back 0 _at_poll_safepoint 0 JavaThread state: _thread_blocked No compile task "C1 CompilerThread14" #19 daemon prio=9 os_prio=64 tid=0x0000000100a38000 nid=0x33 waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE JavaThread state: _thread_blocked Thread: 0x0000000100a38000 [0x33] State: _at_safepoint _has_called_back 0 _at_poll_safepoint 0 JavaThread state: _thread_blocked No compile task "Sweeper thread" #20 daemon prio=9 os_prio=64 tid=0x0000000100a43000 nid=0x34 runnable [0x0000000000000000] java.lang.Thread.State: RUNNABLE JavaThread state: _thread_blocked Thread: 0x0000000100a43000 [0x34] State: _at_safepoint _has_called_back 0 _at_poll_safepoint 0 JavaThread state: _thread_blocked "Common-Cleaner" #21 daemon prio=8 os_prio=64 tid=0x0000000100c31000 nid=0x35 in Object.wait() [0xffffffff50dfe000] java.lang.Thread.State: TIMED_WAITING (on object monitor) JavaThread state: _thread_blocked Thread: 0x0000000100c31000 [0x35] State: _at_safepoint _has_called_back 0 _at_poll_safepoint 0 JavaThread state: _thread_blocked at java.lang.Object.wait(java.base@11-internal/Native Method) - waiting on <0x000000078ec3a990> (a java.lang.ref.ReferenceQueue$Lock) at java.lang.ref.ReferenceQueue.remove(java.base@11-internal/ReferenceQueue.java:151) - waiting to re-lock in wait() <0x000000078ec3a990> (a java.lang.ref.ReferenceQueue$Lock) at jdk.internal.ref.CleanerImpl.run(java.base@11-internal/CleanerImpl.java:148) at java.lang.Thread.run(java.base@11-internal/Thread.java:844) at jdk.internal.misc.InnocuousThread.run(java.base@11-internal/InnocuousThread.java:134) "Service Thread" #22 daemon prio=9 os_prio=64 tid=0x0000000100ef0000 nid=0x36 runnable [0x0000000000000000] java.lang.Thread.State: RUNNABLE JavaThread state: _thread_blocked Thread: 0x0000000100ef0000 [0x36] State: _at_safepoint _has_called_back 0 _at_poll_safepoint 0 JavaThread state: _thread_blocked "pool-1-thread-1" #23 daemon prio=5 os_prio=64 tid=0x00000001011d7800 nid=0x38 waiting on condition [0xffffffff503fe000] java.lang.Thread.State: WAITING (parking) JavaThread state: _thread_blocked Thread: 0x00000001011d7800 [0x38] State: _at_safepoint _has_called_back 0 _at_poll_safepoint 0 JavaThread state: _thread_blocked at jdk.internal.misc.Unsafe.park(java.base@11-internal/Native Method) - parking to wait for <0x000000078ed24cb8> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject) at java.util.concurrent.locks.LockSupport.park(java.base@11-internal/LockSupport.java:194) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(java.base@11-internal/AbstractQueuedSynchronizer.java:2081) at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(java.base@11-internal/ScheduledThreadPoolExecutor.java:1170) at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(java.base@11-internal/ScheduledThreadPoolExecutor.java:899) at java.util.concurrent.ThreadPoolExecutor.getTask(java.base@11-internal/ThreadPoolExecutor.java:1057) at java.util.concurrent.ThreadPoolExecutor.runWorker(java.base@11-internal/ThreadPoolExecutor.java:1117) at java.util.concurrent.ThreadPoolExecutor$Worker.run(java.base@11-internal/ThreadPoolExecutor.java:631) at java.lang.Thread.run(java.base@11-internal/Thread.java:844) "Attach Listener" #28 daemon prio=9 os_prio=64 tid=0x0000000100d3e800 nid=0x3d waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE JavaThread state: _thread_blocked Thread: 0x0000000100d3e800 [0x3d] State: _at_safepoint _has_called_back 0 _at_poll_safepoint 0 JavaThread state: _thread_blocked "VM Thread" os_prio=64 tid=0x000000010093c800 nid=0x21 runnable "GC Thread#0" os_prio=64 tid=0x0000000100144000 nid=0x3 runnable "GC Thread#1" os_prio=64 tid=0x0000000100146000 nid=0x4 runnable "GC Thread#2" os_prio=64 tid=0x0000000100147800 nid=0x5 runnable "GC Thread#3" os_prio=64 tid=0x0000000100149800 nid=0x6 runnable "GC Thread#4" os_prio=64 tid=0x000000010014b800 nid=0x7 runnable "GC Thread#5" os_prio=64 tid=0x000000010014d000 nid=0x8 runnable "GC Thread#6" os_prio=64 tid=0x000000010014f000 nid=0x9 runnable "GC Thread#7" os_prio=64 tid=0x0000000100151000 nid=0xa runnable "GC Thread#8" os_prio=64 tid=0x0000000100152800 nid=0xb runnable "GC Thread#9" os_prio=64 tid=0x0000000100154800 nid=0xc runnable "GC Thread#10" os_prio=64 tid=0x0000000100156000 nid=0xd runnable "GC Thread#11" os_prio=64 tid=0x0000000100158000 nid=0xe runnable "GC Thread#12" os_prio=64 tid=0x000000010015a000 nid=0xf runnable "GC Thread#13" os_prio=64 tid=0x000000010015b800 nid=0x10 runnable "GC Thread#14" os_prio=64 tid=0x000000010015d800 nid=0x11 runnable "GC Thread#15" os_prio=64 tid=0x000000010015f800 nid=0x12 runnable "GC Thread#16" os_prio=64 tid=0x0000000100161000 nid=0x13 runnable "GC Thread#17" os_prio=64 tid=0x0000000100163000 nid=0x14 runnable "GC Thread#18" os_prio=64 tid=0x0000000100164800 nid=0x15 runnable "GC Thread#19" os_prio=64 tid=0x0000000100166800 nid=0x16 runnable "GC Thread#20" os_prio=64 tid=0x0000000100168800 nid=0x17 runnable "GC Thread#21" os_prio=64 tid=0x000000010016a000 nid=0x18 runnable "GC Thread#22" os_prio=64 tid=0x000000010016c000 nid=0x19 runnable "CMS Main Thread" os_prio=64 tid=0x00000001002b4000 nid=0x20 runnable "CMS Thread#0" os_prio=64 tid=0x00000001002a6800 nid=0x1a runnable "CMS Thread#1" os_prio=64 tid=0x00000001002a8800 nid=0x1b runnable "CMS Thread#2" os_prio=64 tid=0x00000001002aa000 nid=0x1c runnable "CMS Thread#3" os_prio=64 tid=0x00000001002ac000 nid=0x1d runnable "CMS Thread#4" os_prio=64 tid=0x00000001002ae000 nid=0x1e runnable "CMS Thread#5" os_prio=64 tid=0x00000001002af800 nid=0x1f runnable "VM Periodic Task Thread" os_prio=64 tid=0x0000000100efe000 nid=0x37 waiting on condition JNI global refs: 18, weak refs: 0 ---------------------------------------- [2018-02-11 12:23:07] exit code: 0 time: 5351 ms ----------------------------------------
12-02-2018
This is probably a dup of JDK-8197591 since it occurred in the same test run, but keeping it separate for now since the JDK-8197591 failures all involve what appears to be a failure to launch LingerApp. In this case a jcmd has failed in some manner, but it is unclear why. I don't see any clues in the test log.
12-02-2018