Initial performance of az is terrible on windows.

[jessehouwing]

Description

The first call to az seems to take ages, subsequent calls are much faster. This is especially true on Windows.

The following azure pipeline takes 1 minute+ to execute the first az pipelines call. subsequent calls execute in less than 3 seocnds:

pool:
  vmImage: windows-latest

variables:
  "system.debug": true
  
steps:
- pwsh: |
      $pipelineId= & az pipelines runs show --id $env:BUILD_BUILDID --query "definition.id" --verbose --organization $env:SYSTEM_COLLECTIONURI --project $env:SYSTEM_TEAMPROJECT
  env:
    AZURE_DEVOPS_EXT_PAT: $(System.AccessToken)

- pwsh: |
      $pipelineId= & az pipelines runs show --id $env:BUILD_BUILDID --query "definition.id" --verbose --organization $env:SYSTEM_COLLECTIONURI --project $env:SYSTEM_TEAMPROJECT
  env:
    AZURE_DEVOPS_EXT_PAT: $(System.AccessToken)

A comparison in time:

$pipelineId = & az pipelines runs show --id $env:BUILD_ID --query "definition.id" --verbose --organization $env:System_CollectionUri --project $env:System_TeamProject
INFO: received PAT from environment variable
INFO: Creating connection with personal access token.
INFO: Command ran in 84.221 seconds (init: 20.825, invoke: 63.396)

$pipelineId = & az pipelines runs show --id $env:BUILD_ID --query "definition.id" --verbose --organization $env:System_CollectionUri --project $env:System_TeamProject
INFO: received PAT from environment variable
INFO: Creating connection with personal access token.
INFO: Command ran in 0.829 seconds (init: 0.322, invoke: 0.507)

Turning off a number of features such as auto-upgrade and telemetry speeds up things quite a bit, but still not within acceptable range, but not consistently

- script: |
   c:
   cd %USERPROFILE%
   md .azure 
   cd .azure
   echo [core] > config
   echo first_run = false >> config
   echo collect_telemetry = false >> config
   echo error_recommendation = off >> config
   echo output = json >> config
   echo only_show_errors = true >> config
   echo no_color = true >> config
   echo disable_progress_bar = true >> config
   echo [auto-upgrade] >> config
   echo enable = False >> config
   echo [logging] >> config
   echo enable_log_file = no >> config
   echo [output] >> config
   echo show_survey_link = no >> config
   az --version

After this the time for the first call drops from the 80 second range to around 30 seconds:

INFO: received PAT from environment variable
INFO: Creating connection with personal access token.
INFO: Command ran in 28.488 seconds (init: 0.330, invoke: 28.158)

Still not great, but a marked improvement

I wonder whether calling az --version and potentially az devops configure -l and possibly a few other with a sufficiently long cache_ttl setting may work to gain super-quick speeds in actual first use. This could potentially save quite a bit of time for each pipeline that uses az and its extensions.

Explicitly logging in also seems to be faster than relying on the environment variable:

echo $(System.AccessToken) | az devops login

is faster than using

  env:
    AZURE_DEVOPS_EXT_PAT: $(System.AccessToken)

It's not a shocking improvement, but still a few seconds. In the grand scheme of things that would save a few a few trees...

Platforms affected

• Azure DevOps
• GitHub Actions - Standard Runners
• GitHub Actions - Larger Runners

Runner images affected

• Ubuntu 20.04
• Ubuntu 22.04
• macOS 11
• macOS 12
• macOS 13
• Windows Server 2019
• Windows Server 2022

Image version and build link

https://github.com/actions/runner-images/releases/tag/win22%2F20230910.1

Is it regression?

no

Expected behavior

First call is within acceptable speed (less than 20 seconds)

Actual behavior

First call take 80+ seconds

Repro steps

Create a pipeline as follows (Azure Pipelines example):

pool:
  vmImage: windows-latest

variables:
  "system.debug": true
  
steps:
- pwsh: |
      $pipelineId= & az pipelines runs show --id $env:BUILD_BUILDID --query "definition.id" --verbose --organization $env:SYSTEM_COLLECTIONURI --project $env:SYSTEM_TEAMPROJECT
  env:
    AZURE_DEVOPS_EXT_PAT: $(System.AccessToken)

- pwsh: |
      $pipelineId= & az pipelines runs show --id $env:BUILD_BUILDID --query "definition.id" --verbose --organization $env:SYSTEM_COLLECTIONURI --project $env:SYSTEM_TEAMPROJECT
  env:
    AZURE_DEVOPS_EXT_PAT: $(System.AccessToken)

[shamil-mubarakshin]

Hello @jessehouwing,
Thank you for reporting and contributing. We will investigate this behavior and warmup possibilities

[jessehouwing]

Pull request is ready.

[ilia-shipitsin]

thank you for pull request. give me few days to test