IJ hangs when I delete from source
Perhaps a dozen times over the last few days I have had to kill and restart IJ because it hung when I deleted Apex class source tokens. I can’t figure out the common factor. Sometimes the deletions would be syntactically correct; other times they might be temporarily incorrect or incomplete, but in any case I am not trying to save when the hang occurs. I have looked in the log and nothing appears to offer any clues. The problem appears intermittent and I can therefore never be sure of reproducing it.
Any advice on how to proceed from here would be appreciated. Thanks.
Comments (12)
-
repo owner -
reporter I used invalidate caches & restart, but immediately got a recurrence. Did I miss a step?
If this was what I should have tried I would be happy to move on to the next step of capturing logs. Unfortunately I cannot do so immediately, since the entire IDE is frozen. So will it suffice if I restart and THEN compress logs and attach here? Not sure what more I can do at this point.
-
repo owner - changed status to resolved
Okay, that's actually good to know. If it's something that occurs right after rebuilding caches/indices, it should be easier to isolate/fix. Yeah, just gather thread dumps and logs right after it occurs. You don't even need to do it from the IDE. You can just open the directory in which they're stored using Help>Show Logs in Explorer/Finder/Files, then when it locks up give it a few and then zip up the contents of that directory and send them my way.
-
repo owner - changed status to open
I have no idea why I changed that resolved just to comment...reopening.
-
reporter So far this issue has not recurred. If it was a flash in the pan, I will update this issue to that effect in a few days. Thanks for your advice.
-
repo owner Okay. If/when it does recur, please send over the thread dumps. If it hasn't recurred in the next week or so we'll resolve the issue.
-
reporter - attached IntelliJIdea2019.1.zip
Just had a recurrence. Here is the compressed log directory.
-
repo owner Thanks for providing the logs, Alan. In the
idea.log
file I can see:2019-06-19 15:05:59,280 [162930375] WARN - ntellij.psi.impl.ApexTypeMixin - The type element is invalid. Returning a null expression type. ... 2019-06-19 15:11:45,485 [163276580] ERROR - j.psi.stubs.StubTreeLoaderImpl - Outdated stub in index: file:///Users/alanbirchenough/IdeaProjects/Meditech Full Sandbox/src/classes/ICON_CreateProforma_Ajax.cls indexed at 1560974791493 with document size 15814, doc=DocumentImpl[file:///Users/alanbirchenough/IdeaProjects/Meditech Full Sandbox/src/classes/ICON_CreateProforma_Ajax.cls], docSaved=false, wasIndexedAlready=true, queried at 1560974791493 indexed lengths={chars=15813, bytes=15786} doc length=15814 file length=15786 cached PSI class com.illuminatedcloud.intellij.filetype.ApexClassFile PSI length=15814 projects with file: 1 java.lang.Exception ... at com.illuminatedcloud.intellij.index.AbstractApexDeclarationStubIndex.get(SourceFile:30) at com.illuminatedcloud.intellij.psi.util.ApexDeclarationUtil.fastFindTypeDeclaration(SourceFile:227) at com.illuminatedcloud.intellij.psi.util.ApexDeclarationUtil.findTypeDeclaration(SourceFile:102) at com.illuminatedcloud.intellij.psi.util.ApexDeclarationUtil.findTypeDeclaration(SourceFile:78) at com.illuminatedcloud.intellij.psi.impl.ApexTypeMixin.lambda$getExpressionType$0(SourceFile:125)
and in the closest matching thread dump (time-wise) I can see two threads executing through IC code that do seem to be stuck:
"JobScheduler FJ pool 0/7" prio=0 tid=0x0 nid=0x0 waiting on condition java.lang.Thread.State: WAITING on com.intellij.util.indexing.StorageGuard@d57de06 at java.lang.Object.wait(Native Method) at java.lang.Object.wait(Object.java:502) at com.intellij.util.indexing.StorageGuard.doWait(StorageGuard.java:63) ... at com.illuminatedcloud.intellij.index.AbstractApexDeclarationStubIndex.get(SourceFile:30) at com.illuminatedcloud.intellij.psi.util.ApexDeclarationUtil.fastFindTypeDeclaration(SourceFile:227) at com.illuminatedcloud.intellij.psi.util.ApexDeclarationUtil.findTypeDeclaration(SourceFile:102) at com.illuminatedcloud.intellij.psi.util.ApexDeclarationUtil.findTypeDeclaration(SourceFile:78) at com.illuminatedcloud.intellij.psi.impl.ApexTypeMixin.lambda$getExpressionType$0(SourceFile:125)
and:
"JobScheduler FJ pool 6/7" prio=0 tid=0x0 nid=0x0 waiting on condition java.lang.Thread.State: TIMED_WAITING on com.intellij.util.concurrency.Semaphore$Sync@45aef161 at sun.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215) ... at com.intellij.util.indexing.FileBasedIndexImpl.lambda$indexUnsavedDocuments$20(FileBasedIndexImpl.java:1255) ... at com.illuminatedcloud.intellij.index.ApexDerivedDeclarationIndex.lambda$getDerivedDeclarations$1(SourceFile:169) at com.illuminatedcloud.intellij.index.ApexDerivedDeclarationIndex$$Lambda$3036/1279329700.compute(Unknown Source) at com.intellij.openapi.util.RecursionManager$1.doPreventingRecursion(RecursionManager.java:116) at com.intellij.openapi.util.RecursionManager.doPreventingRecursion(RecursionManager.java:71) at com.illuminatedcloud.intellij.index.ApexDerivedDeclarationIndex.getDerivedDeclarations(SourceFile:160) at com.illuminatedcloud.intellij.index.ApexDerivedInvokableDeclarationIndex.getDerivedDeclarations(SourceFile:42) at com.illuminatedcloud.intellij.psi.impl.ApexInvokableDeclarationMixin.getDerivedDeclarations(SourceFile:194) at com.illuminatedcloud.intellij.editor.ApexLineMarkerProvider.collectNavigationMarkers(SourceFile:225) at com.illuminatedcloud.intellij.editor.ApexLineMarkerProvider.collectNavigationMarkers(SourceFile:77)
It doesn't seem to be a coincidence to me that something went south in the caches/indices (the entries from
idea.log
) and then these threads deadlocked (perhaps against other IDE threads not going through IC code).Any details on what you were doing leading up to this hang? Based on the logs it just looks like unit test execution and then something that caused IC to enumerate all of the server metadata...perhaps an attempt at a deployment?
For what it's worth, I do see quite a few server communications errors in the log as well, e.g.:
2019-06-19 14:57:40,390 [162431485] WARN - .IlluminatedCloudExceptionUtil - Connection has been shutdown: javax.net.ssl.SSLException: java.net.SocketException: Connection reset javax.net.ssl.SSLException: Connection has been shutdown: javax.net.ssl.SSLException: java.net.SocketException: Connection reset ... at com.illuminatedcloud.client.ForceComApiClient.runWithClient(SourceFile:476) at com.illuminatedcloud.client.ForceComApiClient.runWithClientSimple(SourceFile:502) at com.illuminatedcloud.client.ForceComApiClient.runWithClientSimple(SourceFile:529) at com.illuminatedcloud.client.ApexLogUtil.getApexLogBody(SourceFile:392) at com.illuminatedcloud.intellij.unittest.ApexUnitTestRunProcessHandler.runTestsSynchronous(SourceFile:726) at com.illuminatedcloud.intellij.unittest.ApexUnitTestRunProcessHandler.lambda$startProcessing$5(SourceFile:558)
and:
javax.xml.ws.soap.SOAPFaultException: Unmarshalling Error: Read timed out at org.apache.cxf.jaxws.JaxWsClientProxy.mapException(JaxWsClientProxy.java:195) at org.apache.cxf.jaxws.JaxWsClientProxy.invoke(JaxWsClientProxy.java:145) at com.sun.proxy.$Proxy174.listMetadata(Unknown Source) at com.illuminatedcloud.intellij.builder.ForceComBuilderUtil$1.lambda$process$0(SourceFile:486) at com.illuminatedcloud.client.ForceComApiClient.runWithClient(SourceFile:224) at com.illuminatedcloud.client.ForceComApiClient.runWithClient(SourceFile:339) at com.illuminatedcloud.intellij.builder.ForceComBuilderUtil$1.process(SourceFile:481) at com.illuminatedcloud.intellij.builder.ForceComBuilderUtil$1.process(SourceFile:460) at com.illuminatedcloud.util.ParallelBatchProcessorExecutor.lambda$execute$0(SourceFile:65)
Any idea why those might be occurring? Is the connection to the server poor, or is this another huge org? I doubt that's related, but since it was in the provided logs I figured it's worth asking...
-
repo owner FYI, I was just able to reproduce something very much like this (hopefully the same thing) via
#1315. I'm trying to understand it now so that I can provide a good fix. -
repo owner Okay, I have a prospective fix for this deadlock that will be in the next build (shooting for tomorrow morning).
-
reporter Great. Thanks for the update.
-
repo owner - changed status to resolved
I'm hoping that the changes made in 1.8.5.1/2.0.6.5 will resolve this. Please let me know if you see it occur again after updating.
- Log in to comment
Alan, my first advice would be to totally rebuild caches/indices. My guess is that you've already done that, but it's useful to ensure that things aren't just thrashing on a bad state. Once you know you're in a good caches/indices state and you see the problem occur again, please grab a thread dump of the hanged process so I can see what's going on. IJ takes snapshots every so often so this should be as simple as gather the contents of the log directory using Help>Compress Logs and Show in Explorer/Finder/Files. Please either attach the resulting archive here or email it to me if it might contain sensitive information. Hopefully that will show what's going on.