Refreshing of metadata takes >20 mins to complete
Issue
Refreshing of metadata (single file or a folder from left pane) takes 5-20 mins to complete. A few more details:
- This only happens with one sandbox (CS102)
- First observed: 22nd Oct
Steps to reproduce
- Open a Salesforce project in Intellij
- Open any file (cmd+shift+O)
- Refresh that file (cmd+shift+opt+R)
- Status on the bottom says “Pending“ and the refresh completes in 5-20 mins
Attempts to resolve
- Deleted and re-created the project - No impact
- Removed and re-added the connection - No impact
Impact
Huge blocker for us as it makes development very slow and frustrating. Since we are in the middle of development cycle, almost impossible to move to another sandbox. Also, very difficult to refresh this sandbox (in an anticipation that the new instance will not be CS102)
Comments (7)
-
repo owner -
Account Deactivated reporter Hey @scott wells , thanks for your quick response. I added the
Metadata Retrieval Debug Logging
and refreshed a single class. Attached are the logs (in the original ticket, as I could not upload that in this comment)I find it quite interesting that OneDrive could be a trouble maker for us. I have all my projects in OneDrive and have been like this for over 2 years and this is the first time, I am witnessing such long times for the retrieval.
-
Account Deactivated reporter - attached idea_debug.log
-
repo owner Thanks for the log. It confirms that all of the time is spent waiting for Salesforce to process the retrieval request:
2020-10-26 15:21:36,621 [262615301] DEBUG - lder.ForceComMetadataRetriever - Submitted retrieve request with async process ID 09S1j0000015BilEAE 2020-10-26 15:21:36,621 [262615301] DEBUG - lder.ForceComMetadataRetriever - Polling the status of the retrieve request. 2020-10-26 15:21:36,815 [262615495] DEBUG - lder.ForceComMetadataRetriever - Status: Pending 2020-10-26 15:21:36,815 [262615495] DEBUG - lder.ForceComMetadataRetriever - Retrieve request is still processing. 2020-10-26 15:21:36,815 [262615495] DEBUG - .VariableLengthPollingInterval - AbstractForceComMetadataRetriever.retrieve: Using polling interval 1000 ms for polling iteration 1. 2020-10-26 15:21:37,821 [262616501] DEBUG - lder.ForceComMetadataRetriever - Polling the status of the retrieve request. 2020-10-26 15:21:37,904 [262616584] DEBUG - lder.ForceComMetadataRetriever - Status: Pending 2020-10-26 15:21:37,904 [262616584] DEBUG - lder.ForceComMetadataRetriever - Retrieve request is still processing. 2020-10-26 15:21:37,904 [262616584] DEBUG - .VariableLengthPollingInterval - AbstractForceComMetadataRetriever.retrieve: Using polling interval 1000 ms for polling iteration 2. 2020-10-26 15:21:38,904 [262617584] DEBUG - lder.ForceComMetadataRetriever - Polling the status of the retrieve request. 2020-10-26 15:21:38,976 [262617656] DEBUG - lder.ForceComMetadataRetriever - Status: Pending 2020-10-26 15:21:38,976 [262617656] DEBUG - lder.ForceComMetadataRetriever - Retrieve request is still processing. ... 2020-10-26 15:25:46,527 [262865207] DEBUG - .VariableLengthPollingInterval - AbstractForceComMetadataRetriever.retrieve: Using polling interval 5000 ms for polling iteration 66. 2020-10-26 15:25:51,533 [262870213] DEBUG - lder.ForceComMetadataRetriever - Polling the status of the retrieve request. 2020-10-26 15:25:51,736 [262870416] DEBUG - lder.ForceComMetadataRetriever - Status: Pending 2020-10-26 15:25:51,736 [262870416] DEBUG - lder.ForceComMetadataRetriever - Retrieve request is still processing. 2020-10-26 15:25:51,736 [262870416] DEBUG - .VariableLengthPollingInterval - AbstractForceComMetadataRetriever.retrieve: Using polling interval 5000 ms for polling iteration 67. 2020-10-26 15:25:56,738 [262875418] DEBUG - lder.ForceComMetadataRetriever - Polling the status of the retrieve request. 2020-10-26 15:25:56,933 [262875613] DEBUG - lder.ForceComMetadataRetriever - Status: Succeeded 2020-10-26 15:25:56,933 [262875613] DEBUG - lder.ForceComMetadataRetriever - Retrieve complete. 2020-10-26 15:25:57,452 [262876132] DEBUG - lder.ForceComMetadataRetriever - Retrieved an archive of size 4324 bytes.
As you can see, after submission the job was in a pending state until the final seconds after which the requested retrieval payload was returned. Unfortunately there's nothing in IC that can be changed for this as it's 100% in the Salesforce servers/queues. You would need to log a support case with Salesforce and can include the specific retrieval job IDs emitted into these logs as examples of these long retrieval times.
-
repo owner - changed status to resolved
Confirmed to be Salesforce queueing.
-
Account Deactivated reporter Very clear. Thanks a lot for looking into this.
-
repo owner - changed component to Metadata Deployment/Retrieval/Removal
- Log in to comment
The primary reason for this would be long Salesforce metadata API queues for that particular org. This is the most likely cause. To be 100% sure I'd need to see a log for the retrieval with debug logging enabled for metadata retrieval. What I'd expect to see if that's that case is that it submits the job to the server and polls for its completion for a very long time, likely with the job in a queue/pending state.
Let's start there. However, I also see something potentially problematic in your log. Are you storing your projects under OneDrive? If so, you'll need to move them outside of any cloud drive solution as that creates severe locking contention on the project files between the IDE and the cloud drive service.