'sf project deploy start' commands are taking a long time to pass back a completion status to pipelines

[stuartgrieve]

Summary

We run our deployment automation using Bitbucket Pipelines, using the docker image: salesforce/cli:nightly-full

Over the past week or two, our development team has noticed validations/deployments hitting the sandbox, completing, and then a significant wait before the sf project deploy start command completes in Bitbucket.

After some further investigations, it seems to happen more so on successful runs. I ran four scenarios which run on a consistent pipeline script to a single sandbox:

• branch1 (contains valid metadata so was passing): triggered a build, org showed it passed, the CLI outputs Status: Succeeded
  
  
  
  Some 20 minutes later, Bitbucket has still not received the completion status
  
• branch2 (contains failing tests): triggered a build, org showed it failed, within a minute the step in Bitbucket displays the failure
• branch1 (untouched from the first build): triggered again, same outcome, it passes, but the status hangs
• branch1 (modified a class to break the validation): as with branch2, org presented the failure and almost immediately the Bitbucket step failed too
  

Steps To Reproduce

I can't provide our repository since the content is sensitive, but this behaviour seems to be agnostic to the metadata included in the build anyway. Below is the script we're using for PR validations:

# Author: Slalom

# Docker image to be used
image: 
  name: salesforce/cli:nightly-full
  run-as-user: 0

# Maximum minutes a step can execute before timing out
options:
  max-time: 120

pipelines:

  pull-requests:

    feature/*:
      - step:
          name: QA Sandbox Validation
          script:
            - sf version --verbose --json
            - echo y | sfdx plugins:install sfdx-git-delta
            - export COMMIT_MESSAGE=$(git log --format=%B -n 1 $BITBUCKET_COMMIT)
            - if [[ "$COMMIT_MESSAGE" == *"[bypass-delta]"* ]]; then echo Bypassing creation of delta directory; else mkdir delta-deployment; echo 'force-app/main/default/layouts/*' > .deltainclude; sfdx sgd:source:delta --to origin/$BITBUCKET_BRANCH --from origin/$BITBUCKET_PR_DESTINATION_BRANCH --output "delta-deployment" --generate-delta --include .deltainclude; echo Delta directory result...; ls -R delta-deployment; fi;
            - export TEST_FILES=$(python3 scripts/get-test-class-list.py delta-deployment/force-app/main/default/classes delta-deployment/force-app/main/default/triggers | tr ',' ' '); echo $TEST_FILES
            - export CLIENT_ID=$PLATFORM_QA_SECRET; export USERNAME=$PLATFORM_QA_USERNAME; export URL=$PLATFORM_QA_URL;
            - openssl enc -nosalt -aes-256-cbc -d -in certificates/server.key.enc -out certificates/server.key -base64 -K $ENCRYPTION_KEY -iv $ENCRYPTION_IV; ls certificates
            - sf login org jwt --client-id $CLIENT_ID --username $USERNAME -f certificates/server.key --instance-url $URL
            - if [ "$(ls -A delta-deployment/force-app/main/default)" ] || [ "$(ls -A delta-deployment/omniStudio-metadata)" ] || [ "$(ls -A delta-deployment/unpackaged-metadata)" ]; then sf project deploy start --verbose --ignore-conflicts --ignore-warnings --source-dir delta-deployment --dry-run --test-level RunSpecifiedTests --tests $TEST_FILES "Test With Space" --target-org $USERNAME --wait 60; else echo "No delta detected, full validation..."; sf project deploy start --verbose --ignore-conflicts --ignore-warnings --source-dir force-app/main/default omniStudio-metadata unpackaged-metadata --dry-run --test-level RunLocalTests --target-org $USERNAME --wait 60; fi
            - sf logout org --target-org $USERNAME --no-prompt

Expected result

When a validation/deployment successfully completes in an org, the CLI receives the exit code shortly afterwards

Actual result

Instead, we are seeing it hang for 10-20 minutes.

System Information

Terminal: bash

{
  "cliVersion": "@salesforce/cli/2.12.0",
  "architecture": "linux-x64",
  "nodeVersion": "node-v18.15.0",
  "osVersion": "Linux 5.15.0-1043-aws",
  "shell": "bash",
  "rootPath": "/usr/local/lib/nodejs/lib/node_modules/@salesforce/cli",
  "pluginVersions": [
    "@oclif/plugin-autocomplete 2.3.8 (core)",
    "@oclif/plugin-commands 2.2.26 (core)",
    "@oclif/plugin-help 5.2.19 (core)",
    "@oclif/plugin-not-found 2.4.1 (core)",
    "@oclif/plugin-plugins 3.8.2 (core)",
    "@oclif/plugin-search 0.0.22 (core)",
    "@oclif/plugin-update 3.2.3 (core)",
    "@oclif/plugin-version 1.3.10 (core)",
    "@oclif/plugin-warn-if-update-available 2.1.0 (core)",
    "@oclif/plugin-which 2.2.32 (core)",
    "@salesforce/cli 2.12.0 (core)",
    "apex 2.3.15 (core)",
    "auth 2.8.17 (core)",
    "data 2.5.12 (core)",
    "deploy-retrieve 1.18.2 (core)",
    "info 2.6.45 (core)",
    "limits 2.3.35 (core)",
    "login 1.2.31 (core)",
    "marketplace 0.2.2 (core)",
    "org 2.10.8 (core)",
    "schema 2.3.28 (core)",
    "settings 1.4.30 (core)",
    "sobject 0.2.7 (core)",
    "source 2.10.36 (core)",
    "telemetry 2.3.4 (core)",
    "templates 55.5.13 (core)",
    "trust 2.6.15 (core)",
    "user 2.3.32 (core)"
  ]
}

Additional information

[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.

[mdonnalley]

@stuartgrieve This might be related to a specific metadata type you have in your project. Can you run the command with SF_LOG_LEVEL=debug and DEBUG=* env vars. In those logs you might see logs indicating that we're still polling for certain SourceMembers, Still looking for SourceMembers: ... (logged from here)

[mcarvin8]

Is there any harm to setting the SF_DISABLE_SOURCE_MEMBER_POLLING environment variable to True to disable this behavior?

I was noticing my GitLab pipeline status was stuck in Status: In-Progress for about 30 minutes after the deployment finished.

This deployment only contained 1 ApexComponent that didn't run any tests in the org.

I have also seen this behavior in other deployments which contained different types of metadata.

[mdonnalley]

I would take a look at the description of SF_DISABLE_SOURCE_MEMBER_POLLING here

When you disable SourceMember polling, the CLI’s internal tracking of what’s changed between your local source and org metadata gets out of sync. As a result, subsequent runs of the project deploy|retrieve commands are unreliable, and it’s up to you to synchronize your source. To reset source tracking, use the project reset tracking command.

[mcarvin8]

So based on my understanding on the variable's description, the risk is that the CLI is unable to track what's changed between the local source and the org.

The comment " Sometimes you don't require source tracking at all, such as in a continuous integration (CI) job" makes me think you can accept this risk in disabling the source member polling if you are enforcing strict version control via a Git repository, especially when in my case our Git repo is tied to our CI jobs.

[iowillhoit]

@mcarvin8 If you were able to find which SourceMember it was hanging on (following #2495 (comment)) then we could add it to an exclusion list. Even if you decide to disable source member polling, this could save someone else some time in the future

[mcarvin8]

I haven't been able to replicate this with the above Logging updates suggested, but I noticed 3 deployments run into this issue in my org (1 production and 2 sandbox) and all deployments were deploying 'ApexComponent'. The Prod deployment which stalled in the CLI was just deploying a single ApexComponent without running any tests in the org.

I'll try again to see if I can get the 'Still Looking for SourceMember' log generated with an ApexComponent deployment, but thought I'd share that for now.

[A30016340]

This is stopping us from moving from sfdx to sf commands as sf project deploy start commands keeps timings out and the pipelines are breaking. Any timlines to improve the performance.

[mshanemc]

If you don't care about tracking, you can set SF_DISABLE_SOURCE_MEMBER_POLLING

the org create scratch command has a flag for turning tracking off entirely. I think we need a way for doing that with sandboxes for situations like this where you're not doing dev work and don't need tracking.

Additionally, for long-lived sboxes, the SourceMember history is going to pile up in ways the scratch orgs can't, and that can lead to perf issues as well.

Lastly, we need a way to better expose what's taking SourceMember polling so long, which may help you fix issues. The info is in the logs and captured in telemetry, but not in the json responses.

[mshanemc]

heads-up...we've added a command for sf org disable tracking so you can use that on a source-tracking sandbox but don't actually want tracking.

nightly...now
RC on the 29th,
Latest the following Wed.

[A30016340]

We dont do source tracking, hence for us it may not be the solution we are looking. We only need a working model of project start command