JDK-8272966 : test/jdk/java/awt/Robot/FlushCurrentEvent.java fails by timeout
  • Type: Bug
  • Component: client-libs
  • Sub-Component: java.awt
  • Affected Version: 11.0.12
  • Priority: P4
  • Status: Resolved
  • Resolution: Fixed
  • OS: generic
  • CPU: generic
  • Submitted: 2021-08-19
  • Updated: 2021-11-03
  • Resolved: 2021-09-10
The Version table provides details related to the release that this issue/RFE will be addressed.

Unresolved : Release in which this issue/RFE will be addressed.
Resolved: Release in which this issue/RFE has been resolved.
Fixed : Release in which this issue/RFE has been fixed. The release containing this fix may be available for download as an Early Access Release or a General Availability Release.

To download the current JDK release, click here.
JDK 11
11.0.14 b01Fixed
Related Reports
Relates :  
JDK-8196100 - javax/swing/text/JTextComponent/5074573/bug5074573.java fails
Description
ADDITIONAL SYSTEM INFORMATION :
MacOS, Windows, Linux/ x86_64/ OpenJDK Runtime Environment 18.9 (build 11.0.12+7)

A DESCRIPTION OF THE PROBLEM :
The test test/jdk/java/awt/Robot/FlushCurrentEvent.java fails by timeout with freeze.

The issue is caused by fix for JDK-8196100

STEPS TO FOLLOW TO REPRODUCE THE PROBLEM :
jtreg -v -a  -testjdk:<test_jdk>  test/jdk/java/awt/Robot/FlushCurrentEvent.java

EXPECTED VERSUS ACTUAL BEHAVIOR :
EXPECTED -
Test passed
ACTUAL -
The test failed by timeout with the following error:

```
----------messages:(154/10513)----------
command: main FlushCurrentEvent
reason: Assumed action based on file name: run main FlushCurrentEvent 
Mode: othervm
Additional options from @modules: --add-modules java.desktop
Timeout information:
Running jstack on process 62746
2021-08-19 20:28:49
Full thread dump OpenJDK 64-Bit Server VM (11.0.12-internal+0-adhoc.mgrishchenko.JetBrainsRuntime mixed mode):

Threads class SMR info:
_java_thread_list=0x00007f5ca4002aa0, length=15, elements={
0x00007f5cf0028800, 0x00007f5cf020b000, 0x00007f5cf020f000, 0x00007f5cf0224000,
0x00007f5cf0226000, 0x00007f5cf0228800, 0x00007f5cf022a800, 0x00007f5cf022c800,
0x00007f5cf02f0000, 0x00007f5cf03fe800, 0x00007f5c90157000, 0x00007f5c9015c800,
0x00007f5c90284000, 0x00007f5c9035b000, 0x00007f5ca4001000
}

"main" #1 prio=5 os_prio=0 cpu=93.47ms elapsed=120.33s tid=0x00007f5cf0028800 nid=0xf51b in Object.wait()  [0x00007f5cf67a7000]
   java.lang.Thread.State: WAITING (on object monitor)
	at java.lang.Object.wait(java.base@11.0.12-internal/Native Method)
	- waiting on <0x0000000718cf67e0> (a java.lang.Thread)
	at java.lang.Thread.join(java.base@11.0.12-internal/Thread.java:1300)
	- waiting to re-lock in wait() <0x0000000718cf67e0> (a java.lang.Thread)
	at java.lang.Thread.join(java.base@11.0.12-internal/Thread.java:1375)
	at com.sun.javatest.regtest.agent.MainWrapper.main(MainWrapper.java:74)

"Reference Handler" #2 daemon prio=10 os_prio=0 cpu=0.19ms elapsed=120.32s tid=0x00007f5cf020b000 nid=0xf525 waiting on condition  [0x00007f5ccc185000]
   java.lang.Thread.State: RUNNABLE
	at java.lang.ref.Reference.waitForReferencePendingList(java.base@11.0.12-internal/Native Method)
	at java.lang.ref.Reference.processPendingReferences(java.base@11.0.12-internal/Reference.java:241)
	at java.lang.ref.Reference$ReferenceHandler.run(java.base@11.0.12-internal/Reference.java:213)

"Finalizer" #3 daemon prio=8 os_prio=0 cpu=0.21ms elapsed=120.31s tid=0x00007f5cf020f000 nid=0xf526 in Object.wait()  [0x00007f5cc57fe000]
   java.lang.Thread.State: WAITING (on object monitor)
	at java.lang.Object.wait(java.base@11.0.12-internal/Native Method)
	- waiting on <0x0000000718d09008> (a java.lang.ref.ReferenceQueue$Lock)
	at java.lang.ref.ReferenceQueue.remove(java.base@11.0.12-internal/ReferenceQueue.java:155)
	- waiting to re-lock in wait() <0x0000000718d09008> (a java.lang.ref.ReferenceQueue$Lock)
	at java.lang.ref.ReferenceQueue.remove(java.base@11.0.12-internal/ReferenceQueue.java:176)
	at java.lang.ref.Finalizer$FinalizerThread.run(java.base@11.0.12-internal/Finalizer.java:170)

"Signal Dispatcher" #4 daemon prio=9 os_prio=0 cpu=0.24ms elapsed=120.31s tid=0x00007f5cf0224000 nid=0xf527 runnable  [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Service Thread" #5 daemon prio=9 os_prio=0 cpu=0.03ms elapsed=120.31s tid=0x00007f5cf0226000 nid=0xf528 runnable  [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C2 CompilerThread0" #6 daemon prio=9 os_prio=0 cpu=150.53ms elapsed=120.31s tid=0x00007f5cf0228800 nid=0xf529 waiting on condition  [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE
   No compile task

"C1 CompilerThread0" #9 daemon prio=9 os_prio=0 cpu=113.93ms elapsed=120.31s tid=0x00007f5cf022a800 nid=0xf52a waiting on condition  [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE
   No compile task

"Sweeper thread" #10 daemon prio=9 os_prio=0 cpu=0.03ms elapsed=120.31s tid=0x00007f5cf022c800 nid=0xf52b runnable  [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Common-Cleaner" #11 daemon prio=8 os_prio=0 cpu=0.39ms elapsed=120.28s tid=0x00007f5cf02f0000 nid=0xf52c in Object.wait()  [0x00007f5cc441a000]
   java.lang.Thread.State: TIMED_WAITING (on object monitor)
	at java.lang.Object.wait(java.base@11.0.12-internal/Native Method)
	- waiting on <0x0000000718c05a98> (a java.lang.ref.ReferenceQueue$Lock)
	at java.lang.ref.ReferenceQueue.remove(java.base@11.0.12-internal/ReferenceQueue.java:155)
	- waiting to re-lock in wait() <0x0000000718c05a98> (a java.lang.ref.ReferenceQueue$Lock)
	at jdk.internal.ref.CleanerImpl.run(java.base@11.0.12-internal/CleanerImpl.java:148)
	at java.lang.Thread.run(java.base@11.0.12-internal/Thread.java:829)
	at jdk.internal.misc.InnocuousThread.run(java.base@11.0.12-internal/InnocuousThread.java:134)

"MainThread" #13 prio=5 os_prio=0 cpu=179.62ms elapsed=120.24s tid=0x00007f5cf03fe800 nid=0xf52e in Object.wait()  [0x00007f5cc4216000]
   java.lang.Thread.State: WAITING (on object monitor)
	at java.lang.Object.wait(java.base@11.0.12-internal/Native Method)
	- waiting on <0x000000071886d830> (a java.awt.EventQueue$1AWTInvocationLock)
	at java.lang.Object.wait(java.base@11.0.12-internal/Object.java:328)
	at java.awt.EventQueue.invokeAndWait(java.desktop@11.0.12-internal/EventQueue.java:1367)
	- waiting to re-lock in wait() <0x000000071886d830> (a java.awt.EventQueue$1AWTInvocationLock)
	at java.awt.EventQueue.invokeAndWait(java.desktop@11.0.12-internal/EventQueue.java:1348)
	at sun.awt.SunToolkit.realSync(java.desktop@11.0.12-internal/SunToolkit.java:1518)
	at sun.awt.SunToolkit.realSync(java.desktop@11.0.12-internal/SunToolkit.java:1464)
	at java.awt.Robot.waitForIdle(java.desktop@11.0.12-internal/Robot.java:693)
	- locked <0x0000000718b31108> (a java.awt.Robot)
	at FlushCurrentEvent.main(FlushCurrentEvent.java:43)
	at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(java.base@11.0.12-internal/Native Method)
	at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(java.base@11.0.12-internal/NativeMethodAccessorImpl.java:62)
	at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(java.base@11.0.12-internal/DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(java.base@11.0.12-internal/Method.java:566)
	at com.sun.javatest.regtest.agent.MainWrapper$MainThread.run(MainWrapper.java:127)
	at java.lang.Thread.run(java.base@11.0.12-internal/Thread.java:829)

"Java2D Disposer" #15 daemon prio=10 os_prio=0 cpu=0.08ms elapsed=120.14s tid=0x00007f5c90157000 nid=0xf537 in Object.wait()  [0x00007f5c895c9000]
   java.lang.Thread.State: WAITING (on object monitor)
	at java.lang.Object.wait(java.base@11.0.12-internal/Native Method)
	- waiting on <0x000000071882d6a8> (a java.lang.ref.ReferenceQueue$Lock)
	at java.lang.ref.ReferenceQueue.remove(java.base@11.0.12-internal/ReferenceQueue.java:155)
	- waiting to re-lock in wait() <0x000000071882d6a8> (a java.lang.ref.ReferenceQueue$Lock)
	at java.lang.ref.ReferenceQueue.remove(java.base@11.0.12-internal/ReferenceQueue.java:176)
	at sun.java2d.Disposer.run(java.desktop@11.0.12-internal/Disposer.java:144)
	at java.lang.Thread.run(java.base@11.0.12-internal/Thread.java:829)

"AWT-XAWT" #16 daemon prio=6 os_prio=0 cpu=35.94ms elapsed=120.14s tid=0x00007f5c9015c800 nid=0xf538 runnable  [0x00007f5c894c8000]
   java.lang.Thread.State: RUNNABLE
	at sun.awt.X11.XToolkit.waitForEvents(java.desktop@11.0.12-internal/Native Method)
	at sun.awt.X11.XToolkit.run(java.desktop@11.0.12-internal/XToolkit.java:693)
	at sun.awt.X11.XToolkit.run(java.desktop@11.0.12-internal/XToolkit.java:657)
	at java.lang.Thread.run(java.base@11.0.12-internal/Thread.java:829)

"AWT-Shutdown" #18 prio=5 os_prio=0 cpu=0.14ms elapsed=120.05s tid=0x00007f5c90284000 nid=0xf539 in Object.wait()  [0x00007f5c88141000]
   java.lang.Thread.State: WAITING (on object monitor)
	at java.lang.Object.wait(java.base@11.0.12-internal/Native Method)
	- waiting on <0x0000000718867c98> (a java.lang.Object)
	at java.lang.Object.wait(java.base@11.0.12-internal/Object.java:328)
	at sun.awt.AWTAutoShutdown.run(java.desktop@11.0.12-internal/AWTAutoShutdown.java:291)
	- waiting to re-lock in wait() <0x0000000718867c98> (a java.lang.Object)
	at java.lang.Thread.run(java.base@11.0.12-internal/Thread.java:829)

"AWT-EventQueue-0" #17 prio=6 os_prio=0 cpu=7.75ms elapsed=120.05s tid=0x00007f5c9035b000 nid=0xf53a waiting for monitor entry  [0x00007f5c73ffc000]
   java.lang.Thread.State: BLOCKED (on object monitor)
	at java.awt.Robot.delay(java.desktop@11.0.12-internal/Robot.java:672)
	- waiting to lock <0x0000000718b31108> (a java.awt.Robot)
	at FlushCurrentEvent.lambda$main$0(FlushCurrentEvent.java:40)
	at FlushCurrentEvent$$Lambda$30/0x00000008000e2840.run(Unknown Source)
	at java.awt.event.InvocationEvent.dispatch(java.desktop@11.0.12-internal/InvocationEvent.java:313)
	at java.awt.EventQueue.dispatchEventImpl(java.desktop@11.0.12-internal/EventQueue.java:776)
	at java.awt.EventQueue$4.run(java.desktop@11.0.12-internal/EventQueue.java:727)
	at java.awt.EventQueue$4.run(java.desktop@11.0.12-internal/EventQueue.java:721)
	at java.security.AccessController.doPrivileged(java.base@11.0.12-internal/Native Method)
	at java.security.ProtectionDomain$JavaSecurityAccessImpl.doIntersectionPrivilege(java.base@11.0.12-internal/ProtectionDomain.java:85)
	at java.awt.EventQueue.dispatchEvent(java.desktop@11.0.12-internal/EventQueue.java:746)
	at java.awt.EventDispatchThread.pumpOneEventForFilters(java.desktop@11.0.12-internal/EventDispatchThread.java:203)
	at java.awt.EventDispatchThread.pumpEventsForFilter(java.desktop@11.0.12-internal/EventDispatchThread.java:124)
	at java.awt.EventDispatchThread.pumpEventsForHierarchy(java.desktop@11.0.12-internal/EventDispatchThread.java:113)
	at java.awt.EventDispatchThread.pumpEvents(java.desktop@11.0.12-internal/EventDispatchThread.java:109)
	at java.awt.EventDispatchThread.pumpEvents(java.desktop@11.0.12-internal/EventDispatchThread.java:101)
	at java.awt.EventDispatchThread.run(java.desktop@11.0.12-internal/EventDispatchThread.java:90)

"Attach Listener" #19 daemon prio=9 os_prio=0 cpu=0.39ms elapsed=0.10s tid=0x00007f5ca4001000 nid=0xf581 waiting on condition  [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"VM Thread" os_prio=0 cpu=7.66ms elapsed=120.32s tid=0x00007f5cf0203000 nid=0xf524 runnable  

"GC Thread#0" os_prio=0 cpu=0.75ms elapsed=120.33s tid=0x00007f5cf0040800 nid=0xf51d runnable  

"G1 Main Marker" os_prio=0 cpu=0.18ms elapsed=120.33s tid=0x00007f5cf009e000 nid=0xf51e runnable  

"G1 Conc#0" os_prio=0 cpu=0.02ms elapsed=120.33s tid=0x00007f5cf00a0000 nid=0xf51f runnable  

"G1 Refine#0" os_prio=0 cpu=0.14ms elapsed=120.33s tid=0x00007f5cf019e000 nid=0xf520 runnable  

"G1 Young RemSet Sampling" os_prio=0 cpu=21.76ms elapsed=120.33s tid=0x00007f5cf019f800 nid=0xf521 runnable  
"VM Periodic Task Thread" os_prio=0 cpu=107.57ms elapsed=120.26s tid=0x00007f5cf034e000 nid=0xf52d waiting on condition  

JNI global refs: 70, weak refs: 0

--- Timeout information end.
elapsed time (seconds): 120.4
```


FREQUENCY : always
Comments
Changeset: 180bc526 Author: Sergey Bylokhov <serb@openjdk.org> Date: 2021-09-10 17:39:08 +0000 URL: https://git.openjdk.java.net/jdk11u/commit/180bc526b025e815b43070150369ae399e27753f
03-11-2021
Changeset: 180bc526 Author: Sergey Bylokhov <serb@openjdk.org> Date: 2021-09-10 17:39:08 +0000 URL: https://git.openjdk.java.net/jdk11u-dev/commit/180bc526b025e815b43070150369ae399e27753f
10-09-2021
Fix Request (11u). This is the fix for the new test failure recently backported to the jdk11.
10-09-2021
Pardeep Sharma cannot reproduce the bug because the cpu repo was used, this bug is for openjdk only.
02-09-2021
The problem caused by the backport JDK-8267722, The test should not be pushed as-is to jdk11.
02-09-2021
Submitter has responded back with confirmation that the test continued to fail at his end. "The test also fails by timeout on Ubuntu 20.04. Besides that I run the test as a standalone application and it also hangs."
02-09-2021
Update from submitter: ========================================================= I checked this test on on Windows 10 (64-bit), this failure is still reproduced. I checked it with OpenJDK 11.0.12+7-ga. It is also observed with OpenJDK 11.0.12+7-ga built by myself. $ /cygdrive/C/Work/jtreg/bin/jtreg -a -v -testjdk:'/cygdrive/d/IdeaProjects/jdk11u-dev/build/windows-x86_64-normal-server-release/images/jdk' test/jdk/java/awt/Robot/FlushCurrentEvent.java runner starting test: java/awt/Robot/FlushCurrentEvent.java runner finished test: java/awt/Robot/FlushCurrentEvent.java Error. Program `d:\IdeaProjects\jdk11u-dev\build\windows-x86_64-normal-server-release\images\jdk\bin\java' timed out (timeout set to 120000ms, elapsed time including timeout hand ling was 120424ms). Test results: error: 1 Report written to D:\IdeaProjects\jdk11u-dev\JTreport\html\report.html Results written to D:\IdeaProjects\jdk11u-dev\JTwork Error: Some tests failed or other problems occurred. The test hangs on src/java.desktop/share/classes/sun/awt/SunToolkit.java:1491 Does this test require any specific environment settings? =========================================================
27-08-2021
Checked this for Windows 10 and macOS 11.5.2 and issue does not reproduce with JDK 11.0.12 b08. Written back to the submitter requesting to recheck with latest build and reconfirm the status. % ./jtreg -v -a ~/workspace/jdk/repository/jdk11u-cpu-open/test/jdk/java/awt/Robot/FlushCurrentEvent.java Directory "JTwork" not found: creating Directory "JTreport" not found: creating runner starting test: java/awt/Robot/FlushCurrentEvent.java runner finished test: java/awt/Robot/FlushCurrentEvent.java Passed. Execution successful Test results: passed: 1 Report written to /Users/user/workspace/sqe/jtreg/bin/JTreport/html/report.html Results written to /Users/user/workspace/sqe/jtreg/bin/JTwork
26-08-2021