search

ant-druha / intellij-powershell

Adds PowerShell language support to IntelliJ-based IDEs.
https://plugins.jetbrains.com/plugin/10249-powershell
Apache License 2.0
74 stars 20 forks source link

Debugger tests are unstable on Windows and Linux #308

Open ForNeVeR opened 3 months ago

ForNeVeR commented 3 months ago

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.

BenSouchet commented 1 month ago

Hi, don't know if it's related but I was redirected here from this bug report I filled for the PyCharm integration: https://youtrack.jetbrains.com/issue/PY-76758/Configurations-with-Powershell-Before-task-dont-work-in-Debug

ForNeVeR commented 1 month ago

No, this is not related. I'll open a new issue about this.