TestBug269121 reports deadlock more often since I20221022-1800

[iloveeclipse]

Earlier occurrences are random on different platforms:

• https://download.eclipse.org/eclipse/downloads/drops4/I20220912-1800/testresults/html/org.eclipse.ui.tests_ep426I-unit-cen64-gtk3-java18_linux.gtk.x86_64_18.html
• https://download.eclipse.org/eclipse/downloads/drops4/I20220919-0240/testresults/html/org.eclipse.ui.tests_ep426I-unit-cen64-gtk3-java18_linux.gtk.x86_64_18.html
• https://download.eclipse.org/eclipse/downloads/drops4/I20221017-1800/testresults/html/org.eclipse.ui.tests_ep426I-unit-mac64-java17_macosx.cocoa.x86_64_17.html

Latest fails are only on Java 17 Linux builds, but seem to happen more often:

• https://download.eclipse.org/eclipse/downloads/drops4/I20221022-1800/testresults/html/org.eclipse.ui.tests_ep426I-unit-cen64-gtk3-java17_linux.gtk.x86_64_17.html
• https://download.eclipse.org/eclipse/downloads/drops4/I20221023-1800/testresults/html/org.eclipse.ui.tests_ep426I-unit-cen64-gtk3-java17_linux.gtk.x86_64_17.html
• https://download.eclipse.org/eclipse/downloads/drops4/I20221025-1800/testresults/html/org.eclipse.ui.tests_ep426I-unit-cen64-gtk3-java17_linux.gtk.x86_64_17.html

Deadlock occurred

java.lang.AssertionError: Deadlock occurred
at org.junit.Assert.fail(Assert.java:89)
at org.junit.Assert.assertTrue(Assert.java:42)
at org.eclipse.ui.tests.concurrency.TestBug269121.testBug(TestBug269121.java:106)

[jukzi]

All those failed tests log stacktraces similar to this:

!ENTRY org.eclipse.core.jobs 4 2 2022-09-13 03:39:41.893
!MESSAGE An internal error occurred during: "Checking for deadlock".
!STACK 0
java.lang.AssertionError: Timeout after 1000ms waiting for status to change from DONE to DONE
 [ThreadDump taken from thread 'Worker-12: Checking for deadlock' at 2022-09-13 03:39:41.889:
   Thread "main" #1 prio=6 RUNNABLE
     at org.eclipse.swt.internal.gtk3.GTK3.gtk_main_iteration_do(Native Method)
     at org.eclipse.swt.widgets.Display.readAndDispatch(Display.java:4474)
     at org.eclipse.ui.internal.dialogs.EventLoopProgressMonitor.runEventLoop(EventLoopProgressMonitor.java:126)
     at org.eclipse.ui.internal.dialogs.EventLoopProgressMonitor.isCanceled(EventLoopProgressMonitor.java:100)
     at org.eclipse.core.runtime.SubMonitor$RootInfo.isCanceled(SubMonitor.java:235)
     at org.eclipse.core.runtime.SubMonitor.isCanceled(SubMonitor.java:581)
     at org.eclipse.core.runtime.ProgressMonitorWrapper.isCanceled(ProgressMonitorWrapper.java:114)
     at org.eclipse.ui.internal.dialogs.EventLoopProgressMonitor.isCanceled(EventLoopProgressMonitor.java:101)
     at org.eclipse.core.internal.jobs.ThreadJob.isCanceled(ThreadJob.java:148)
     at org.eclipse.core.internal.jobs.ThreadJob.waitForRun(ThreadJob.java:280)
     at org.eclipse.core.internal.jobs.ThreadJob.joinRun(ThreadJob.java:208)
     at org.eclipse.core.internal.jobs.ImplicitJobs.begin(ImplicitJobs.java:95)
     at org.eclipse.core.internal.jobs.JobManager.beginRule(JobManager.java:315)
     at org.eclipse.core.internal.resources.WorkManager.checkIn(WorkManager.java:124)
     at org.eclipse.core.internal.resources.Workspace.prepareOperation(Workspace.java:2330)
     at org.eclipse.core.internal.resources.Workspace.run(Workspace.java:2375)
     at org.eclipse.core.internal.resources.Workspace.run(Workspace.java:2405)
     at org.eclipse.ui.actions.WorkspaceModifyOperation.run(WorkspaceModifyOperation.java:131)
     at org.eclipse.jface.operation.ModalContext.runInCurrentThread(ModalContext.java:434)
     at org.eclipse.jface.operation.ModalContext.run(ModalContext.java:352)
     at org.eclipse.jface.dialogs.ProgressMonitorDialog.run(ProgressMonitorDialog.java:470)
     at org.eclipse.ui.tests.concurrency.TestBug269121.testBug(TestBug269121.java:96)

1. GTK3.gtk_main_iteration_do(Native Method)-> it's totally unrelated to JobManager, that GTK is hanging
2. "Timeout after 1000ms waiting for status to change from DONE to DONE" => the test would have passed in the next millisecond. =>The test machine is just a tiny bit too slow for the timeout.

[iloveeclipse]

Thanks Jörg, I've pushed, we will see if that helps.

[jukzi]

happened again:

https://download.eclipse.org/eclipse/downloads/drops4/I20230525-0350/testresults/html/org.eclipse.ui.tests_ep428I-unit-win32-java17_win32.win32.x86_64_17.html

java.lang.AssertionError: Deadlock occurred
at org.junit.Assert.fail(Assert.java:89)
at org.junit.Assert.assertTrue(Assert.java:42)
at org.eclipse.ui.tests.concurrency.TestBug269121.testBug(TestBug269121.java:106)

[jukzi]

The logging reveals it was only a timeout: I will increase timeout from 1s to 5s
https://download.eclipse.org/eclipse/downloads/drops4/I20230525-0350/testresults/ep428I-unit-win32-java17_win32.win32.x86_64_17/org.eclipse.ui.tests.UiTestSuite.txt

java.lang.AssertionError: Timeout after 1207ms waiting for status to change from UNKNOWN_STATUS to DONE
 [ThreadDump taken from thread 'Worker-0: Checking for deadlock' at 2023-05-25 13:09:43.522:
   Thread "main" #1 prio=6 RUNNABLE
...
     at org.eclipse.ui.internal.progress.ProgressManager.getRootElements(ProgressManager.java:781)
     at org.eclipse.ui.internal.progress.ProgressContentProvider.getElements(ProgressContentProvider.java:51)
     at org.eclipse.ui.internal.progress.ProgressViewerContentProvider.getElements(ProgressViewerContentProvider.java:81)
...
   Thread "Worker-0: Checking for deadlock" #29 prio=5 RUNNABLE
     at java.base@17.0.5/java.lang.Thread.dumpThreads(Native Method)
     at java.base@17.0.5/java.lang.Thread.getAllStackTraces(Thread.java:1662)
     at org.eclipse.core.tests.harness.TestBarrier2.getThreadDump(TestBarrier2.java:109)
     at org.eclipse.core.tests.harness.TestBarrier2.doWaitForStatus(TestBarrier2.java:93)
     at org.eclipse.core.tests.harness.TestBarrier2.waitForStatus(TestBarrier2.java:148)
     at org.eclipse.ui.tests.concurrency.TestBug269121$3.run(TestBug269121.java:82)
     at org.eclipse.core.internal.jobs.Worker.run(Worker.java:63)