High CPU usage on source push

[Luke Kozakewycz]

When pushing source from SFDX, I'm getting ~67% CPU usage every time for some reason.

The usage seems to be shared between IntelliJ and node.

Know why this might be happening?

I don't know if this is related - but since Winter '18 my pushes have been taking approximately 1m and 20 seconds whereas they used to take around 20 seconds. I probably never noticed the CPU usage increase before because it never took so long to compile. As far as I'm aware, judging by the logs, IC is simply requesting and retrieving during the lengthy waiting time so this might be on Salesforce's end.

As for the CPU usage - presumably IC is only polling for updates? Seems excessive - maybe I'm wrong?

[Luke Kozakewycz]

Hi Scott,

I've just done a few tests regarding the time it takes to push the source code.

Via IC it takes approx. 1m 20s. Via CLI it takes approx. 10s

It seems that IC is having trouble with it's pushes.

[Luke Kozakewycz]

Scott - I've updated IC and it now works as normal again! I'll resolve this. Thank you!

[Luke Kozakewycz]

Patch fixed this

[Scott Wells]

Luke, the issue was likely with the CLI updating. They pushed out a new version that's based on a new core in conjunction with the Winter '18 platform update. The update happens automatically when the CLI runs, and at least for me it took a long time and pegged several of my cores. I actually saw the same thing a few times after the update, but only on Windows. I've been communicating with Salesforce about it and it seems to be a known issue with the CLI on Windows right now that there's hoping to address.

If you do see this happen again, please let me know. All that IC is doing is launching a background sfdx CLI process and waiting for it to complete, then processing the JSON output of that process. It shouldn't be eating any CPU itself, but that doesn't mean the CLI isn't doing so and we'd need to communicate that to Salesforce if we see it happen.

[Luke Kozakewycz]

Hi Scott,

Just to let you know - this is happening again. CPU hungry and 1m 30s pushes.

[Scott Wells]

Yup. I haven't seen the fix come through from Salesforce. Does it just do it once and after that it's just fine again? That would certainly correlate with the CLI updating. If it happens repeatedly even after the CLI is updated I'll need to get a log as that would indicate something else goign on.

[Luke Kozakewycz]

It happens every time I push now unfortunately. :(

[Scott Wells]

Actually that's great. Consistently reproducible is good because it's fixable. Does the same thing happen when you try to do a push from the CLI? If so, it's a CLI issue; if not, it's an IC issue. If the latter, would you please add the following to Help>Debug Log Settings and reproduce the issue:

#com.illuminatedcloud.intellij.builder.ForceComSfdxDeployer
#com.illuminatedcloud.intellij.sfdx.SfdxUtil
#com.illuminatedcloud.util.CommandLineUtil

Then send me your idea.log using Help>Show Log in Explorer/Finder/Files. That should show me what's going on to burn your CPU and take so long. Thanks!

[Scott Wells]

Moving back to open while we triage the latest occurrence.

[Luke Kozakewycz]

When using the CLI, I get about 40% CPU usage from the powershell (not enough to switch the fan on apparently).

When using the IDE, I get about 70% CPU usage and the fan always comes on.

[Scott Wells]

Gotcha. So all that IC is doing is launching the process and then waiting for it to finish while pulling off of the process' stdout and stderr streams. However, it does look like it's not yielding CPU very well while doing so. I'll add in a sleep there to cause it to play more nicely. I think the reason you don't see this happen under happy path is because the CPU is pretty idle, but in the situation you describe where the CLI alone is pegging 40% CPU usage, things are already under duress. Either way I need to make IC a better citizen. Let me make a quick change and attach a test build here so that perhaps you can confirm that it helps. That work for you?

[Luke Kozakewycz]

Sure - sounds good to me. :)

Here's a log for you by the way:

2017-11-24 16:39:15,378 [24961390]   INFO - lij.diagnostic.DebugLogManager - Set DEBUG for the following categories: #com.illuminatedcloud.intellij.builder.ForceComSfdxDeployer, #com.illuminatedcloud.intellij.sfdx.SfdxUtil, #com.illuminatedcloud.util.CommandLineUtil 
2017-11-24 16:39:19,821 [24965833]  DEBUG - j.builder.ForceComSfdxDeployer - Pushing 'ls-engage' to 'AuraDev' 
2017-11-24 16:39:19,823 [24965835]  DEBUG - j.builder.ForceComSfdxDeployer - Bringing static resource bundles up-to-date. 
2017-11-24 16:39:19,823 [24965835]  DEBUG - j.builder.ForceComSfdxDeployer - Checking static resource bundle C:/Users/Luke/sfdx/ls-engage/resource-bundles/JS.resource. 
2017-11-24 16:39:19,823 [24965835]  DEBUG - j.builder.ForceComSfdxDeployer - Checking bundle directory contents relative to static resource file C:/Users/Luke/sfdx/ls-engage/force-app/main/default/staticresources/JS.resource. 
2017-11-24 16:39:19,824 [24965836]   INFO - j.builder.ForceComSfdxDeployer - Static resource JS.resource is up-to-date relative to resource bundle directory. 
2017-11-24 16:39:19,824 [24965836]  DEBUG - j.builder.ForceComSfdxDeployer - Checking static resource bundle C:/Users/Luke/sfdx/ls-engage/resource-bundles/SITERES.resource. 
2017-11-24 16:39:19,824 [24965836]  DEBUG - j.builder.ForceComSfdxDeployer - Checking bundle directory contents relative to static resource file C:/Users/Luke/sfdx/ls-engage/force-app/main/default/staticresources/SITERES.resource. 
2017-11-24 16:39:19,827 [24965839]   INFO - j.builder.ForceComSfdxDeployer - Static resource SITERES.resource is up-to-date relative to resource bundle directory. 
2017-11-24 16:39:19,827 [24965839]  DEBUG - j.builder.ForceComSfdxDeployer - Checking static resource bundle C:/Users/Luke/sfdx/ls-engage/resource-bundles/Stripe.resource. 
2017-11-24 16:39:19,827 [24965839]  DEBUG - j.builder.ForceComSfdxDeployer - Checking bundle directory contents relative to static resource file C:/Users/Luke/sfdx/ls-engage/force-app/main/default/staticresources/Stripe.resource. 
2017-11-24 16:39:19,827 [24965839]   INFO - j.builder.ForceComSfdxDeployer - Static resource Stripe.resource is up-to-date relative to resource bundle directory. 
2017-11-24 16:39:19,827 [24965839]  DEBUG - j.builder.ForceComSfdxDeployer - Checking static resource bundle C:/Users/Luke/sfdx/ls-engage/resource-bundles/UX.resource. 
2017-11-24 16:39:19,827 [24965839]  DEBUG - j.builder.ForceComSfdxDeployer - Checking bundle directory contents relative to static resource file C:/Users/Luke/sfdx/ls-engage/force-app/main/default/staticresources/UX.resource. 
2017-11-24 16:39:19,832 [24965844]   INFO - j.builder.ForceComSfdxDeployer - Static resource UX.resource is up-to-date relative to resource bundle directory. 
2017-11-24 16:39:19,832 [24965844]  DEBUG - j.builder.ForceComSfdxDeployer - Checking static resource bundle C:/Users/Luke/sfdx/ls-engage/resource-bundles/AuraLib.resource. 
2017-11-24 16:39:19,832 [24965844]  DEBUG - j.builder.ForceComSfdxDeployer - Checking bundle directory contents relative to static resource file C:/Users/Luke/sfdx/ls-engage/force-app/main/default/staticresources/AuraLib.resource. 
2017-11-24 16:39:19,832 [24965844]   INFO - j.builder.ForceComSfdxDeployer - Static resource AuraLib.resource is up-to-date relative to resource bundle directory. 
2017-11-24 16:39:19,832 [24965844]  DEBUG - j.builder.ForceComSfdxDeployer - Checking static resource bundle C:/Users/Luke/sfdx/ls-engage/resource-bundles/AuraStyle.resource. 
2017-11-24 16:39:19,832 [24965844]  DEBUG - j.builder.ForceComSfdxDeployer - Checking bundle directory contents relative to static resource file C:/Users/Luke/sfdx/ls-engage/force-app/main/default/staticresources/AuraStyle.resource. 
2017-11-24 16:39:19,833 [24965845]   INFO - undle.StaticResourceBundleUtil - Static resource C:/Users/Luke/sfdx/ls-engage/force-app/main/default/staticresources/AuraStyle.resource is out-of-date relative to bundle contents file C:/Users/Luke/sfdx/ls-engage/resource-bundles/AuraStyle.resource/bolt.css (1511541355087 > 1511541354519). 
2017-11-24 16:39:19,833 [24965845]  DEBUG - j.builder.ForceComSfdxDeployer - The bundle contents are newer than the static resource file. Updating the static resource for deployment. 
2017-11-24 16:39:19,833 [24965845]   INFO - j.builder.ForceComSfdxDeployer - Updating single static resource from bundle C:/Users/Luke/sfdx/ls-engage/resource-bundles/AuraStyle.resource for deployment. 
2017-11-24 16:39:19,843 [24965855]  DEBUG - j.builder.ForceComSfdxDeployer - Updated static resource file C:/Users/Luke/sfdx/ls-engage/force-app/main/default/staticresources/AuraStyle.resource from bundle C:/Users/Luke/sfdx/ls-engage/resource-bundles/AuraStyle.resource. 
2017-11-24 16:39:19,843 [24965855]   INFO - j.builder.ForceComSfdxDeployer - Using the sfdx CLI to push changes for project 'ls-engage' to scratch org 'AuraDev' with force=false, background=false. 
2017-11-24 16:39:19,844 [24965856]  DEBUG - atedcloud.util.CommandLineUtil - Running command line: C:/Program Files/sfdx/bin/sfdx.exe force:source:push -u test-c4wilkwrvqa9@learnsmarter_-_lk.net --json 
2017-11-24 16:41:05,133 [25071145]   INFO - ide.actions.ShowFilePathAction - 
Exit code 1 
2017-11-24 16:41:06,834 [25072846]  DEBUG - atedcloud.util.CommandLineUtil - Added 183 bytes from output stream. 
2017-11-24 16:41:06,887 [25072899]  DEBUG - atedcloud.util.CommandLineUtil - Returning command-line response: CommandLineResponse{exitCode=0, output='{"status":0,"result":{"pushedSource":[{"state":"Changed","fullName":"AuraStyle","type":"StaticResource","filePath":"force-app\\main\\default\\staticresources\\AuraStyle.resource"}]}}
', error=''} 
2017-11-24 16:41:06,887 [25072899]   INFO - j.builder.ForceComSfdxDeployer - Push completed in 1m 47s 44ms. 
2017-11-24 16:41:06,887 [25072899]  DEBUG - j.builder.ForceComSfdxDeployer - Received push response:
{
  "status": 0,
  "successResponse": {
    "status": 0,
    "result": {
      "pushedSource": [
        {
          "filePath": "force-app\\main\\default\\staticresources\\AuraStyle.resource",
          "fullName": "AuraStyle",
          "state": "Changed",
          "type": "StaticResource"
        }
      ]
    }
  }
} 
2017-11-24 16:41:06,887 [25072899]  DEBUG - j.builder.ForceComSfdxDeployer - Checking for conflicts. 
2017-11-24 16:41:06,887 [25072899]  DEBUG - j.builder.ForceComSfdxDeployer - Push appears to have succeeded. Adding details. 
2017-11-24 16:41:06,887 [25072899]  DEBUG - j.builder.ForceComSfdxDeployer - Processing result:
{
  "filePath": "force-app\\main\\default\\staticresources\\AuraStyle.resource",
  "fullName": "AuraStyle",
  "state": "Changed",
  "type": "StaticResource"
} 
2017-11-24 16:41:06,887 [25072899]  DEBUG - j.builder.ForceComSfdxDeployer - Trying to find a file for path: force-app\main\default\staticresources\AuraStyle.resource 
2017-11-24 16:41:06,887 [25072899]  DEBUG - j.builder.ForceComSfdxDeployer -   Looking for files named: AuraStyle.resource 
2017-11-24 16:41:06,890 [25072902]  DEBUG - j.builder.ForceComSfdxDeployer -   Found 2 matching files. 
2017-11-24 16:41:06,891 [25072903]  DEBUG - j.builder.ForceComSfdxDeployer -   Evaluating as match: C:/Users/Luke/sfdx/ls-engage/force-app/main/default/staticresources/AuraStyle.resource 
2017-11-24 16:41:06,891 [25072903]  DEBUG - j.builder.ForceComSfdxDeployer -   Looking for file under deployable source roots: 
2017-11-24 16:41:06,891 [25072903]  DEBUG - j.builder.ForceComSfdxDeployer -     Looking under: C:/Users/Luke/sfdx/ls-engage/force-app/main/default 
2017-11-24 16:41:06,891 [25072903]  DEBUG - j.builder.ForceComSfdxDeployer -     Found a match. 
2017-11-24 16:41:06,891 [25072903]  DEBUG - j.builder.ForceComSfdxDeployer -   Found as: C:/Users/Luke/sfdx/ls-engage/force-app/main/default/staticresources/AuraStyle.resource 
2017-11-24 16:41:06,891 [25072903]  DEBUG - j.builder.ForceComSfdxDeployer -   Adding build success as 'staticresources/AuraStyle.resource - Changed'. 
2017-11-24 16:41:06,891 [25072903]   INFO - .IlluminatedCloudExceptionUtil - Pushed 1/1 components to AuraDev in 1m 47s 44ms with status 0. 
2017-11-24 16:41:06,891 [25072903]   INFO - .IlluminatedCloudExceptionUtil - Push details:
{
  "successes": [
    "staticresources/AuraStyle.resource - Changed"
  ],
  "failures": [],
  "numSuccesses": 1,
  "numFailures": 0
} 

[Scott Wells]

Okay, here's a test build that yields CPU time properly while waiting for the sub-process to complete. It won't fix any delays from the CLI itself, but it should keep IC's overhead to a bare minimum. Let me know whether it makes a difference for you (positive or negative). Assuming it's a positive change I'll plan to include it in the next release.

[Luke Kozakewycz]

That resolved it! It's now down to 30-35% CPU. That's about what SFDX does alone. Thanks Scott!

Now - I can only hope that Salesforce fix the fact it's taking 1m 30s for each push! This is an awful amount of time to wait for every save.

[Scott Wells]

Glad to hear. I'll include that in this week's build. I've been using it over the past few days and it seems to make a nice difference (to the extent that I'm embarrassed I didn't see the IC portion of the problem earlier!).

Also, it appears that last week's SFDX CLI update has resolved the additional overhead of that process on Windows as well. I'm seeing very nice performance from the CLI now between the two. Make sure that you're running 6.0.16-3780698 or higher and let me know if the CLI problem still exists.

[Luke Kozakewycz]

I've just done some tests - pushing via the IDE takes around 1m 30s. The CLI doing the same process is taking as little as 10 seconds... hmmm. I thought it might have been either my ISP or Salesforce but I'm not so sure.

CPU usage is great now though!

[Scott Wells]

Luke, if you still have debug logging set up as described above, please send over a log showing this so I can see where the time is being spent. Like I said, it should just be running the CLI and (now patiently!) waiting for it to finish, then displaying the results. The polling interval is 1 second for the first 10 seconds then 2 seconds for the next 50 seconds and finally 5 seconds thereafter. I wouldn't ever expect there to be more than a 5 second difference between the CLI and IDE, and that would only be for processes that take more than a minute to run.

[Luke Kozakewycz]

2017-11-27 14:13:12,798 [1862674]  DEBUG - j.builder.ForceComSfdxDeployer - Pushing 'ls-engage' to 'AuraDev' 
2017-11-27 14:13:12,805 [1862681]  DEBUG - j.builder.ForceComSfdxDeployer - Bringing static resource bundles up-to-date. 
2017-11-27 14:13:12,806 [1862682]  DEBUG - j.builder.ForceComSfdxDeployer - Checking static resource bundle C:/Users/Luke/sfdx/ls-engage/resource-bundles/JS.resource. 
2017-11-27 14:13:12,806 [1862682]  DEBUG - j.builder.ForceComSfdxDeployer - Checking bundle directory contents relative to static resource file C:/Users/Luke/sfdx/ls-engage/force-app/main/default/staticresources/JS.resource. 
2017-11-27 14:13:12,810 [1862686]   INFO - j.builder.ForceComSfdxDeployer - Static resource JS.resource is up-to-date relative to resource bundle directory. 
2017-11-27 14:13:12,810 [1862686]  DEBUG - j.builder.ForceComSfdxDeployer - Checking static resource bundle C:/Users/Luke/sfdx/ls-engage/resource-bundles/AuraLib.resource. 
2017-11-27 14:13:12,810 [1862686]  DEBUG - j.builder.ForceComSfdxDeployer - Checking bundle directory contents relative to static resource file C:/Users/Luke/sfdx/ls-engage/force-app/main/default/staticresources/AuraLib.resource. 
2017-11-27 14:13:12,810 [1862686]   INFO - j.builder.ForceComSfdxDeployer - Static resource AuraLib.resource is up-to-date relative to resource bundle directory. 
2017-11-27 14:13:12,810 [1862686]  DEBUG - j.builder.ForceComSfdxDeployer - Checking static resource bundle C:/Users/Luke/sfdx/ls-engage/resource-bundles/SITERES.resource. 
2017-11-27 14:13:12,810 [1862686]  DEBUG - j.builder.ForceComSfdxDeployer - Checking bundle directory contents relative to static resource file C:/Users/Luke/sfdx/ls-engage/force-app/main/default/staticresources/SITERES.resource. 
2017-11-27 14:13:12,814 [1862690]   INFO - j.builder.ForceComSfdxDeployer - Static resource SITERES.resource is up-to-date relative to resource bundle directory. 
2017-11-27 14:13:12,814 [1862690]  DEBUG - j.builder.ForceComSfdxDeployer - Checking static resource bundle C:/Users/Luke/sfdx/ls-engage/resource-bundles/Stripe.resource. 
2017-11-27 14:13:12,814 [1862690]  DEBUG - j.builder.ForceComSfdxDeployer - Checking bundle directory contents relative to static resource file C:/Users/Luke/sfdx/ls-engage/force-app/main/default/staticresources/Stripe.resource. 
2017-11-27 14:13:12,815 [1862691]   INFO - j.builder.ForceComSfdxDeployer - Static resource Stripe.resource is up-to-date relative to resource bundle directory. 
2017-11-27 14:13:12,815 [1862691]  DEBUG - j.builder.ForceComSfdxDeployer - Checking static resource bundle C:/Users/Luke/sfdx/ls-engage/resource-bundles/UX.resource. 
2017-11-27 14:13:12,815 [1862691]  DEBUG - j.builder.ForceComSfdxDeployer - Checking bundle directory contents relative to static resource file C:/Users/Luke/sfdx/ls-engage/force-app/main/default/staticresources/UX.resource. 
2017-11-27 14:13:12,819 [1862695]   INFO - j.builder.ForceComSfdxDeployer - Static resource UX.resource is up-to-date relative to resource bundle directory. 
2017-11-27 14:13:12,819 [1862695]  DEBUG - j.builder.ForceComSfdxDeployer - Checking static resource bundle C:/Users/Luke/sfdx/ls-engage/resource-bundles/AuraStyle.resource. 
2017-11-27 14:13:12,820 [1862696]  DEBUG - j.builder.ForceComSfdxDeployer - Checking bundle directory contents relative to static resource file C:/Users/Luke/sfdx/ls-engage/force-app/main/default/staticresources/AuraStyle.resource. 
2017-11-27 14:13:12,820 [1862696]   INFO - j.builder.ForceComSfdxDeployer - Static resource AuraStyle.resource is up-to-date relative to resource bundle directory. 
2017-11-27 14:13:12,820 [1862696]   INFO - j.builder.ForceComSfdxDeployer - Using the sfdx CLI to push changes for project 'ls-engage' to scratch org 'AuraDev' with force=false, background=false. 
2017-11-27 14:13:12,820 [1862696]  DEBUG - atedcloud.util.CommandLineUtil - Running command line: C:/Program Files/sfdx/bin/sfdx.exe force:source:push -u test-c4wilkwrvqa9@learnsmarter_-_lk.net --json 
2017-11-27 14:14:32,842 [1942718]  DEBUG - atedcloud.util.CommandLineUtil - Added 185 bytes from output stream. 
2017-11-27 14:14:37,843 [1947719]  DEBUG - atedcloud.util.CommandLineUtil - Returning command-line response: CommandLineResponse{exitCode=0, output='{"status":0,"result":{"pushedSource":[{"state":"Changed","fullName":"ControlPaymentConfig","type":"ApexPage","filePath":"force-app\\main\\default\\pages\\ControlPaymentConfig.page"}]}}
', error=''} 
2017-11-27 14:14:37,844 [1947720]   INFO - j.builder.ForceComSfdxDeployer - Push completed in 1m 25s 24ms. 
2017-11-27 14:14:37,844 [1947720]  DEBUG - j.builder.ForceComSfdxDeployer - Received push response:
{
  "status": 0,
  "successResponse": {
    "status": 0,
    "result": {
      "pushedSource": [
        {
          "filePath": "force-app\\main\\default\\pages\\ControlPaymentConfig.page",
          "fullName": "ControlPaymentConfig",
          "state": "Changed",
          "type": "ApexPage"
        }
      ]
    }
  }
} 
2017-11-27 14:14:37,845 [1947721]  DEBUG - j.builder.ForceComSfdxDeployer - Checking for conflicts. 
2017-11-27 14:14:37,845 [1947721]  DEBUG - j.builder.ForceComSfdxDeployer - Push appears to have succeeded. Adding details. 
2017-11-27 14:14:37,845 [1947721]  DEBUG - j.builder.ForceComSfdxDeployer - Processing result:
{
  "filePath": "force-app\\main\\default\\pages\\ControlPaymentConfig.page",
  "fullName": "ControlPaymentConfig",
  "state": "Changed",
  "type": "ApexPage"
} 
2017-11-27 14:14:37,845 [1947721]  DEBUG - j.builder.ForceComSfdxDeployer - Trying to find a file for path: force-app\main\default\pages\ControlPaymentConfig.page 
2017-11-27 14:14:37,845 [1947721]  DEBUG - j.builder.ForceComSfdxDeployer -   Looking for files named: ControlPaymentConfig.page 
2017-11-27 14:14:37,845 [1947721]  DEBUG - j.builder.ForceComSfdxDeployer -   Found 1 matching files. 
2017-11-27 14:14:37,846 [1947722]  DEBUG - j.builder.ForceComSfdxDeployer -   Evaluating as match: C:/Users/Luke/sfdx/ls-engage/force-app/main/default/pages/ControlPaymentConfig.page 
2017-11-27 14:14:37,846 [1947722]  DEBUG - j.builder.ForceComSfdxDeployer -   Looking for file under deployable source roots: 
2017-11-27 14:14:37,846 [1947722]  DEBUG - j.builder.ForceComSfdxDeployer -     Looking under: C:/Users/Luke/sfdx/ls-engage/force-app/main/default 
2017-11-27 14:14:37,846 [1947722]  DEBUG - j.builder.ForceComSfdxDeployer -     Found a match. 
2017-11-27 14:14:37,846 [1947722]  DEBUG - j.builder.ForceComSfdxDeployer -   Found as: C:/Users/Luke/sfdx/ls-engage/force-app/main/default/pages/ControlPaymentConfig.page 
2017-11-27 14:14:37,846 [1947722]  DEBUG - j.builder.ForceComSfdxDeployer -   Adding build success as 'pages/ControlPaymentConfig.page - Changed'. 
2017-11-27 14:14:37,846 [1947722]   INFO - .IlluminatedCloudExceptionUtil - Pushed 1/1 components to AuraDev in 1m 25s 24ms with status 0. 
2017-11-27 14:14:37,847 [1947723]   INFO - .IlluminatedCloudExceptionUtil - Push details:
{
  "successes": [
    "pages/ControlPaymentConfig.page - Changed"
  ],
  "failures": [],
  "numSuccesses": 1,
  "numFailures": 0
} 
2017-11-27 14:47:46,663 [3936539]   INFO - ide.actions.ShowFilePathAction - 
Exit code 1 

[Luke Kozakewycz]

Certainly looks like it happens between calling SFDX and the response! I wonder if SFDX has a problem with the plugin functionality, as opposed to the actual push...

[Scott Wells]

Thanks for the log. So here's what I see:

2017-11-27 14:13:12,820 [1862696]  DEBUG - atedcloud.util.CommandLineUtil - Running command line: C:/Program Files/sfdx/bin/sfdx.exe force:source:push -u test-c4wilkwrvqa9@learnsmarter_-_lk.net --json 
2017-11-27 14:14:32,842 [1942718]  DEBUG - atedcloud.util.CommandLineUtil - Added 185 bytes from output stream. 
2017-11-27 14:14:37,843 [1947719]  DEBUG - atedcloud.util.CommandLineUtil - Returning command-line response: CommandLineResponse{exitCode=0, ...

It looks like it actually took 1m20s to run the command. Then there's another 5s for one more polling interval that I've already eliminated in the version that I'll be releasing with the official product tomorrow or Wednesday, so that'll drop off.

The main difference between the embedded CLI execution and explicit CLI inovcation is that IC set the SFDX_AUTOUPDATE_DISABLE environment variable to true. That's supposed to be an optimization, but perhaps it's causing something weird to happen in the CLI? Do you mind running the CLI with that environment variable set to see if the times are closer between the IDE and the CLI?

[Luke Kozakewycz]

I've played around with the CLI command you are executing. Executing the same command also took as long as the IDE. I tried changing the path to just sfdx and the username to just the alias and removing --json. Nothing worked.

However - the thing that did work was adding -f. If you force an overwrite, it's instant! And that's what I've been doing the majority of the time when using the CLI. That's why it has been so much faster.

Is there a way to execute the command with -f in the IDE? I haven't seen any options to do so. I can obviously see the benefits of not forcing an overwrite, but in most cases, I just want to save and be done with it.

Thanks for your help Scott.

[Luke Kozakewycz]

FYI - The environment variable suggestion didn't make any difference.

[Scott Wells]

Not surprising. Based on what you've said, it sounds like the difference is the CLI's conflict detection. Before I add that as an option in IC, let me chat with the SFDX team and see if they know that conflict detection can add so much overhead. I don't have an issue providing a per-connection (i.e., scratch org) or even global option to disable conflict detection for SFDX push/pull in IC, but since it raises the likelihood of data loss, let me just check in with the folks who've written this stuff before adding such an option. Thanks for helping to corner it!

[Scott Wells]

Hey, Luke. The SFDX team is definitely intrigued by the behavior you're seeing. Just to clarify 100%, you can reproduce this from the CLI, correct? If you use -f then it's fast; if you don't then it's slow? If so, would you be open to a direct connection with the SFDX team to help them reproduce this behavior? None of us are able to reproduce it in isolation.

[Luke Kozakewycz]

I can post on the SFDX group.

I am running this for a fairly large project. I wonder if that is the reason why it takes so long. But then would they not just do checksum comparisons to reduce overhead?

[Scott Wells]

Sounds good. Go ahead and mention Thomas Dvornik, Dave Carroll, and me to help bridge into the discussion.

[Scott Wells]

Fix delivered with 1.8.1.3.

[Scott Wells]

And just to clarify, this is the fix for IC pegging a CPU while waiting for the CLI. It doesn't add an option for the "-f" flag all the time. I may still do that based on the discussion on the Success forum, though.