intellij-powershell icon indicating copy to clipboard operation
intellij-powershell copied to clipboard

Debugger tests are unstable on Windows and Linux

Open ForNeVeR opened this issue 1 year ago • 2 comments

So, yeah, they started failing sometimes. Of course, the timeout fails. Example stack:

junit.framework.AssertionFailedError: Pause should be triggered in PT30S
	at junit.framework.Assert.fail(Assert.java:57)
	at junit.framework.Assert.assertTrue(Assert.java:22)
	at junit.framework.TestCase.assertTrue(TestCase.java:192)
	at com.intellij.plugin.powershell.debugger.StepTest$testStepIn$1.invokeSuspend(StepTest.kt:65)
	at _COROUTINE._BOUNDARY._(CoroutineDebugging.kt:42)
	at com.intellij.plugin.powershell.testFramework.DebuggerTestBase$runInEdt$1.invokeSuspend(DebuggerTestBase.kt:23)
Caused by: junit.framework.AssertionFailedError: Pause should be triggered in PT30S
	at junit.framework.Assert.fail(Assert.java:57)
	at junit.framework.Assert.assertTrue(Assert.java:22)
	at junit.framework.TestCase.assertTrue(TestCase.java:192)
	at com.intellij.plugin.powershell.debugger.StepTest$testStepIn$1.invokeSuspend(StepTest.kt:65)
	at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:33)
	at kotlinx.coroutines.DispatchedTask.run(DispatchedTask.kt:104)
	at com.intellij.openapi.application.impl.DispatchedRunnable.run(DispatchedRunnable.kt:44)
	at com.intellij.openapi.application.TransactionGuardImpl.runWithWritingAllowed(TransactionGuardImpl.java:229)
	at com.intellij.openapi.application.TransactionGuardImpl.access$100(TransactionGuardImpl.java:22)
	at com.intellij.openapi.application.TransactionGuardImpl$2.run(TransactionGuardImpl.java:211)
	at com.intellij.openapi.application.impl.AnyThreadWriteThreadingSupport.runWithImplicitRead(AnyThreadWriteThreadingSupport.kt:122)
	at com.intellij.openapi.application.impl.ApplicationImpl.runWithImplicitRead(ApplicationImpl.java:1162)
	at com.intellij.openapi.application.impl.FlushQueue.doRun(FlushQueue.java:78)
	at com.intellij.openapi.application.impl.FlushQueue.runNextEvent(FlushQueue.java:119)
	at com.intellij.openapi.application.impl.FlushQueue.flushNow(FlushQueue.java:41)
	at java.desktop/java.awt.event.InvocationEvent.dispatch(InvocationEvent.java:318)
	at java.desktop/java.awt.EventQueue.dispatchEventImpl(EventQueue.java:781)
	at java.desktop/java.awt.EventQueue$4.run(EventQueue.java:728)
	at java.desktop/java.awt.EventQueue$4.run(EventQueue.java:722)
	at java.base/java.security.AccessController.doPrivileged(AccessController.java:400)
	at java.base/java.security.ProtectionDomain$JavaSecurityAccessImpl.doIntersectionPrivilege(ProtectionDomain.java:87)
	at java.desktop/java.awt.EventQueue.dispatchEvent(EventQueue.java:750)
	at com.intellij.ide.IdeEventQueue.defaultDispatchEvent(IdeEventQueue.kt:696)
	at com.intellij.ide.IdeEventQueue._dispatchEvent$lambda$16(IdeEventQueue.kt:590)
	at com.intellij.openapi.application.impl.AnyThreadWriteThreadingSupport.runWithoutImplicitRead(AnyThreadWriteThreadingSupport.kt:117)
	at com.intellij.ide.IdeEventQueue._dispatchEvent(IdeEventQueue.kt:590)
	at com.intellij.ide.IdeEventQueue.access$_dispatchEvent(IdeEventQueue.kt:73)
	at com.intellij.ide.IdeEventQueue$dispatchEvent$processEventRunnable$1$1$1$1.compute(IdeEventQueue.kt:357)
	at com.intellij.ide.IdeEventQueue$dispatchEvent$processEventRunnable$1$1$1$1.compute(IdeEventQueue.kt:356)
	at com.intellij.openapi.progress.impl.CoreProgressManager.computePrioritized(CoreProgressManager.java:843)
	at com.intellij.ide.IdeEventQueue$dispatchEvent$processEventRunnable$1$1$1.invoke(IdeEventQueue.kt:356)
	at com.intellij.ide.IdeEventQueue$dispatchEvent$processEventRunnable$1$1$1.invoke(IdeEventQueue.kt:351)
	at com.intellij.ide.IdeEventQueueKt$performActivity$runnableWithWIL$1.invoke$lambda$0(IdeEventQueue.kt:1035)
	at com.intellij.openapi.application.WriteIntentReadAction.lambda$run$0(WriteIntentReadAction.java:24)
	at com.intellij.openapi.application.impl.AnyThreadWriteThreadingSupport.runWriteIntentReadAction(AnyThreadWriteThreadingSupport.kt:84)
	at com.intellij.openapi.application.impl.ApplicationImpl.runWriteIntentReadAction(ApplicationImpl.java:910)
	at com.intellij.openapi.application.WriteIntentReadAction.compute(WriteIntentReadAction.java:55)
	at com.intellij.openapi.application.WriteIntentReadAction.run(WriteIntentReadAction.java:23)
	at com.intellij.ide.IdeEventQueueKt$performActivity$runnableWithWIL$1.invoke(IdeEventQueue.kt:1035)
	at com.intellij.ide.IdeEventQueueKt$performActivity$runnableWithWIL$1.invoke(IdeEventQueue.kt:1035)
	at com.intellij.ide.IdeEventQueueKt.performActivity$lambda$1(IdeEventQueue.kt:1036)
	at com.intellij.openapi.application.TransactionGuardImpl.performActivity(TransactionGuardImpl.java:106)
	at com.intellij.ide.IdeEventQueueKt.performActivity(IdeEventQueue.kt:1036)
	at com.intellij.ide.IdeEventQueue.dispatchEvent$lambda$10(IdeEventQueue.kt:351)
	at com.intellij.ide.IdeEventQueue.dispatchEvent(IdeEventQueue.kt:397)
	at java.desktop/java.awt.EventDispatchThread.pumpOneEventForFilters(EventDispatchThread.java:207)
	at java.desktop/java.awt.EventDispatchThread.pumpEventsForFilter(EventDispatchThread.java:128)
	at java.desktop/java.awt.EventDispatchThread.pumpEventsForHierarchy(EventDispatchThread.java:117)
	at java.desktop/java.awt.EventDispatchThread.pumpEvents(EventDispatchThread.java:113)
	at java.desktop/java.awt.EventDispatchThread.pumpEvents(EventDispatchThread.java:105)
	at java.desktop/java.awt.EventDispatchThread.run(EventDispatchThread.java:92)

The corresponding log fragment:

2024-08-25 00:50:48,053 [  19226]   INFO - #c.i.p.p.l.l.l.EditorServicesLanguageHostStarter - host[-1]: DEBUG: Creating startup info object
2024-08-25 00:50:48,054 [  19227]   INFO - #c.i.p.p.l.l.l.EditorServicesLanguageHostStarter - host[-1]: 
2024-08-25 00:50:48,054 [  19227]   INFO - #c.i.p.p.l.l.l.EditorServicesLanguageHostStarter - host[-1]: VERBOSE: Starting server, deregistering host logger and registering shutdown lis
2024-08-25 00:50:48,054 [  19227]   INFO - #c.i.p.p.l.l.l.EditorServicesLanguageHostStarter - host[-1]: 
2024-08-25 00:50:48,054 [  19227]   INFO - #c.i.p.p.l.l.l.EditorServicesLanguageHostStarter - host[-1]: stener
2024-08-25 00:50:48,061 [  19234]   INFO - #c.i.p.p.l.l.l.EditorServicesLanguageHostStarter - host[-1]: 
2024-08-25 00:50:48,061 [  19234]   INFO - #c.i.p.p.l.l.l.EditorServicesLanguageHostStarter - host[-1]: 
2024-08-25 00:50:48,111 [  19284]   INFO - #c.i.p.p.l.l.l.EditorServicesLanguageHostStarter - PowerShell language host process started, SessionInfo(powerShellVersion=7.4.4, status=started, languageService=Pipes(readPipeName=\\.\pipe\in_PSES_fpofjnoq.uz4, writePipeName=\\.\pipe\out_PSES_fpofjnoq.uz4), debuggerService=Pipes(readPipeName=\\.\pipe\in_PSES_c0u2h1ks.4pd, writePipeName=\\.\pipe\out_PSES_c0u2h1ks.4pd)).
2024-08-25 00:50:48,958 [  20131]   INFO - #c.i.p.p.l.l.l.LanguageServerEndpoint - Got server initialize result for C:/Users/runneradmin/AppData/Local/Temp/unitTest_StepIn_2l81m8mMIqpaUMKMVuH7iLuudUe
2024-08-25 00:51:17,358 [  48531]   INFO - #c.i.u.i.ManagedPersistentCache - created persistent map persistent-code-vision-testStepIn-testStepIn2l81mD8oV0mrcTA5TVlZMOuk5t24b66f0ed with size 0
2024-08-25 00:51:17,379 [  48552]   INFO - #c.i.u.i.PersistentDirtyFilesQueue - Dirty file ids stored. Size: 0. Index: 0 Path: D:\a\intellij-powershell\intellij-powershell\build\idea-sandbox\IC-2024.2.0.2\system-test\index\dirty-file-queues\testStepIn_2l81mD8oV0mrcTA5TVlZMOuk5t24b66f0ed. Ids & filenames: {}
2024-08-25 00:51:17,400 [  48573]   INFO - #c.i.p.p.l.l.l.EditorServicesLanguageHostStarter - PowerShell language host process terminated
2024-08-25 00:51:17,400 [  48573]   INFO - #c.i.p.p.l.l.l.LanguageServerEndpoint - Connection to PowerShell language host closed for C:/Users/runneradmin/AppData/Local/Temp/unitTest_StepIn_2l81m8mMIqpaUMKMVuH7iLuudUe.
2024-08-25 00:51:17,487 [  48660]   INFO - #c.i.p.p.l.l.l.EditorServicesLanguageHostStarter - Language host with PID = -1 has exited with code -1.
2024-08-25 00:51:17,525 [  48698]   INFO - #c.i.p.p.l.l.l.EditorServicesLanguageHostStarter - Language host with PID = -1 has exited with code 1.

So, the debug host has been bootstrapped, then a 30-sec pause happened, and then nothing.

So far it's not clear what is causing the error. Let's enable trace logs for debugger in those tests.

ForNeVeR avatar Aug 25 '24 17:08 ForNeVeR