1. Scott Wells Avatar Scott Wells
  2. Illuminated Cloud
  3. IlluminatedCloud
  4. Issues

IJ hangs when I delete from source

Issue #1317 resolved
Alan Birchenough created an issue

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)

  1. Scott Wells repo owner

    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.

  2. Alan Birchenough 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.

  3. Scott Wells repo owner

    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.

  5. Alan Birchenough 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.

  6. Scott Wells 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.

  8. Scott Wells 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...

  9. Scott Wells 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.

  10. Scott Wells repo owner

    Okay, I have a prospective fix for this deadlock that will be in the next build (shooting for tomorrow morning).

  12. Scott Wells repo owner

    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.

  13. Log in to comment
Assignee
–
Type
bug
Priority
major
Status
resolved
Component
–
Version
2.0.6.3
Votes
0
Watchers
1
Jira: the preferred issue tracker for Bitbucket. Join the team!