Webstorm Freezing when refreshing metadata
In the retrieval dialog box it is freezing trying to populate the contents.
It’s happened a few times and I’m not getting much information out of the logs.
I’ll have to revert to using the sfdx command line for the time being.
Comments (26)
-
repo owner -
reporter - attached log_1.zip
-
reporter I’ve attached the logs. Seems to do it everytime I hit the little refresh button in the top left corner. Probably related to something specific about the org.
I’ll try adding back the original refresh always thing to see if it fixes it.
-
repo owner - attached IlluminatedCloud2.zip
Justin, can you install this build and see whether it resolves the issue for you or not? Please let me know either way. Thanks!
-
reporter Looks like that solved it thanks! Was it some sort of locking/contention issue?
-
repo owner Okay, good. Yeah, your provided thread dump was invaluable. What confuses me is why I've never seen it, and why I'm not hearing about it from every single user. Long story short, it has to do with some of the crazy threading states you can get into with a combination of the Swing event thread (EDT) and background threads displaying progress indicators. I just moved a critical section so that it's always guaranteed to run on the EDT before the progress indicator is displayed--it's not a time-consuming operation so it can happen beforehand--and that removed the potential deadlock.
Go ahead and sit on that build for now. I've already included that change in the branch for the next build which I plan to get out Thursday morning this week. Then you'll be good to update safely. Thanks again for providing the diagnostic info.
-
reporter that’s ok.
Look I had a DNS issue when I was running this - and so I wanted to cancel the request except when I clicked cancel it just hung but didn’t freeze - and I had to kill webstorm to resolve it. Any idea why that is? Do I have to wait longer? I would think a cancel should be almost immediate.
thanks
-
reporter arghh… so webstorm isn’t freezing but the process isn’t completing.
The process has stopped logging for the last 4 minutes now and just out put this:
2020-06-30 09:08:24,911 [ 338119] INFO - cloud.client.ForceComApiClient - Logging into Salesforce DX as 2jjulicher@fortherecord.com.cortexfull. 2020-06-30 09:08:24,911 [ 338119] INFO - cloud.client.ForceComApiClient - Retrieving org details from Salesforce CLI. 2020-06-30 09:08:24,911 [ 338119] INFO - cloud.client.ForceComApiClient - Logging into Salesforce DX as 2jjulicher@fortherecord.com.cortexfull. 2020-06-30 09:08:24,911 [ 338119] INFO - cloud.client.ForceComApiClient - Retrieving org details from Salesforce CLI. 2020-06-30 09:08:24,912 [ 338120] INFO - cloud.client.ForceComApiClient - Logging into Salesforce DX as 2jjulicher@fortherecord.com.cortexfull. 2020-06-30 09:08:24,912 [ 338120] INFO - cloud.client.ForceComApiClient - Retrieving org details from Salesforce CLI. 2020-06-30 09:08:24,912 [ 338120] INFO - cloud.client.ForceComApiClient - Logging into Salesforce DX as 2jjulicher@fortherecord.com.cortexfull. 2020-06-30 09:08:24,912 [ 338120] INFO - cloud.client.ForceComApiClient - Retrieving org details from Salesforce CLI. 2020-06-30 09:08:24,912 [ 338120] INFO - cloud.client.ForceComApiClient - Logging into Salesforce DX as 2jjulicher@fortherecord.com.cortexfull. 2020-06-30 09:08:24,912 [ 338120] INFO - cloud.client.ForceComApiClient - Retrieving org details from Salesforce CLI. 2020-06-30 09:08:24,912 [ 338120] INFO - cloud.client.ForceComApiClient - Logging into Salesforce DX as 2jjulicher@fortherecord.com.cortexfull. 2020-06-30 09:08:24,912 [ 338120] INFO - cloud.client.ForceComApiClient - Retrieving org details from Salesforce CLI. 2020-06-30 09:08:24,915 [ 338123] INFO - cloud.client.ForceComApiClient - Logging into Salesforce DX as 2jjulicher@fortherecord.com.cortexfull. 2020-06-30 09:08:24,915 [ 338123] INFO - cloud.client.ForceComApiClient - Retrieving org details from Salesforce CLI. 2020-06-30 09:08:24,917 [ 338125] INFO - cloud.client.ForceComApiClient - Logging into Salesforce DX as 2jjulicher@fortherecord.com.cortexfull. 2020-06-30 09:08:24,917 [ 338125] INFO - cloud.client.ForceComApiClient - Retrieving org details from Salesforce CLI. 2020-06-30 09:08:24,918 [ 338126] INFO - cloud.client.ForceComApiClient - Logging into Salesforce DX as 2jjulicher@fortherecord.com.cortexfull. 2020-06-30 09:08:24,918 [ 338126] INFO - cloud.client.ForceComApiClient - Retrieving org details from Salesforce CLI. 2020-06-30 09:08:24,920 [ 338128] INFO - cloud.client.ForceComApiClient - Logging into Salesforce DX as 2jjulicher@fortherecord.com.cortexfull. 2020-06-30 09:08:24,920 [ 338128] INFO - cloud.client.ForceComApiClient - Retrieving org details from Salesforce CLI. 2020-06-30 09:08:24,922 [ 338130] INFO - cloud.client.ForceComApiClient - Logging into Salesforce DX as 2jjulicher@fortherecord.com.cortexfull. 2020-06-30 09:08:24,922 [ 338130] INFO - cloud.client.ForceComApiClient - Retrieving org details from Salesforce CLI.
The last timestamp is now 5 minutes ago. Doesn’t seem like it’s going to finish the process now - and there is no thread dump.
-
repo owner Those are probably secondary threads in a spin lock against the main thread that's currently running the CLI. Sounds like the CLI is taking an exorbitant amount of time to run. If you're on Mac OS or Linux you might try
killall node
. If you're on Windows you might use Task Manager to find and kill thenode.exe
process.As for why cancel might not take effect immediately, basically you check for a user-requested cancellation after each step. In the case of an API request to the server via an HTTPS connection, the client is configured for a five minute timeout. Unfortunately that's a single config across all API requests and not tuned per-request. It's that high because some API requests can take quite a while to fulfill, especially against big orgs or even against moderate orgs but for large amounts of (meta)data. So basically you click Cancel and it tells the event system that the next time it transitions, it can cancel the overarching operation. Again, perhaps more than you wanted to know...
-
reporter Yeah I killed all the node instances and it didn’t release Webstorm so had to kill Webstorm too.
No it’s good to understand the process.
-
reporter Ok seems to be working good. however after updating and changing the context I got this:
2020-06-30 12:17:52,840 [6545314] WARN - .IlluminatedCloudExceptionUtil - java.lang.NullPointerException at com.illuminatedcloud.intellij.builder.BuildOptionsDialog$2.run(SourceFile:836) at com.intellij.openapi.progress.impl.CoreProgressManager$TaskRunnable.run(CoreProgressManager.java:932) at com.intellij.openapi.progress.impl.CoreProgressManager$4.run(CoreProgressManager.java:482) at com.intellij.openapi.progress.impl.ProgressRunner.lambda$new$0(ProgressRunner.java:77) at com.intellij.openapi.progress.impl.ProgressRunner.lambda$null$3(ProgressRunner.java:233) at com.intellij.openapi.progress.impl.CoreProgressManager.lambda$runProcess$2(CoreProgressManager.java:166) at com.intellij.openapi.progress.impl.CoreProgressManager.registerIndicatorAndRun(CoreProgressManager.java:627) at com.intellij.openapi.progress.impl.CoreProgressManager.executeProcessUnderProgress(CoreProgressManager.java:572) at com.intellij.openapi.progress.impl.ProgressManagerImpl.executeProcessUnderProgress(ProgressManagerImpl.java:61) at com.intellij.openapi.progress.impl.CoreProgressManager.runProcess(CoreProgressManager.java:153) at com.intellij.openapi.progress.impl.ProgressRunner.lambda$submit$4(ProgressRunner.java:233) at java.base/java.util.concurrent.CompletableFuture$AsyncSupply.run(CompletableFuture.java:1700) at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) at java.base/java.lang.Thread.run(Thread.java:834)
-
repo owner That says to me that it couldn't determine the IC config for that module. I just added some defensive handling of that, but in the end it would have resulted in an empty dialog for that context.
-
repo owner - attached IlluminatedCloud2.zip
Here's another build that's defensive around that NPE. I'm curious, though, why it's unable to get a builder for that module. As I mentioned, that would generally imply some type of project/module config issue.
-
reporter Thanks I’ll check it out.
I had another instance of Webstorm freezing (a good 15 minutes before I killed it) when just changing connections to one I actually just set up.
I think whatever you did on this build though has fixed it and it spat out this:
com.sforce.soap.metadata.MetadataApi 2020-07-01 11:23:20,064 [ 163323] WARN - onfigCache.FilePropertiesCache - Failed to list metadata as a batch. Will try again one at a time. javax.xml.ws.WebServiceException: org.apache.cxf.binding.soap.SoapFault: UNKNOWN_EXCEPTION: invalid parameter value at org.apache.cxf.jaxws.JaxWsClientProxy.mapException(JaxWsClientProxy.java:193) at org.apache.cxf.jaxws.JaxWsClientProxy.invoke(JaxWsClientProxy.java:145) at com.sun.proxy.$Proxy187.listMetadata(Unknown Source) at com.illuminatedcloud.intellij.configCache.FilePropertiesCache$2.lambda$process$0(SourceFile:255) at com.illuminatedcloud.client.ForceComApiClient.runWithClient(SourceFile:226) at com.illuminatedcloud.client.ForceComApiClient.runWithClient(SourceFile:341) at com.illuminatedcloud.intellij.configCache.FilePropertiesCache$2.process(SourceFile:250) at com.illuminatedcloud.intellij.configCache.FilePropertiesCache$2.process(SourceFile:229) at com.illuminatedcloud.util.ParallelBatchProcessorExecutor.lambda$execute$0(SourceFile:65) at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) at java.base/java.lang.Thread.run(Thread.java:834) Caused by: org.apache.cxf.binding.soap.SoapFault: UNKNOWN_EXCEPTION: invalid parameter value at org.apache.cxf.binding.soap.interceptor.Soap11FaultInInterceptor.unmarshalFault(Soap11FaultInInterceptor.java:87) at org.apache.cxf.binding.soap.interceptor.Soap11FaultInInterceptor.handleMessage(Soap11FaultInInterceptor.java:53) at org.apache.cxf.binding.soap.interceptor.Soap11FaultInInterceptor.handleMessage(Soap11FaultInInterceptor.java:42) at org.apache.cxf.phase.PhaseInterceptorChain.doIntercept(PhaseInterceptorChain.java:308) at org.apache.cxf.interceptor.AbstractFaultChainInitiatorObserver.onMessage(AbstractFaultChainInitiatorObserver.java:112) at org.apache.cxf.binding.soap.interceptor.CheckFaultInterceptor.handleMessage(CheckFaultInterceptor.java:70) at org.apache.cxf.binding.soap.interceptor.CheckFaultInterceptor.handleMessage(CheckFaultInterceptor.java:35) at org.apache.cxf.phase.PhaseInterceptorChain.doIntercept(PhaseInterceptorChain.java:308) at org.apache.cxf.endpoint.ClientImpl.onMessage(ClientImpl.java:826) at org.apache.cxf.transport.http.HTTPConduit$WrappedOutputStream.handleResponseInternal(HTTPConduit.java:1695) at org.apache.cxf.transport.http.HTTPConduit$WrappedOutputStream.handleResponse(HTTPConduit.java:1572) at org.apache.cxf.transport.http.HTTPConduit$WrappedOutputStream.close(HTTPConduit.java:1373) at org.apache.cxf.transport.AbstractConduit.close(AbstractConduit.java:56) at org.apache.cxf.transport.http.HTTPConduit.close(HTTPConduit.java:673) at org.apache.cxf.interceptor.MessageSenderInterceptor$MessageSenderEndingInterceptor.handleMessage(MessageSenderInterceptor.java:63) at org.apache.cxf.phase.PhaseInterceptorChain.doIntercept(PhaseInterceptorChain.java:308) at org.apache.cxf.endpoint.ClientImpl.doInvoke(ClientImpl.java:531) at org.apache.cxf.endpoint.ClientImpl.invoke(ClientImpl.java:440) at org.apache.cxf.endpoint.ClientImpl.invoke(ClientImpl.java:355) at org.apache.cxf.endpoint.ClientImpl.invoke(ClientImpl.java:313) at org.apache.cxf.frontend.ClientProxy.invokeSync(ClientProxy.java:96) at org.apache.cxf.jaxws.JaxWsClientProxy.invoke(JaxWsClientProxy.java:140) ... 11 more 2020-07-01 11:23:30,465 [ 173724] ERROR - onfigCache.FilePropertiesCache - Failed to list metadata for ManagedTopic: org.apache.cxf.binding.soap.SoapFault: UNKNOWN_EXCEPTION: invalid parameter value java.lang.Throwable: Failed to list metadata for ManagedTopic: org.apache.cxf.binding.soap.SoapFault: UNKNOWN_EXCEPTION: invalid parameter value at com.intellij.openapi.diagnostic.Logger.error(Logger.java:146) at com.illuminatedcloud.intellij.configCache.FilePropertiesCache$3.process(SourceFile:369) at com.illuminatedcloud.intellij.configCache.FilePropertiesCache$3.process(SourceFile:339) at com.illuminatedcloud.util.ParallelBatchProcessorExecutor.lambda$execute$0(SourceFile:65) at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) at java.base/java.lang.Thread.run(Thread.java:834)
Any ideas?
I don’t even have ManagedTopic as a subscribed metadata selection.
-
reporter From the documentation at:
https://developer.salesforce.com/docs/atlas.en-us.api_meta.meta/api_meta/meta_managedtopics.htm
The api says it should be folder name managedTopics - there isn’t a ManagedTopic api name.
-
repo owner I think I saw this with another user and it was because the source root was configured one level too high and it saw one of the project-level directories as matching that metadata type. How are your content roots and source roots configured for this project?
-
reporter it’s [project dir]/src/
and the source root is the src dir.
-
reporter Ok had another freeze while refreshing. Attached the new logs + threaddump.
Was using your latest build.
-
reporter - attached log.zip
Latest thread dump log.
-
reporter I don’t know what’s going on but it freezes everytime I refresh again. I reinstalled the last link you provided but it’s happening again.
-
repo owner - attached IlluminatedCloud2.zip
Okay, here's a slightly updated form of that change for you to try. The most recent provided thread dump was a bit confusing, but this does remove one thing that looked potentially problematic to me.
-
repo owner Oh, and as for that
ManagedTopic
question, is that just reflected in the log? Assuming so, it should be benign. Perhaps I just need to ratchet down the logging level when that occurs so that it doesn't end up in the log unless you're using debug logging. -
repo owner I've just posted 2.1.2.8 which includes all of the prospective fixes posted here so far. Once you update please let me know whether you continue to see the freeze or not. I'll leave this case open for a bit while you check it out.
-
reporter Yeah since that last updated I haven’t had this happen again. I just did 2 refreshes and both successfully completed!
thanks. I’m confident this can be resolved. I’ll re-open if I experience another freeze like this.
-
reporter - changed status to resolved
Bug fix successful
-
repo owner - changed component to Metadata Deployment/Retrieval/Removal
- Log in to comment
Ugh...and I know this is likely all on the latest builds. Do you mind attaching/emailing any thread dumps so I can see if there's a deadlock of some form?