Hi Sergey,
Here's the stacktrace on timeout. It seems that robot events are not
processed so EDT hangs and jtreg test did not finish. Calling
waitForIdle() probably allow those events to process.
Timeout information:
Running jstack on process 16896
2018-02-14 10:57:56
Full thread dump Java HotSpot(TM) 64-Bit Server VM (10-ea+41 mixed mode):
Threads class SMR info:
_java_thread_list=0x000001b8718ef900, length=18, elements={
0x000001b83d8ad000, 0x000001b865155800, 0x000001b865156800, 0x000001b8651b6800,
0x000001b8651b7000, 0x000001b8651bc000, 0x000001b8651be800, 0x000001b8651bf800,
0x000001b8651d3800, 0x000001b8651c8800, 0x000001b865774000, 0x000001b865895000,
0x000001b86592e800, 0x000001b865cb9000, 0x000001b8656fb000, 0x000001b865a39800,
0x000001b865b79000, 0x000001b871cc1000
}
"main" #1 prio=5 os_prio=0 tid=0x000001b83d8ad000 nid=0x3e84 in Object.wait()
[0x0000003e642fe000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(java.base@10-ea/Native Method)
- waiting on <0x00000006d2880200> (a java.lang.Thread)
at java.lang.Thread.join(java.base@10-ea/Thread.java:1353)
- waiting to re-lock in wait() <0x00000006d2880200> (a java.lang.Thread)
at java.lang.Thread.join(java.base@10-ea/Thread.java:1427)
at
java.lang.ApplicationShutdownHooks.runHooks(java.base@10-ea/ApplicationShutdownHooks.java:107)
at
java.lang.ApplicationShutdownHooks$1.run(java.base@10-ea/ApplicationShutdownHooks.java:46)
at java.lang.Shutdown.runHooks(java.base@10-ea/Shutdown.java:123)
at java.lang.Shutdown.sequence(java.base@10-ea/Shutdown.java:167)
at java.lang.Shutdown.exit(java.base@10-ea/Shutdown.java:212)
- locked <0x00000006d28858b8> (a java.lang.Class for java.lang.Shutdown)
at java.lang.Runtime.exit(java.base@10-ea/Runtime.java:118)
at java.lang.System.exit(java.base@10-ea/System.java:1720)
at com.sun.javatest.regtest.agent.AStatus.exit(AStatus.java:199)
at com.sun.javatest.regtest.agent.MainWrapper.main(MainWrapper.java:83)
"Reference Handler" #2 daemon prio=10 os_prio=2 tid=0x000001b865155800
nid=0x4f54 waiting on condition [0x0000003e658fe000]
java.lang.Thread.State: RUNNABLE
at
java.lang.ref.Reference.waitForReferencePendingList(java.base@10-ea/Native
Method)
at
java.lang.ref.Reference.processPendingReferences(java.base@10-ea/Reference.java:174)
at java.lang.ref.Reference.access$000(java.base@10-ea/Reference.java:44)
at
java.lang.ref.Reference$ReferenceHandler.run(java.base@10-ea/Reference.java:138)
"Finalizer" #3 daemon prio=8 os_prio=1 tid=0x000001b865156800 nid=0x1518 in
Object.wait() [0x0000003e659fe000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(java.base@10-ea/Native Method)
- waiting on <0x00000006d2f09408> (a java.lang.ref.ReferenceQueue$Lock)
at
java.lang.ref.ReferenceQueue.remove(java.base@10-ea/ReferenceQueue.java:151)
- waiting to re-lock in wait() <0x00000006d2f09408> (a
java.lang.ref.ReferenceQueue$Lock)
at
java.lang.ref.ReferenceQueue.remove(java.base@10-ea/ReferenceQueue.java:172)
at
java.lang.ref.Finalizer$FinalizerThread.run(java.base@10-ea/Finalizer.java:216)
"Signal Dispatcher" #4 daemon prio=9 os_prio=2 tid=0x000001b8651b6800
nid=0x562c runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"Attach Listener" #5 daemon prio=5 os_prio=2 tid=0x000001b8651b7000 nid=0x40a8
waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"C2 CompilerThread0" #6 daemon prio=9 os_prio=2 tid=0x000001b8651bc000
nid=0x5388 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
No compile task
"C2 CompilerThread1" #7 daemon prio=9 os_prio=2 tid=0x000001b8651be800
nid=0xa44 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
No compile task
"C2 CompilerThread2" #8 daemon prio=9 os_prio=2 tid=0x000001b8651bf800
nid=0x1744 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
No compile task
"C1 CompilerThread3" #9 daemon prio=9 os_prio=2 tid=0x000001b8651d3800
nid=0x2f68 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
No compile task
"Sweeper thread" #10 daemon prio=9 os_prio=2 tid=0x000001b8651c8800 nid=0x4fb4
runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"Service Thread" #11 daemon prio=9 os_prio=0 tid=0x000001b865774000 nid=0x5da4
runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"Common-Cleaner" #12 daemon prio=8 os_prio=1 tid=0x000001b865895000 nid=0x5218
in Object.wait() [0x0000003e663ff000]
java.lang.Thread.State: TIMED_WAITING (on object monitor)
at java.lang.Object.wait(java.base@10-ea/Native Method)
- waiting on <0x00000006d2ee5f38> (a java.lang.ref.ReferenceQueue$Lock)
at
java.lang.ref.ReferenceQueue.remove(java.base@10-ea/ReferenceQueue.java:151)
- waiting to re-lock in wait() <0x00000006d2ee5f38> (a
java.lang.ref.ReferenceQueue$Lock)
at
jdk.internal.ref.CleanerImpl.run(java.base@10-ea/CleanerImpl.java:148)
at java.lang.Thread.run(java.base@10-ea/Thread.java:844)
at
jdk.internal.misc.InnocuousThread.run(java.base@10-ea/InnocuousThread.java:134)
"Java2D Disposer" #15 daemon prio=10 os_prio=2 tid=0x000001b86592e800
nid=0x1294 in Object.wait() [0x0000003e665ff000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(java.base@10-ea/Native Method)
- waiting on <0x00000006d2a00908> (a java.lang.ref.ReferenceQueue$Lock)
at
java.lang.ref.ReferenceQueue.remove(java.base@10-ea/ReferenceQueue.java:151)
- waiting to re-lock in wait() <0x00000006d2a00908> (a
java.lang.ref.ReferenceQueue$Lock)
at
java.lang.ref.ReferenceQueue.remove(java.base@10-ea/ReferenceQueue.java:172)
at sun.java2d.Disposer.run(java.desktop@10-ea/Disposer.java:144)
at java.lang.Thread.run(java.base@10-ea/Thread.java:844)
"AWT-Shutdown" #16 prio=5 os_prio=0 tid=0x000001b865cb9000 nid=0x1250 in
Object.wait() [0x0000003e666ff000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(java.base@10-ea/Native Method)
- waiting on <0x00000006d286d188> (a java.lang.Object)
at java.lang.Object.wait(java.base@10-ea/Object.java:328)
at
sun.awt.AWTAutoShutdown.run(java.desktop@10-ea/AWTAutoShutdown.java:291)
- waiting to re-lock in wait() <0x00000006d286d188> (a java.lang.Object)
at java.lang.Thread.run(java.base@10-ea/Thread.java:844)
"AWT-Windows" #17 daemon prio=6 os_prio=0 tid=0x000001b8656fb000 nid=0x423c
runnable [0x0000003e667fe000]
java.lang.Thread.State: RUNNABLE
at sun.awt.windows.WToolkit.eventLoop(java.desktop@10-ea/Native Method)
at sun.awt.windows.WToolkit.run(java.desktop@10-ea/WToolkit.java:301)
at java.lang.Thread.run(java.base@10-ea/Thread.java:844)
"AWT-EventQueue-0" #19 prio=6 os_prio=0 tid=0x000001b865a39800 nid=0x4624
waiting on condition [0x0000003e668fe000]
java.lang.Thread.State: WAITING (parking)
at jdk.internal.misc.Unsafe.park(java.base@10-ea/Native Method)
- parking to wait for <0x00000006d2744b20> (a
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
at
java.util.concurrent.locks.LockSupport.park(java.base@10-ea/LockSupport.java:194)
at
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(java.base@10-ea/AbstractQueuedSynchronizer.java:2075)
at
java.awt.EventQueue.getNextEvent(java.desktop@10-ea/EventQueue.java:566)
at
java.awt.EventDispatchThread.pumpOneEventForFilters(java.desktop@10-ea/EventDispatchThread.java:190)
at
java.awt.EventDispatchThread.pumpEventsForFilter(java.desktop@10-ea/EventDispatchThread.java:124)
at
java.awt.EventDispatchThread.pumpEventsForHierarchy(java.desktop@10-ea/EventDispatchThread.java:113)
at
java.awt.EventDispatchThread.pumpEvents(java.desktop@10-ea/EventDispatchThread.java:109)
at
java.awt.EventDispatchThread.pumpEvents(java.desktop@10-ea/EventDispatchThread.java:101)
at
java.awt.EventDispatchThread.run(java.desktop@10-ea/EventDispatchThread.java:90)
"TimerQueue" #20 daemon prio=5 os_prio=0 tid=0x000001b865b79000 nid=0x5b90
waiting on condition [0x0000003e669fe000]
java.lang.Thread.State: WAITING (parking)
at jdk.internal.misc.Unsafe.park(java.base@10-ea/Native Method)
- parking to wait for <0x00000006d24b2df8> (a
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
at
java.util.concurrent.locks.LockSupport.park(java.base@10-ea/LockSupport.java:194)
at
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(java.base@10-ea/AbstractQueuedSynchronizer.java:2075)
at
java.util.concurrent.DelayQueue.take(java.base@10-ea/DelayQueue.java:217)
at javax.swing.TimerQueue.run(java.desktop@10-ea/TimerQueue.java:171)
at java.lang.Thread.run(java.base@10-ea/Thread.java:844)
"ToolkitShutdown" #18 daemon prio=6 os_prio=0 tid=0x000001b871cc1000 nid=0x50c4
runnable [0x0000003e66fff000]
java.lang.Thread.State: RUNNABLE
at sun.awt.windows.WToolkit.shutdown(java.desktop@10-ea/Native Method)
at
sun.awt.windows.WToolkit$$Lambda$13/1860234640.run(java.desktop@10-ea/Unknown
Source)
at java.lang.Thread.run(java.base@10-ea/Thread.java:844)
"VM Thread" os_prio=2 tid=0x000001b86514f000 nid=0x4e10 runnable
"GC Thread#0" os_prio=2 tid=0x000001b83d8c3800 nid=0x45d8 runnable
"GC Thread#1" os_prio=2 tid=0x000001b83d8c5800 nid=0x760 runnable
"GC Thread#2" os_prio=2 tid=0x000001b83d8c7800 nid=0x5368 runnable
"GC Thread#3" os_prio=2 tid=0x000001b83d8cb000 nid=0x5504 runnable
"GC Thread#4" os_prio=2 tid=0x000001b83d8cc800 nid=0x4bec runnable
"GC Thread#5" os_prio=2 tid=0x000001b83d8d6800 nid=0x4d74 runnable
"GC Thread#6" os_prio=2 tid=0x000001b83d8d2800 nid=0x472c runnable
"GC Thread#7" os_prio=2 tid=0x000001b83d8d7000 nid=0x5d10 runnable
"G1 Main Marker" os_prio=2 tid=0x000001b83d92d800 nid=0x17b4 runnable
"G1 Conc#0" os_prio=2 tid=0x000001b83d8d3000 nid=0x55ec runnable
"G1 Conc#1" os_prio=2 tid=0x000001b83d8d3800 nid=0x4790 runnable
"G1 Refine#0" os_prio=2 tid=0x000001b861e3e000 nid=0x4f4c runnable
"G1 Refine#1" os_prio=2 tid=0x000001b861e3f000 nid=0x5014 runnable
"G1 Refine#2" os_prio=2 tid=0x000001b861e42000 nid=0x3adc runnable
"G1 Refine#3" os_prio=2 tid=0x000001b861e47000 nid=0x4ba8 runnable
"G1 Refine#4" os_prio=2 tid=0x000001b83d8d4800 nid=0x498c runnable
"G1 Refine#5" os_prio=2 tid=0x000001b83d8d1000 nid=0x5e04 runnable
"G1 Refine#6" os_prio=2 tid=0x000001b83d8d7800 nid=0x398c runnable
"G1 Refine#7" os_prio=2 tid=0x000001b83d8d8800 nid=0x55d4 runnable
"G1 Young RemSet Sampling" os_prio=2 tid=0x000001b861e5a000 nid=0x4948 runnable
"VM Periodic Task Thread" os_prio=2 tid=0x000001b8653d4000 nid=0x4958 waiting
on condition
JNI global references: 181
--- Timeout information end.
On 2/14/2018 3:56 AM, Sergey Bylokhov wrote:
Hi, Prasanta.
Did you have a chance to get a stack trace on timeout? The change in
the tests are correct but it is unclear in what place the test may
hang and why the changes fixed it.
On 13/02/2018 01:22, Prasanta Sadhukhan wrote:
Hi All,
Please review a testfix seen in the recent sprint-run, whereby the
test seems to times out .
Seems like test is issuing mouse events without waiting for robot to
process those events.
Enhance the test to allow robot to process the events and also
dispose of the frame once done,
so it should not bother other tests when run in bunch.
Bug: https://bugs.openjdk.java.net/browse/JDK-8197825
webrev: http://cr.openjdk.java.net/~psadhukhan/8197825/webrev.00/
Regards
Prasanta
