Long delay in push after the deployment completes before the CLI exits

[SCWells72]

A bit back I enhanced IC2 to start a separate polling thread for the deployment job created by a force:source:push initiated by IC2 to provide more granular reporting feedback. That works great, but I've noticed that there can often be a significant delay between completion of the deployment job and when the CLI command itself exits. I've started to add a "Waiting for CLI to exit" message to the progress indicator in this situation, but I figured I'd log it with you all to see if that's expected and, if(/assuming?) not, to ensure it's on your radar. Here's an extract from an IC2 debug log showing the relationship between the deployment job completion and the CLI command completion:

2023-03-23 12:33:23,449 [ 873577]   FINE - #com.illuminatedcloud.intellij.builder.ForceComSfdxDeployer - Querying the push deployment job status.
2023-03-23 12:33:23,646 [ 873774]   FINE - #com.illuminatedcloud.intellij.builder.ForceComSfdxDeployer -   Found the deployment job status:
{
  "checkOnly": false,
  "completedDate": 1679592797000,
  "createdBy": "<redacted>",
  "createdByName": "User User",
  "createdDate": 1679592664000,
  "details": {},
  "done": true,
  "id": "<redacted>",
  "numberComponentErrors": 0,
  "numberComponentsDeployed": 643,
  "numberComponentsTotal": 643,
  "numberTestErrors": 0,
  "numberTestsCompleted": 0,
  "numberTestsTotal": 0,
  "rollbackOnError": true,
  "runTestsEnabled": false,
  "startDate": 1679592665000,
  "status": "SUCCEEDED",
  "success": true
}
2023-03-23 12:33:23,646 [ 873774]   FINE - #com.illuminatedcloud.util.VariableLengthPollingInterval - C:/Program Files/sfdx/bin/sfdx.cmd force:source:push -u <redacted> --json: Using polling interval 5000 ms for polling iteration 45.
...
2023-03-23 12:34:25,796 [ 935924]   FINE - #com.illuminatedcloud.util.VariableLengthPollingInterval - C:/Program Files/sfdx/bin/sfdx.cmd force:source:push -u <redacted> --json: Using polling interval 5000 ms for polling iteration 57.
2023-03-23 12:34:30,804 [ 940932]   FINE - #com.illuminatedcloud.util.CommandLineUtil - Returning command-line response: CommandLineResponse{exitCode=0, output='{
  "status": 0,
  "result": {
    "pushedSource": [
    ...
    ]
  }
}

Notice that there's over a full minute between when the deployment job is reported as SUCCEEDED and when the CLI push command completes.

Let me know if you need any more info to help with this.

[github-actions]

Thank you for filing this issue. We appreciate your feedback and will review the issue as soon as possible. Remember, however, that GitHub isn't a mechanism for receiving support under any agreement or SLA. If you require immediate assistance, contact Salesforce Customer Support.

[daveespo]

We had logged this a long time ago when the structure of the local source tracking was changed to be a git repo -- Over on #1394 (comment) I reported it was taking 17 minutes but further on in that thread it was reduced down to "2 minutes" which sounds similar to what you're reporting

[WillieRuemmele]

Hey @daveespo @SCWells72 👋

I'm almost certain that this is happening because of server updating the SourceMember table. Once the deployment is complete, it will update the table, and then the CLI has to query the updated table to update the local source tracking information. You might already know that, but there's not much we can do for now... there's some config settings to set disable it or set timeouts, but those might not be viable for you https://developer.salesforce.com/docs/atlas.en-us.sfdx_setup.meta/sfdx_setup/sfdx_dev_cli_env_variables.htm

We've been talking about how to enable performance logging to help raise these issues to other teams and improve this experience

[SCWells72]

Hi, @WillieRuemmele. Good info to have. I already have IC2 telling the end user that it's in a "deployment complete/waiting on CLI" state, so I don't know that there's anything else I need to do. More than anything I wanted to bring this to your attention because the delay can be unexpectedly long and I didn't know if you were aware of it and/or if it was perhaps a low-hanging-fruit type of thing to address. It sounds like it's probably not, and of course now I know you're in fact aware of it, so I'm good. Thanks again!

[mshanemc]

@W-13792892@