UI Freeze - Anon Apex autocomplete

Issue #1997 resolved
Xander Victory created an issue

Editing in the Anon Apex tool window for a non project connection (anon set to prod, project is sandbox), I got a UI freeze and the log line 2021-10-26 17:25:07,402 [29371188] WARN - .diagnostic.PerformanceWatcher - UI was frozen for 6716ms, details saved to C:\Users\lex\AppData\Local\JetBrains\IntelliJIdea2021.2\log\threadDumps-freeze-20211026-172505-IU-212.5457.46-6sec

Is there a way for it to avoid calling SFDX for this use case?

"AWT-EventQueue-0" prio=0 tid=0x0 nid=0x0 waiting on condition
     java.lang.Thread.State: TIMED_WAITING

    at java.base@11.0.12/java.lang.Thread.sleep(Native Method)
    at com.illuminatedcloud.util.CommandLineUtil.runCommandLine(SourceFile:133)
    at com.illuminatedcloud.intellij.sfdx.SfdxUtil.runSalesforceCliCommand(SourceFile:258)
    at com.illuminatedcloud.intellij.sfdx.SfdxUtil.runSalesforceCliCommand(SourceFile:406)
    at com.illuminatedcloud.intellij.sfdx.SfdxUtil.runSalesforceCliCommand(SourceFile:372)
    at com.illuminatedcloud.intellij.sfdx.SfdxUtil.runSfdx(SourceFile:352)
    at com.illuminatedcloud.intellij.sfdx.SfdxUtil.runSfdx(SourceFile:306)
    at com.illuminatedcloud.intellij.sfdx.SfdxUtil.runSfdxForceOrgList(SourceFile:652)
    at com.illuminatedcloud.intellij.settings.application.IlluminatedCloudConnectionConfig.doGetSfdxConnectionConfigs(SourceFile:938)
    at com.illuminatedcloud.intellij.settings.application.IlluminatedCloudConnectionConfig.access$500(SourceFile:71)
    at com.illuminatedcloud.intellij.settings.application.IlluminatedCloudConnectionConfig$1.run(SourceFile:891)
    at com.intellij.openapi.progress.impl.CoreProgressManager.startTask(CoreProgressManager.java:450)
    at com.intellij.openapi.progress.impl.ProgressManagerImpl.startTask(ProgressManagerImpl.java:117)
    at com.intellij.openapi.progress.impl.CoreProgressManager.lambda$runProcessWithProgressSynchronously$8(CoreProgressManager.java:556)
    at com.intellij.openapi.progress.impl.CoreProgressManager$$Lambda$5300/0x0000000803207040.run(Unknown Source)
    at com.intellij.openapi.progress.impl.CoreProgressManager.lambda$runProcess$2(CoreProgressManager.java:183)
    at com.intellij.openapi.progress.impl.CoreProgressManager$$Lambda$376/0x0000000800529040.run(Unknown Source)
    at com.intellij.openapi.progress.impl.CoreProgressManager.registerIndicatorAndRun(CoreProgressManager.java:705)
    at com.intellij.openapi.progress.impl.CoreProgressManager.executeProcessUnderProgress(CoreProgressManager.java:647)
    at com.intellij.openapi.progress.impl.ProgressManagerImpl.executeProcessUnderProgress(ProgressManagerImpl.java:63)
    at com.intellij.openapi.progress.impl.CoreProgressManager.runProcess(CoreProgressManager.java:170)
    at com.intellij.openapi.application.impl.ApplicationImpl.runProcessWithProgressSynchronously(ApplicationImpl.java:407)
    at com.intellij.openapi.progress.impl.CoreProgressManager.runProcessWithProgressSynchronously(CoreProgressManager.java:567)
    at com.intellij.openapi.progress.impl.ProgressManagerImpl.runProcessWithProgressSynchronously(ProgressManagerImpl.java:88)
    at com.intellij.openapi.progress.impl.CoreProgressManager.run(CoreProgressManager.java:398)
    at com.illuminatedcloud.intellij.settings.application.IlluminatedCloudConnectionConfig.lambda$runSfdxForceOrgList$1(SourceFile:882)
    at com.illuminatedcloud.intellij.settings.application.IlluminatedCloudConnectionConfig$$Lambda$5310/0x0000000803210440.compute(Unknown Source)
    at com.intellij.openapi.util.RecursionGuard$$Lambda$443/0x000000080065e040.compute(Unknown Source)
    at com.intellij.openapi.util.RecursionManager$1.computePreventingRecursion(RecursionManager.java:114)
    at com.intellij.openapi.util.RecursionGuard.doPreventingRecursion(RecursionGuard.java:43)
    at com.intellij.openapi.util.RecursionManager.doPreventingRecursion(RecursionManager.java:68)
    at com.illuminatedcloud.intellij.settings.application.IlluminatedCloudConnectionConfig.runSfdxForceOrgList(SourceFile:858)
    at com.illuminatedcloud.intellij.settings.application.IlluminatedCloudConnectionConfig.getSfdxConnectionConfigs(SourceFile:796)
    at com.illuminatedcloud.intellij.settings.application.IlluminatedCloudConnectionConfig.getConnectionConfigs(SourceFile:671)
    at com.illuminatedcloud.intellij.settings.application.IlluminatedCloudConnectionConfig.getConnectionConfigs(SourceFile:625)
    at com.illuminatedcloud.intellij.settings.application.IlluminatedCloudConnectionConfig.getConnection(SourceFile:995)
    at com.illuminatedcloud.intellij.sdktype.IlluminatedCloudSdkType.getSdk(SourceFile:114)
    at com.illuminatedcloud.intellij.index.IlluminatedCloudIndexUtil.isSdkFile(SourceFile:188)
    at com.illuminatedcloud.intellij.index.IlluminatedCloudIndexUtil.isSourceFile(SourceFile:94)
    at com.illuminatedcloud.symtab.ApexSystemNamespace.isOrganizationNamespace(SourceFile:164)
    at com.illuminatedcloud.symtab.ApexSystemNamespace.isImplicitNamespace(SourceFile:193)
    at com.illuminatedcloud.intellij.psi.util.VisibleDeclarationCollector.accept(SourceFile:114)
    at com.illuminatedcloud.intellij.psi.util.VisibleDeclarationCollector.collect(SourceFile:233)
    at com.illuminatedcloud.intellij.psi.util.VisibleDeclarationCollector.collect(SourceFile:226)
    at com.illuminatedcloud.intellij.psi.impl.ApexNamespace.collectVisibleDeclarations(SourceFile:104)
    at com.illuminatedcloud.intellij.psi.util.VisibleDeclarationCollector.collectVisibleDeclarations(SourceFile:217)
    at com.illuminatedcloud.intellij.filetype.ApexClassFile.collectVisibleDeclarations(SourceFile:203)
    at com.illuminatedcloud.intellij.psi.util.VisibleDeclarationCollector.collectVisibleDeclarations(SourceFile:217)
    at com.illuminatedcloud.intellij.psi.util.VisibleDeclarationCollector.collectVisibleDeclarations(SourceFile:155)
    at com.illuminatedcloud.intellij.livetemplate.ApexIterableVariableMacro.getIterables(SourceFile:155)
    at com.illuminatedcloud.intellij.livetemplate.ApexIterableVariableMacro.calculateResult(SourceFile:75)
    at com.intellij.codeInsight.template.impl.MacroCallNode.calculateResult(MacroCallNode.java:34)
    at com.intellij.codeInsight.template.impl.TemplateState.recalcSegment(TemplateState.java:720)
    at com.intellij.codeInsight.template.impl.TemplateState.lambda$calcResults$5(TemplateState.java:606)
    at com.intellij.codeInsight.template.impl.TemplateState$$Lambda$9598/0x0000000802f23c40.run(Unknown Source)
    at com.intellij.openapi.project.DumbService.withAlternativeResolveEnabled(DumbService.java:346)
    at com.intellij.codeInsight.template.impl.TemplateState.lambda$calcResults$6(TemplateState.java:605)
    at com.intellij.codeInsight.template.impl.TemplateState$$Lambda$9596/0x0000000802f25440.run(Unknown Source)
    at com.intellij.openapi.command.WriteCommandAction.lambda$runWriteCommandAction$4(WriteCommandAction.java:348)
    at com.intellij.openapi.command.WriteCommandAction$$Lambda$9597/0x0000000802f23840.run(Unknown Source)
    at com.intellij.openapi.command.WriteCommandAction$BuilderImpl.lambda$doRunWriteCommandAction$1(WriteCommandAction.java:143)
    at com.intellij.openapi.command.WriteCommandAction$BuilderImpl$$Lambda$9592/0x0000000801bfb040.run(Unknown Source)
    at com.intellij.openapi.application.impl.ApplicationImpl.runWriteAction(ApplicationImpl.java:936)
    at com.intellij.openapi.command.WriteCommandAction$BuilderImpl.lambda$doRunWriteCommandAction$2(WriteCommandAction.java:141)
    at com.intellij.openapi.command.WriteCommandAction$BuilderImpl$$Lambda$9591/0x0000000801bfcc40.run(Unknown Source)
    at com.intellij.openapi.command.impl.CoreCommandProcessor.executeCommand(CoreCommandProcessor.java:207)
    at com.intellij.openapi.command.impl.CoreCommandProcessor.executeCommand(CoreCommandProcessor.java:182)
    at com.intellij.openapi.command.WriteCommandAction$BuilderImpl.doRunWriteCommandAction(WriteCommandAction.java:150)
    at com.intellij.openapi.command.WriteCommandAction$BuilderImpl.run(WriteCommandAction.java:117)
    at com.intellij.openapi.command.WriteCommandAction.runWriteCommandAction(WriteCommandAction.java:348)
    at com.intellij.codeInsight.template.impl.TemplateState.calcResults(TemplateState.java:588)
    at com.intellij.codeInsight.template.impl.TemplateState.lambda$processAllExpressions$1(TemplateState.java:354)
    at com.intellij.codeInsight.template.impl.TemplateState$$Lambda$9595/0x0000000801beac40.run(Unknown Source)
    at com.intellij.openapi.application.impl.ApplicationImpl.runWriteAction(ApplicationImpl.java:936)
    at com.intellij.codeInsight.template.impl.TemplateState.processAllExpressions(TemplateState.java:346)
    at com.intellij.codeInsight.template.impl.TemplateState.start(TemplateState.java:331)
    at com.intellij.codeInsight.template.impl.TemplateState.start(TemplateState.java:295)
    at com.intellij.codeInsight.template.impl.TemplateManagerImpl.lambda$startTemplate$2(TemplateManagerImpl.java:169)
    at com.intellij.codeInsight.template.impl.TemplateManagerImpl$$Lambda$9593/0x0000000801a23c40.run(Unknown Source)
    at com.intellij.openapi.command.impl.CoreCommandProcessor.executeCommand(CoreCommandProcessor.java:207)
    at com.intellij.openapi.command.impl.CoreCommandProcessor.executeCommand(CoreCommandProcessor.java:172)
    at com.intellij.openapi.command.impl.CoreCommandProcessor.executeCommand(CoreCommandProcessor.java:162)
    at com.intellij.openapi.command.impl.CoreCommandProcessor.executeCommand(CoreCommandProcessor.java:148)
    at com.intellij.codeInsight.template.impl.TemplateManagerImpl.startTemplate(TemplateManagerImpl.java:172)
    at com.intellij.codeInsight.template.impl.TemplateManagerImpl.startTemplate(TemplateManagerImpl.java:190)
    at com.intellij.codeInsight.template.impl.TemplateManagerImpl.startTemplate(TemplateManagerImpl.java:129)
    at com.intellij.codeInsight.template.impl.LiveTemplateLookupElementImpl.startTemplate(LiveTemplateLookupElementImpl.java:44)
    at com.intellij.codeInsight.template.impl.LiveTemplateLookupElementImpl.handleInsert(LiveTemplateLookupElementImpl.java:38)
    at com.intellij.codeInsight.completion.CodeCompletionHandlerBase.lambda$insertItem$15(CodeCompletionHandlerBase.java:690)
    at com.intellij.codeInsight.completion.CodeCompletionHandlerBase$$Lambda$6102/0x000000080377c840.run(Unknown Source)
    at com.intellij.util.indexing.FileBasedIndex.lambda$ignoreDumbMode$0(FileBasedIndex.java:163)
    at com.intellij.util.indexing.FileBasedIndex$$Lambda$3633/0x000000080227e440.compute(Unknown Source)
    at com.intellij.openapi.util.RecursionManager$1.computePreventingRecursion(RecursionManager.java:114)
    at com.intellij.util.indexing.FileBasedIndexEx.ignoreDumbMode(FileBasedIndexEx.java:588)
    at com.intellij.util.indexing.FileBasedIndex.ignoreDumbMode(FileBasedIndex.java:162)
    at com.intellij.util.indexing.DumbModeAccessType.ignoreDumbMode(DumbModeAccessType.java:43)
    at com.intellij.codeInsight.completion.CodeCompletionHandlerBase.lambda$insertItem$16(CodeCompletionHandlerBase.java:689)
    at com.intellij.codeInsight.completion.CodeCompletionHandlerBase$$Lambda$6101/0x000000080377b840.run(Unknown Source)
    at com.intellij.openapi.application.impl.ApplicationImpl.runWriteAction(ApplicationImpl.java:936)
    at com.intellij.codeInsight.completion.CodeCompletionHandlerBase.insertItem(CodeCompletionHandlerBase.java:673)
    at com.intellij.codeInsight.completion.CodeCompletionHandlerBase.lambda$doInsertItem$12(CodeCompletionHandlerBase.java:598)
    at com.intellij.codeInsight.completion.CodeCompletionHandlerBase$$Lambda$6100/0x000000080377a440.perform(Unknown Source)
    at com.intellij.openapi.editor.impl.CaretModelImpl.lambda$runForEachCaret$3(CaretModelImpl.java:312)
    at com.intellij.openapi.editor.impl.CaretModelImpl$$Lambda$5668/0x00000008035c3440.run(Unknown Source)
    at com.intellij.openapi.editor.impl.CaretModelImpl.doWithCaretMerging(CaretModelImpl.java:421)
    at com.intellij.openapi.editor.impl.CaretModelImpl.runForEachCaret(CaretModelImpl.java:321)
    at com.intellij.openapi.editor.impl.CaretModelImpl.runForEachCaret(CaretModelImpl.java:296)
    at com.intellij.codeInsight.completion.CodeCompletionHandlerBase.doInsertItem(CodeCompletionHandlerBase.java:588)
    at com.intellij.codeInsight.completion.CodeCompletionHandlerBase.insertItemHonorBlockSelection(CodeCompletionHandlerBase.java:548)
    at com.intellij.codeInsight.completion.CodeCompletionHandlerBase.lookupItemSelected(CodeCompletionHandlerBase.java:494)
    at com.intellij.codeInsight.completion.CompletionProgressIndicator.itemSelected(CompletionProgressIndicator.java:180)
    at com.intellij.codeInsight.completion.BaseCompletionLookupArranger.itemSelected(BaseCompletionLookupArranger.java:227)
    at com.intellij.codeInsight.lookup.impl.LookupImpl.fireItemSelected(LookupImpl.java:926)
    at com.intellij.codeInsight.lookup.impl.LookupImpl.finishLookupInWritableFile(LookupImpl.java:580)
    at com.intellij.codeInsight.lookup.impl.LookupImpl.lambda$finishLookup$5(LookupImpl.java:538)
    at com.intellij.codeInsight.lookup.impl.LookupImpl$$Lambda$6096/0x0000000803779040.run(Unknown Source)
    at com.intellij.openapi.command.impl.CoreCommandProcessor.executeCommand(CoreCommandProcessor.java:207)
    at com.intellij.openapi.command.impl.CoreCommandProcessor.executeCommand(CoreCommandProcessor.java:172)
    at com.intellij.openapi.command.impl.CoreCommandProcessor.executeCommand(CoreCommandProcessor.java:162)
    at com.intellij.openapi.command.impl.CoreCommandProcessor.executeCommand(CoreCommandProcessor.java:148)
    at com.intellij.codeInsight.lookup.impl.LookupImpl.finishLookup(LookupImpl.java:538)
    at com.intellij.codeInsight.lookup.impl.LookupImpl.finishLookup(LookupImpl.java:523)
    at com.intellij.codeInsight.lookup.impl.actions.ChooseItemAction$Handler.lambda$doExecute$0(ChooseItemAction.java:72)
    at com.intellij.codeInsight.lookup.impl.actions.ChooseItemAction$Handler$$Lambda$6095/0x0000000803778c40.run(Unknown Source)
    at com.intellij.util.SlowOperations.allowSlowOperations(SlowOperations.java:152)
    at com.intellij.codeInsight.lookup.impl.actions.ChooseItemAction$Handler.doExecute(ChooseItemAction.java:72)
    at com.intellij.openapi.editor.actionSystem.DynamicEditorActionHandler.doExecute(DynamicEditorActionHandler.java:60)
    at com.intellij.openapi.editor.actionSystem.EditorActionHandler.lambda$execute$4(EditorActionHandler.java:199)
    at com.intellij.openapi.editor.actionSystem.EditorActionHandler$$Lambda$6061/0x000000080373a440.perform(Unknown Source)
    at com.intellij.openapi.editor.actionSystem.EditorActionHandler.doIfEnabled(EditorActionHandler.java:89)
    at com.intellij.openapi.editor.actionSystem.EditorActionHandler.execute(EditorActionHandler.java:198)
    at com.intellij.openapi.editor.actionSystem.EditorAction.lambda$actionPerformed$0(EditorAction.java:89)
    at com.intellij.openapi.editor.actionSystem.EditorAction$$Lambda$5669/0x00000008035c3840.run(Unknown Source)
    at com.intellij.openapi.command.impl.CoreCommandProcessor.executeCommand(CoreCommandProcessor.java:216)
    at com.intellij.openapi.command.impl.CoreCommandProcessor.executeCommand(CoreCommandProcessor.java:172)
    at com.intellij.openapi.editor.actionSystem.EditorAction.actionPerformed(EditorAction.java:98)
    at com.intellij.openapi.editor.actionSystem.EditorAction.actionPerformed(EditorAction.java:73)
    at com.intellij.openapi.keymap.impl.ActionProcessor.performAction(ActionProcessor.java:65)
    at com.intellij.openapi.keymap.impl.IdeKeyEventDispatcher$1.performAction(IdeKeyEventDispatcher.java:563)
    at com.intellij.openapi.keymap.impl.IdeKeyEventDispatcher.lambda$doPerformActionInner$8(IdeKeyEventDispatcher.java:677)
    at com.intellij.openapi.keymap.impl.IdeKeyEventDispatcher$$Lambda$5575/0x0000000803510c40.run(Unknown Source)
    at com.intellij.openapi.actionSystem.ex.ActionUtil.performDumbAwareWithCallbacks(ActionUtil.java:261)
    at com.intellij.openapi.keymap.impl.IdeKeyEventDispatcher.doPerformActionInner(IdeKeyEventDispatcher.java:670)
    at com.intellij.openapi.keymap.impl.IdeKeyEventDispatcher.processAction(IdeKeyEventDispatcher.java:603)
    at com.intellij.openapi.keymap.impl.IdeKeyEventDispatcher.processAction(IdeKeyEventDispatcher.java:574)
    at com.intellij.openapi.keymap.impl.IdeKeyEventDispatcher.processActionOrWaitSecondStroke(IdeKeyEventDispatcher.java:457)
    at com.intellij.openapi.keymap.impl.IdeKeyEventDispatcher.inInitState(IdeKeyEventDispatcher.java:450)
    at com.intellij.openapi.keymap.impl.IdeKeyEventDispatcher.dispatchKeyEvent(IdeKeyEventDispatcher.java:218)
    at com.intellij.ide.IdeEventQueue.dispatchKeyEvent(IdeEventQueue.java:798)
    at com.intellij.ide.IdeEventQueue._dispatchEvent(IdeEventQueue.java:748)
    at com.intellij.ide.IdeEventQueue.lambda$dispatchEvent$6(IdeEventQueue.java:441)
    at com.intellij.ide.IdeEventQueue$$Lambda$459/0x000000080069e440.compute(Unknown Source)
    at com.intellij.openapi.progress.impl.CoreProgressManager.computePrioritized(CoreProgressManager.java:825)
    at com.intellij.ide.IdeEventQueue.lambda$dispatchEvent$7(IdeEventQueue.java:440)
    at com.intellij.ide.IdeEventQueue$$Lambda$455/0x0000000800658840.run(Unknown Source)
    at com.intellij.openapi.application.impl.ApplicationImpl.runIntendedWriteActionOnCurrentThread(ApplicationImpl.java:794)
    at com.intellij.ide.IdeEventQueue.dispatchEvent(IdeEventQueue.java:492)
    at java.desktop@11.0.12/java.awt.EventDispatchThread.pumpOneEventForFilters(EventDispatchThread.java:203)
    at java.desktop@11.0.12/java.awt.EventDispatchThread.pumpEventsForFilter(EventDispatchThread.java:124)
    at java.desktop@11.0.12/java.awt.EventDispatchThread.pumpEventsForHierarchy(EventDispatchThread.java:113)
    at java.desktop@11.0.12/java.awt.EventDispatchThread.pumpEvents(EventDispatchThread.java:109)
    at java.desktop@11.0.12/java.awt.EventDispatchThread.pumpEvents(EventDispatchThread.java:101)
    at java.desktop@11.0.12/java.awt.EventDispatchThread.run(EventDispatchThread.java:90)

Comments (21)

  1. Scott Wells repo owner

    IC uses the CLI to get up-to-date details about the CLI-configured connections as a list (force:org:list) and also individually (force:org:display) as needed. It caches that information quite aggressively, and when it detects that the information is stale, it uses the most efficient invocation of the CLI to update it (sfdx force:org:list --skipconnectionstatus). Having said that, you can configure IC's behavior when it detects that the cached information is stale in Illuminated Cloud>Configure Application>Salesforce DX using the When the cached connection list/details appear(s) stale options. By default those are set to Refresh, but if you don't want that to happen, you can change them to Notify or even Do nothing in which case it will be up to you to refresh the cached connection info in the connection manager.

    If force:org:list is taking a while to run, I'd recommend that you use the Remove Stale Salesforce CLI Connections toolbar action (trashcan icon) in the connection manager, or if you'd prefer, you can just run sfdx force:org:list --clean from the command-line yourself. If it's still taking a while to run, see whether you have any OAuth connections with expired tokens that you don't need anymore and log out of those as well.

    Hope that helps.

  2. Xander Victory reporter

    Thanks, didn’t know about those options! Have changed to Notify for now, since even sfdx force:org:list --skipconnectionstatus takes about 3-4 seconds for some odd reason (I’ll try a purge and reinstall of sfdx later to get rid of potential npm issues)

    Perhaps there are some false positives in the change detection? (e.g. sfdx updating the stored token) - this actually happened twice in the space of about a minute, where nothing else used sfdx, both in anon apex

  3. Scott Wells repo owner

    IC2 determines that the cache is stale using a two-pass check. The first pass looks to see if any of the relevant files under the ~/.sfdx directory have last modified timestamps more recent than the cache population timestamp. If so, it then computes checksums for those files and compares those to the stored checksums. And of course if the set of relevant files has changed, that will also result in a cache eviction/read-through. That's been a very efficient way to avoid false positives for the most part. So it sounds to me like the CLI is changing files in that directory and then changing others (and/or perhaps the same ones?) again shortly thereafter. I've seen that happen in the past myself, though rarely.

    By "relevant files", I mean that it looks at all files with a .json file extension that represent connection configuration information, effectively alias.json and the various username@hostname.json files. It ignores other files that can change more often, or which don't contain anything interesting about the connection information.

    So I guess the next time you see this happen, it might be worth running ls -ltr ~/.sfdx and seeing which files are listed last.

    Oh, and if you want, you can enable trace-level logging which will show cache health checks and eviction strategy. Be warned, though, that it can lead to quite noisy logs. Just add the following for debug logging:

    #com.illuminatedcloud.intellij.sfdx.SfdxUtil!trace
    

    I'll be curious to hear what you find.

  4. Xander Victory reporter

    Does the checksum exclude fields such as the accessToken/refreshToken?

    Literally all my active org json username@host files just got updated by running sfdx force:org:list (i.e. where it does a login)

    Hmm, seems the field instanceApiVersionLastRetrieved got changed in one that I had open in Notepad++ before and after the listing, unsure about the tokens.

    sfdx-cli/7.94.3-a4e7c7955b win32-x64 node-v14.15.4

  5. Scott Wells repo owner

    Yes, for the files included in the evaluation, the checksum is based on the entire file. The access token is critical for IC2 to be able to access the org. The refresh token is really an internal detail, but it's also something that shouldn't change often...certainly not more frequently than the access token, and generally less frequently.

    By default IC2 uses force:org:list --skipconnectionstatus which does not perform any logins. As noted previously, you can configure it to omit that option if When the cached connection list appears stale is set to Force Refresh, and it will also omit that option if you click the Force Refresh toolbar button in the connection manager. Otherwise there should be no logins as a result of IC2 automatically running that command.

    I would expect instanceApiVersion/LastRetrieved to be updated exactly once per-connection on first access after each seasonal platform release, so that frequency should also be very low.

  6. Xander Victory reporter

    Running the refresh commands from the event log appears to have confused the checking. No manual sfdx commands were issued, yet it is marking one as being modified.

    2021-10-28 08:22:35,021 [  51692]   INFO - luminatedCloudConnectionConfig - Retrieving org list information from Salesforce CLI. 
    2021-10-28 08:22:35,021 [  51692]  DEBUG - atedcloud.util.CommandLineUtil - Running command line: 'C:/Program Files/Salesforce CLI/bin/sfdx.cmd force:org:list --skipconnectionstatus --json' from working directory: 'C:\Users\lex\git-trausteknik\BlackandWhiteWaiters'. 
    2021-10-28 08:22:35,024 [  51695]  DEBUG - .VariableLengthPollingInterval - C:/Program Files/Salesforce CLI/bin/sfdx.cmd force:org:list --skipconnectionstatus --json: Using polling interval 1000 ms for polling iteration 1. 
    2021-10-28 08:22:36,024 [  52695]  DEBUG - .VariableLengthPollingInterval - C:/Program Files/Salesforce CLI/bin/sfdx.cmd force:org:list --skipconnectionstatus --json: Using polling interval 1000 ms for polling iteration 2. 
    2021-10-28 08:22:37,027 [  53698]  DEBUG - .VariableLengthPollingInterval - C:/Program Files/Salesforce CLI/bin/sfdx.cmd force:org:list --skipconnectionstatus --json: Using polling interval 1000 ms for polling iteration 3. 
    2021-10-28 08:22:38,038 [  54709]  DEBUG - .VariableLengthPollingInterval - C:/Program Files/Salesforce CLI/bin/sfdx.cmd force:org:list --skipconnectionstatus --json: Using polling interval 1000 ms for polling iteration 4. 
    2021-10-28 08:22:39,040 [  55711]  DEBUG - atedcloud.util.CommandLineUtil - Returning command-line response: CommandLineResponse{exitCode=0, output='{  "status": 0,  "result": <redacted>    ],    "scratchOrgs": []  },  "warnings": [    "Starting in API version 52, the JSON output of this command no longer returns the property connectedStatus for scratch orgs."  ]}', error='', duration=4019} 
    2021-10-28 08:22:39,050 [  55721]   WARN - ctionSystem.impl.ActionUpdater - Slow (7897 ms) `com.illuminatedcloud.intellij.builder.FullBuildAction#update`. Consider speeding it up and/or implementing UpdateInBackground. 
    2021-10-28 08:22:39,051 [  55722]   WARN - ctionSystem.impl.ActionUpdater - 7901 ms to expand group child IlluminatedCloud.FullBuild 
    2021-10-28 08:22:39,058 [  55729]   WARN - .diagnostic.PerformanceWatcher - UI was frozen for 7901ms, details saved to C:\Users\lex\AppData\Local\JetBrains\IntelliJIdea2021.2\log\threadDumps-freeze-20211028-082236-IU-212.5457.46-7sec 
    2021-10-28 08:22:39,064 [  55735]   WARN - ctionSystem.impl.ActionUpdater - 7915 ms to expand group child null 
    2021-10-28 08:22:45,195 [  61866]  DEBUG - d.intellij.sfdx.SfdxUtil!trace - Checking the last modified timestamps of 23 SFDX config files. 
    2021-10-28 08:22:45,196 [  61867]  DEBUG - d.intellij.sfdx.SfdxUtil!trace - The following files have been modified since Thu Oct 28 08:22:39 AWST 2021: { blackandwhitewaiters.support@trausteknik.com.dev.json }. Comparing checksums. 
    2021-10-28 08:22:45,196 [  61867]  DEBUG - d.intellij.sfdx.SfdxUtil!trace - Different checksum found for blackandwhitewaiters.support@trausteknik.com.dev.json: expected 499330281, actual 3896732425. 
    2021-10-28 08:22:45,196 [  61867]  DEBUG - d.intellij.sfdx.SfdxUtil!trace - The following modified files had different checksums: { blackandwhitewaiters.support@trausteknik.com.dev.json }. 
    

    BlackAndWhiteDev specific refresh option was clicked, then the connection list. The 3rd event is unactioned.

    28/10/2021
    8:22 am Illuminated Cloud
                    The Salesforce CLI connection list appears to be stale.
                    Refresh
                    Force refresh
                    Remind me later
                    Configure...
    
    8:22 am Illuminated Cloud
                    The Salesforce CLI connection 'BlackAndWhiteDev' appears to be stale.
                    Refresh
                    Remind me later
                    Configure...
    
    8:22 am Illuminated Cloud
                    The Salesforce CLI connection list appears to be stale.
                    Refresh
                    Force refresh
                    Remind me later
                    Configure...
    

  7. Xander Victory reporter

    Related tangent: some of my sfdx command slowness appears to be due to having the lwc-dev-server plugin enabled. Taking it out lets sfdx --help execute a bit faster

  8. Scott Wells repo owner

    Xander, I'm not sure if I'm following the sequence of events. Based on the log something has modified that file. Both the timestamp and the checksum have changed. IC2 treats those files as read-only. Note that the CLI can update these files based on even a force:org:list or force:org:display as a side-effect. Or am I misunderstanding what's being reported here? That's always a distinct possibility...

  9. Xander Victory reporter

    During that log snippet, only IC2/IDEA actions were performed. Let me know if I need to tweak any debug log settings.

    Sequence of events

    1. Refresh command link under BlackAndWhiteDev action center item

      1. This appears to have triggered it to see things as changed, with the timestamp pointing to this action’s refresh as last known update
    2. Refresh command link under ‘The Salesforce CLI connection list appears to be stale.’

      1. again triggering a notice that things are stale
    3. Maybe opening the Retrieve Metadata dialog (but no retrieve)

    4. Copy/paste log

  10. Xander Victory reporter

    I say Maybe under number 3, because I can’t recall if I opened it before or during this sequence (or both).

  11. Scott Wells repo owner

    Pretty much anytime that IC2 needs connection info--either details for a specific connection or the list of connections--it checks whether its caches are stale. That can happen in situations you might not assume would need that information, e.g., just opening the Deploy/Retrieve/Delete dialogs.

    Regarding your posted sequence of events, you've reconfigured things to notify only now, correct? So in step 1 it realized that things were stale and notified you, and it did so again in step 2. If that's the case, did you click Remind me later after the first one? If not, it'll notify again immediately the next time it does anything that checks the cache. If you did, it shouldn't notify you again of that particular stale cache (list vs. display) for 30 minutes.

    If, on the other hand, it was configured to refresh or force refresh, after step 1 it should have updated the cache contents, and I wouldn't expect step 2 to find the same cache to be stale. I could see a situation in which it might find the force:org:list cache stale first and then find the force:org:display cache stale, but if you're seeing it finding the same cache stale immediately after it has been updated, that's definitely unexpected.

  12. Xander Victory reporter

    My dot points are actions I took using the event log items. i.e. it was told to refresh (because it’s set to notify), but immediately after refreshing it complained things were stale again (i.e. I got a third popup in the UI which was not actioned)

  13. Scott Wells repo owner

    I'm sorry for being dense, Xander, but I guess I'm not quite connecting the dots here (pun intended for levity). At this point I'm not sure how you have things configured with regard to these stale cache behaviors. Just so I properly understand, can you please clearly re-state how those two cache options are configured and then the exact sequence of steps you've taken with the expected and actual behavior after each? Again, my apologies for asking you to do this, but I think I just got lost somewhere along the way...

  14. Scott Wells repo owner

    Gotcha. Thanks. So I'd like to see a log of the span of time from when you clicked Refresh to when it next showed things as being stale with that same level of debug logging enabled so I can see which file(s) are out-of-date the second time.

  15. Scott Wells repo owner

    Thanks. Hopefully I can reproduce this behavior locally and figure out why it's not seeing the cache as whole immediately after it updates from the CLI.

  16. Scott Wells repo owner

    Everything around CLI connection caching has changed since this was logged. Resolving, but if it's still happening, please reopen and we'll get new diagnostic info.

  17. Log in to comment