WSL: Why Azure CLI is too slow at each command execution?

alexsandro-xpt commented 5 years ago

Describe the bug It's not exactly a bug but every command at PowerShell or Bash in WSL is too slow, I know that every command is making a web-api request call but is really sad this api call is causing too much delay.

I don't know if I am at Brazil and the all api calls is from US and those internet latence is the cause but is really bad.

To Reproduce Stay at Brazil and call a single command like az acr list.

Expected behavior I don't know, but some loading indicator or proxy all api request call near Brazil...

Environment summary Windows 10 with PowerShell and WSL

λ  az --version
azure-cli (2.0.46)

acr (2.1.5)
acs (2.3.4)
advisor (0.6.0)
ams (0.2.3)
appservice (0.2.4)
backup (1.2.1)
batch (3.4.0)
batchai (0.4.3)
billing (0.2.0)
botservice (0.1.1)
cdn (0.1.1)
cloud (2.1.0)
cognitiveservices (0.2.3)
command-modules-nspkg (2.0.2)
configure (2.0.18)
consumption (0.4.0)
container (0.3.4)
core (2.0.46)
cosmosdb (0.2.1)
dla (0.2.3)
dls (0.1.3)
dms (0.1.1)
eventgrid (0.2.0)
eventhubs (0.2.4)
extension (0.2.1)
feedback (2.1.4)
find (0.2.12)
interactive (0.3.30)
iot (0.3.2)
iotcentral (0.1.2)
keyvault (2.2.3)
lab (0.1.1)
maps (0.3.2)
monitor (0.2.3)
network (2.2.5)
nspkg (3.0.3)
policyinsights (0.1.0)
profile (2.1.1)
rdbms (0.3.2)
redis (0.3.2)
relay (0.1.2)
reservations (0.4.0)
resource (2.1.4)
role (2.1.5)
search (0.1.1)
servicebus (0.2.3)
servicefabric (0.1.3)
signalr (1.0.0)
sql (2.1.4)
storage (2.2.2)
telemetry (1.0.0)
vm (2.2.3)

Python location 'C:\Program Files (x86)\Microsoft SDKs\Azure\CLI2\python.exe'
Extensions directory 'C:\Users\alexs\.azure\cliextensions'

Python (Windows) 3.6.5 (v3.6.5:f59c0932b4, Mar 28 2018, 16:07:46) [MSC v.1900 32 bit (Intel)]

Legal docs and information: aka.ms/AzureCliLegal

Additional context Every was slow here at Brazil, I don't know if it is slow in another region, I'm posting it right now because I'm starting use Azure CLI constantly and I wish a better user experience.

Thank's!

troydai commented 5 years ago

Can you time the command for us? And could you run az account list and time it?

alexsandro-xpt commented 5 years ago

@troydai az account list is quick, is between 3 or 4 seconds.

troydai commented 5 years ago

3 to 4 seconds is not normal. Is it in WSL or PowerShell?

alexsandro-xpt commented 5 years ago

In the both @troydai, the user experience with Azure CLI time perception is not good.

andreacassioli commented 5 years ago

Same here. I run a simple command like

18:45 $ time  az resource list --resource-group xxx --resource-type "Microsoft.KeyVault/vaults"
...
real    0m2.418s
user    0m0.582s
sys 0m0.120s

and it took more than 2 seconds! And this is a consistent behaviour... It seems a lot for a simple info request.

nholms commented 5 years ago

I can also confirm this issue

λ  Measure-Command {az account list}
Days              : 0
Hours             : 0
Minutes           : 0
Seconds           : 4
Milliseconds      : 92
Ticks             : 40921235
TotalDays         : 4.73625405092593E-05
TotalHours        : 0.00113670097222222
TotalMinutes      : 0.0682020583333333
TotalSeconds      : 4.0921235
TotalMilliseconds : 4092.1235

λ  Measure-Command {az resource list --resource-group xxx --resource-type "Microsoft.KeyVault/vaults"}
Resource group 'xxx' could not be found.
Days              : 0
Hours             : 0
Minutes           : 0
Seconds           : 4
Milliseconds      : 871
Ticks             : 48719548
TotalDays         : 5.63883657407407E-05
TotalHours        : 0.00135332077777778
TotalMinutes      : 0.0811992466666667
TotalSeconds      : 4.8719548
TotalMilliseconds : 4871.9548

alexsandro-xpt commented 5 years ago

@NickSuperb Are you run it from Brazil too?

sasacocic commented 5 years ago

I'm also having a similar issue except with aks and kubectl.

time kubectl get pods --all-namespaces

real    0m5.510s
user    0m0.111s
sys 0m0.020s

it takes 5 seconds ....

the az cli also takes quite a bit of time.

sylfabre commented 5 years ago

Same here, I'm in Paris, France

gstolz commented 5 years ago

same here, from Germany to DC in Amsterdam,NL az network traffic-manager endpoint list... --> 8s With a script consisting of multiple requests this adds up quite a bit...

andreacassioli commented 5 years ago

It does not seems to be a geographical issue, but rather Azure slow responding. Which does not really not surprise me as also from the portal I often experience very slow operations.

Any comments from MS Azure people?

tjprescott commented 5 years ago

There are performance issues native to WSL and Windows Defender that make things abnormally slow in this environment. Future versions of WSL aim to address this performance issue, but it is not something we control within the CLI.

alexsandro-xpt commented 5 years ago

@tjprescott It's not only in WSL, PowerShell or CMD has same behavior.

andreacassioli commented 5 years ago

@tjprescott I am running Mac OSX and experiencing slowness as well.

silkfire commented 5 years ago

@tjprescott Experiencing the same issue. A login request takes about 5 sec...

andreacassioli commented 5 years ago

To add a bit more: I sometimes experience similar poor performance also using the azure portal. Is it then a back end issue?

yonzhan commented 4 years ago

add to S164.

CoderKooke commented 4 years ago

Hi All.

I would like to contribute to this if I may. Sadly I don't have a trace to offer but I can confirm the below:

Container create in Portal - 25-30 seconds
Contaniner create via CLI from local machine with direct access on owner account: 1 hour+
Container delete in Portal - 5 seconds
Container delete via CLI from local machine with direct access on owner account: I gave up

Parameters: Linux image (119MB) from Docker Hub into West Europe Container Group with 1vcpu and 1.5GiB.

jiasli commented 4 years ago

@CoderKooke, could you let us know the command you were running? Thanks.

CoderKooke commented 4 years ago

Sure. az container create

Pulling a Linux image from DockerHub. Looking at the output, it appears that the length was because it failed then tried again.

The output eventually said success but the container was in state "Invalid" or something like that.

On Fri, 17 Jan 2020, 01:48 Jiashuo Li, notifications@github.com wrote:

@CoderKooke https://github.com/CoderKooke, could you let us know the command you were running? Thanks.

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/Azure/azure-cli/issues/7447?email_source=notifications&email_token=AKY2HOP6DXWVDYHFZQQ77O3Q6EE5NA5CNFSM4FYEOKOKYY3PNVWWK3TUL52HS4DFVREXG43VMVBW63LNMVXHJKTDN5WW2ZLOORPWSZGOEJGFMBA#issuecomment-575428100, or unsubscribe https://github.com/notifications/unsubscribe-auth/AKY2HOJG3OG4NMGTHSKE2TLQ6EE5NANCNFSM4FYEOKOA .

yonzhan commented 4 years ago

@fengzhou-msft please take a look also.

gewoonwoutje commented 4 years ago

Asking what version of the az CLI already takes more than 2 seconds. Isn't that quite long for showing a version number?

I installed the CLI via the .msi installer.

C:\Windows\system32> az --version
azure-cli                         2.0.80

command-modules-nspkg              2.0.3
core                              2.0.80
nspkg                              3.0.4
telemetry                          1.0.4

Extensions:
azure-devops                      0.17.0

Python location 'C:\Program Files (x86)\Microsoft SDKs\Azure\CLI2\python.exe'
Extensions directory 'C:\Users\Wout\.azure\cliextensions'

Python (Windows) 3.6.6 (v3.6.6:4cf1f54eb7, Jun 27 2018, 02:47:15) [MSC v.1900 32 bit (Intel)]

Legal docs and information: aka.ms/AzureCliLegal

Your CLI is up-to-date.

Please let us know how we are doing: https://aka.ms/clihats
C:\Windows\system32> Measure-Command { az --version }

Days              : 0
Hours             : 0
Minutes           : 0
Seconds           : 2
Milliseconds      : 400
Ticks             : 24004857
TotalDays         : 2,77833993055556E-05
TotalHours        : 0,000666801583333333
TotalMinutes      : 0,040008095
TotalSeconds      : 2,4004857
TotalMilliseconds : 2400,4857

DanielLarsenNZ commented 4 years ago

I don't think this is a WSL issue, I think this is an az CLI issue. I am observing differences in performance when comparing az CLI to PowerShell AZ. Why would az CLI commands run slower than PowerShell AZ?

My script and an example observation below. Note that I am in New Zealand connecting to Australia East. I expect some latency, but I don't expect difference in performance between CLI and PowerShell. The interesting result for me is the difference between az group show (2,931 ms) and Get-AzResourceGroup (741 ms).

DanielLarsenNZ/examples/blob/master/Scripts/Utilities/az-cli-vs-ps.ps1

Tue, 17 Mar 2020 20:44:50 GMT
azure-cli                          2.2.0

command-modules-nspkg              2.0.3
core                               2.2.0
nspkg                              3.0.4
telemetry                          1.0.4

Extensions:
application-insights               0.1.1
front-door                         0.1.8
interactive                        0.4.3
storage-preview                    0.2.7

Python location 'C:\Program Files (x86)\Microsoft SDKs\Azure\CLI2\python.exe'
Extensions directory 'C:\Users\dalars\.azure\cliextensions'

Python (Windows) 3.6.6 (v3.6.6:4cf1f54eb7, Jun 27 2018, 02:47:15) [MSC v.1900 32 bit (Intel)]

Legal docs and information: aka.ms/AzureCliLegal

Your CLI is up-to-date.

Please let us know how we are doing: https://aka.ms/clihats

Name                           Value
----                           -----
PSVersion                      7.0.0
PSEdition                      Core
GitCommitId                    7.0.0
OS                             Microsoft Windows 10.0.18363
Platform                       Win32NT
PSCompatibleVersions           {1.0, 2.0, 3.0, 4.0…}
PSRemotingProtocolVersion      2.3
SerializationVersion           1.1.0.1
WSManStackVersion              3.0

az group create

Ticks             : 82722758
Days              : 0
Hours             : 0
Milliseconds      : 272
Minutes           : 0
Seconds           : 8
TotalDays         : 9.57439328703704E-05
TotalHours        : 0.00229785438888889
TotalMilliseconds : 8272.2758
TotalMinutes      : 0.137871263333333
TotalSeconds      : 8.2722758

New-AzResourceGroup
VERBOSE: Performing the operation "Replacing resource group ..." on target "test2-rg".
VERBOSE: 9:45:05 am - Created resource group 'test2-rg' in location 'australiaeast'

Ticks             : 15474831
Days              : 0
Hours             : 0
Milliseconds      : 547
Minutes           : 0
Seconds           : 1
TotalDays         : 1.79106840277778E-05
TotalHours        : 0.000429856416666667
TotalMilliseconds : 1547.4831
TotalMinutes      : 0.025791385
TotalSeconds      : 1.5474831

az group show

Ticks             : 29305181
Days              : 0
Hours             : 0
Milliseconds      : 930
Minutes           : 0
Seconds           : 2
TotalDays         : 3.39180335648148E-05
TotalHours        : 0.000814032805555556
TotalMilliseconds : 2930.5181
TotalMinutes      : 0.0488419683333333
TotalSeconds      : 2.9305181

Get-AzResourceGroup

Ticks             : 7408608
Days              : 0
Hours             : 0
Milliseconds      : 740
Minutes           : 0
Seconds           : 0
TotalDays         : 8.57477777777778E-06
TotalHours        : 0.000205794666666667
TotalMilliseconds : 740.8608
TotalMinutes      : 0.01234768
TotalSeconds      : 0.7408608

az group delete

Ticks             : 495528816
Days              : 0
Hours             : 0
Milliseconds      : 552
Minutes           : 0
Seconds           : 49
TotalDays         : 0.000573528722222222
TotalHours        : 0.0137646893333333
TotalMilliseconds : 49552.8816
TotalMinutes      : 0.82588136
TotalSeconds      : 49.5528816

Remove-AzResourceGroup
VERBOSE: Performing the operation "Removing resource group ..." on target "test2-rg".

Ticks             : 475125652
Days              : 0
Hours             : 0
Milliseconds      : 512
Minutes           : 0
Seconds           : 47
TotalDays         : 0.000549913949074074
TotalHours        : 0.0131979347777778
TotalMilliseconds : 47512.5652
TotalMinutes      : 0.791876086666667
TotalSeconds      : 47.5125652

fbarresi commented 3 years ago

In newer version of az CLI still not getting better. Almost 4 seconds for getting version number.

PS > az --version
azure-cli                          2.9.1

command-modules-nspkg              2.0.3
core                               2.9.1
nspkg                              3.0.4
telemetry                          1.0.4

Extensions:
azure-iot                          0.9.2

Python location 'C:\Program Files (x86)\Microsoft SDKs\Azure\CLI2\python.exe'
Extensions directory 'C:\Users\federico.barresi\.azure\cliextensions'

Python (Windows) 3.6.6 (v3.6.6:4cf1f54eb7, Jun 27 2018, 02:47:15) [MSC v.1900 32 bit (Intel)]

Legal docs and information: aka.ms/AzureCliLegal

Your CLI is up-to-date.

Please let us know how we are doing: https://aka.ms/azureclihats
and let us know if you're interested in trying out our newest features: https://aka.ms/CLIUXstudy

PS > Measure-Command {az --version}

Days              : 0
Hours             : 0
Minutes           : 0
Seconds           : 3
Milliseconds      : 878
Ticks             : 38785149
TotalDays         : 4,489021875E-05
TotalHours        : 0,00107736525
TotalMinutes      : 0,064641915
TotalSeconds      : 3,8785149
TotalMilliseconds : 3878,5149

jiasli commented 3 years ago

az --version has a network request to PyPI to check if there are any updates:

https://github.com/Azure/azure-cli/blob/dd24e800fee710567ba35ac0cffde3fb4057aa7f/src/azure-cli-core/azure/cli/core/util.py#L154-L155

Could you try az version instead? It doesn't trigger the network request.

We have added a new mechanism called Command Index to boost the performance (https://github.com/Azure/azure-cli/pull/13294).

With the released version, I got:

> Measure-Command {az version}

Days              : 0
Hours             : 0
Minutes           : 0
Seconds           : 0
Milliseconds      : 935
Ticks             : 9352923
TotalDays         : 1.08251423611111E-05
TotalHours        : 0.000259803416666667
TotalMinutes      : 0.015588205
TotalSeconds      : 0.9352923
TotalMilliseconds : 935.2923

fbarresi commented 3 years ago

Hi! Thank you for your quick reply. You're right, this other command works faster.

Do you know some other performance tricks for those cases?

PS > Measure-Command {az iot hub list}

Days              : 0
Hours             : 0
Minutes           : 0
Seconds           : 5
Milliseconds      : 156
Ticks             : 51563711
TotalDays         : 5,96802210648148E-05
TotalHours        : 0,00143232530555556
TotalMinutes      : 0,0859395183333333
TotalSeconds      : 5,1563711
TotalMilliseconds : 5156,3711

PS > measure-command {az iot hub module-identity list --device-id MyFancyDevice--hub-name MyFancyHub}

Days              : 0
Hours             : 0
Minutes           : 0
Seconds           : 3
Milliseconds      : 789
Ticks             : 37891935
TotalDays         : 4,385640625E-05
TotalHours        : 0,00105255375
TotalMinutes      : 0,063153225
TotalSeconds      : 3,7891935
TotalMilliseconds : 3789,1935

I would like to integrate such ps call in an application, but it's going to be too much laggy for a comfortable user experience.

jiasli commented 3 years ago

I think the latency is caused by the service-side, and this is really something out of Azure CLI's control. We plan to add some metrics in Azure CLI to measure the E2E latency of network transactions.

BTW, what is the result when you run Measure-Command {az version}?

fbarresi commented 3 years ago

My result is a bit better than az --version, but still upsetting...

Here the result in a fresh PS two times in short distance.

PS > Measure-Command {az version}

Days              : 0
Hours             : 0
Minutes           : 0
Seconds           : 2
Milliseconds      : 776
Ticks             : 27767078
TotalDays         : 3,21378217592593E-05
TotalHours        : 0,000771307722222222
TotalMinutes      : 0,0462784633333333
TotalSeconds      : 2,7767078
TotalMilliseconds : 2776,7078

PS > Measure-Command {az version}

Days              : 0
Hours             : 0
Minutes           : 0
Seconds           : 1
Milliseconds      : 27
Ticks             : 10277306
TotalDays         : 1,18950300925926E-05
TotalHours        : 0,000285480722222222
TotalMinutes      : 0,0171288433333333
TotalSeconds      : 1,0277306
TotalMilliseconds : 1027,7306

gtirloni commented 3 years ago

Timings from Linux 5.7.14 and Python 3.8:

$ time az --version >/dev/null
real    0m2.859s
user    0m1.411s
sys 0m0.152s

$ time az help >/dev/null
real    0m1.578s
user    0m1.459s
sys 0m0.107s

$ time az vm list-sizes -l eastus2 > /dev/null
real    0m2.674s
user    0m1.960s
sys 0m0.125s

It's much faster when running with Python 3.6 (edit /usr/bin/az and point it to python3.6 interpreter):

$ time az --version >/dev/null
real    0m1.996s
user    0m0.741s
sys 0m0.081s

$ time az help >/dev/null
real    0m0.899s
user    0m0.809s
sys 0m0.059s

$ time az vm list-sizes -l eastus2 > /dev/null
real    0m1.354s
user    0m0.731s
sys 0m0.073s

Disabling telemetry has no impact here.

sharma-abhay commented 3 years ago

Hi,

I'm from Australia SouthEast and am using az devops to interact with Azure DevOps instance (Australia East). Currently have 11 projects in my SandPit instance and here's how long it takes to list the projects.

PS> Measure-Command { az devops project list --org https://dev.azure.com/XXXXXX/ | Out-Default }

Days              : 0
Hours             : 0
Minutes           : 0
Seconds           : 49
Milliseconds      : 171
Ticks             : 491718208
TotalDays         : 0.000569118296296296
TotalHours        : 0.0136588391111111
TotalMinutes      : 0.819530346666667
TotalSeconds      : 49.1718208
TotalMilliseconds : 49171.8208

taksan commented 3 years ago

I'm facing the same issue running on linux

zsh$ time az devops project list

az devops project list  1,43s user 0,07s system 14% cpu 10,313 total

Sometime it takes up to 50s to perform the commands

yungezz commented 3 years ago

I'm facing the same issue running on linux
zsh$ time az devops project list

az devops project list  1,43s user 0,07s system 14% cpu 10,313 total
Sometime it takes up to 50s to perform the commands

route to appropriate team to help look at az devops command performance

ghost commented 3 years ago

Thanks for the feedback! We are routing this to the appropriate team for follow-up. cc @narula0781, @ashishonce, @romil07.

Issue Details

**Describe the bug** It's not exactly a bug but every command at PowerShell or Bash in WSL is too slow, I know that every command is making a web-api request call but is really sad this api call is causing too much delay. I don't know if I am at Brazil and the all api calls is from US and those internet latence is the cause but is really bad. **To Reproduce** Stay at Brazil and call a single command like `az acr list`. **Expected behavior** I don't know, but some loading indicator or proxy all api request call near Brazil... **Environment summary** Windows 10 with PowerShell and WSL ``` λ az --version azure-cli (2.0.46) acr (2.1.5) acs (2.3.4) advisor (0.6.0) ams (0.2.3) appservice (0.2.4) backup (1.2.1) batch (3.4.0) batchai (0.4.3) billing (0.2.0) botservice (0.1.1) cdn (0.1.1) cloud (2.1.0) cognitiveservices (0.2.3) command-modules-nspkg (2.0.2) configure (2.0.18) consumption (0.4.0) container (0.3.4) core (2.0.46) cosmosdb (0.2.1) dla (0.2.3) dls (0.1.3) dms (0.1.1) eventgrid (0.2.0) eventhubs (0.2.4) extension (0.2.1) feedback (2.1.4) find (0.2.12) interactive (0.3.30) iot (0.3.2) iotcentral (0.1.2) keyvault (2.2.3) lab (0.1.1) maps (0.3.2) monitor (0.2.3) network (2.2.5) nspkg (3.0.3) policyinsights (0.1.0) profile (2.1.1) rdbms (0.3.2) redis (0.3.2) relay (0.1.2) reservations (0.4.0) resource (2.1.4) role (2.1.5) search (0.1.1) servicebus (0.2.3) servicefabric (0.1.3) signalr (1.0.0) sql (2.1.4) storage (2.2.2) telemetry (1.0.0) vm (2.2.3) Python location 'C:\Program Files (x86)\Microsoft SDKs\Azure\CLI2\python.exe' Extensions directory 'C:\Users\alexs\.azure\cliextensions' Python (Windows) 3.6.5 (v3.6.5:f59c0932b4, Mar 28 2018, 16:07:46) [MSC v.1900 32 bit (Intel)] Legal docs and information: aka.ms/AzureCliLegal ``` **Additional context** Every was slow here at Brazil, I don't know if it is slow in another region, I'm posting it right now because I'm starting use Azure CLI constantly and I wish a better user experience. Thank's!

Author:	alexsandro-xpt
Assignees:	fengzhou-msft
Labels:	`DevOps`, `Performance`, `Service Attention`, `customer-reported`, `feature-request`
Milestone:	Backlog

PushkarVaity commented 3 years ago

Hi,

I am running some az-cli commands that are taking forever to complete. My python script logs the user in ADO by: cat ~/.ssh/ado.pat | az devops login;

Following are the commands that are a part of my script and get called multiple times in a loop: az repos list --org https://dev.azure.com/my-org/ --project my_project --query ‘[*].name’; az repos show --org https://dev.azure.com/my-org/ --project my_project --repository my_repo–query ‘sshUrl’; az repos ref list --org https://dev.azure.com/my-org/ --project my_project --repository my_repo–query ‘[*].{Name: name, ObjectId: objectId}’ --filter heads/

These commands have variable execution times when I timed my script: Mostly, these take 1 - 1.5 seconds each as expected. But randomly, all 3 commands also take 100+ seconds each causing the total run time to go through the roof. Is this a known problem and can someone help debug this? I am not able to figure out what is causing this issue.

This is on CentOS 7 machines % az --version azure-cli 2.18.0 *

core 2.18.0 * telemetry 1.0.6

Extensions: azure-devops 0.18.0

MaisaDaoud commented 3 years ago

same here in NZ, azure shell and the portal shell are too slow.

jiasli commented 3 years ago

@PushkarVaity,

But randomly, all 3 commands also take 100+ seconds each causing the total run time to go through the roof.

The delay should be caused by azure-devops service issue. Investigating in https://github.com/Azure/azure-cli/issues/17490.

jiasli commented 3 years ago

@MaisaDaoud, please see my comment at https://github.com/Azure/azure-cli/issues/7447#issuecomment-666058032.

A client-side command now only takes 400ms on Windows:

> Measure-Command {az version}
TotalMilliseconds : 444.3177

Please share the command you used and open a new issue for us to investigate. Thanks.

MaisaDaoud commented 3 years ago

time az --version real 0m1.039s user 0m0.328s sys 0m0.060s

time kubect get nodes real 0m5.654s user 0m0.086s sys 0m0.026s

DanielLarsenNZ commented 3 years ago

Re-running my test az-cli-vs-ps.ps1

> .\az-cli-vs-ps.ps1
Mon, 29 Mar 2021 08:38:42 GMT

azure-cli                         2.21.0
core                              2.21.0
telemetry                          1.0.6
Extensions:
application-insights              0.1.13
front-door                        1.0.11
interactive                        0.4.4
storage-preview                    0.7.0

Python location 'C:\Program Files (x86)\Microsoft SDKs\Azure\CLI2\python.exe'
Extensions directory 'C:\Users\dalars\.azure\cliextensions'

Python (Windows) 3.6.8 (tags/v3.6.8:3c6b436a57, Dec 23 2018, 23:31:17) [MSC v.1916 32 bit (Intel)]

Name                           Value
----                           -----
PSVersion                      7.0.2
PSEdition                      Core
GitCommitId                    7.0.2
OS                             Microsoft Windows 10.0.19042
Platform                       Win32NT
PSCompatibleVersions           {1.0, 2.0, 3.0, 4.0…}
PSRemotingProtocolVersion      2.3
SerializationVersion           1.1.0.1
WSManStackVersion              3.0

CliCommand                                                 CliSeconds PSCommand                                                                 PSSeconds
----------                                                 ---------- ---------                                                                 ---------
 az --version                                               1.2784802  $PSVersionTable                                                          0.0022685
 az group create -n 'test1-rg' --location 'australiaeast'   1.4451656  New-AzResourceGroup -Name 'test2-rg' -Location 'Australia East' -Force   1.2809508
 az group show -n 'test1-rg'                                1.3791062  Get-AzResourceGroup -Name 'test2-rg'                                     0.9544952
 az group delete -n 'test1-rg' --yes                       46.5991574  Remove-AzResourceGroup -Name 'test2-rg' -Force                          46.4704706

PowerShell is still faster, but AZ CLI performance is much better compared to one year ago. Thanks team! 🎉

jiasli commented 3 years ago

@MaisaDaoud, how is the performance of az version without --?

Mossaka commented 3 years ago

Why is this issue being closed? I don't see any improvements over the performance of the az cli commands. Can we leave this open until the perf issue is really getting resolved?

yonzhan commented 3 years ago

@Mossaka please help send out detailed info related to which command you see the performance issue.

jiasli commented 3 years ago

Why is this issue being closed?

With the introduction of Command Index (#13294) and migration to PEP 420 (#14372), the client-side execution speed of Azure CLI has been significantly improved. That's why we closed this issue.

If the Azure CLI command involves Azure REST API invocation, Azure CLI will spend most of its time communicating with Azure REST API and do long-running operation query, which is out of our control. In such case, those changes won't give you too much performance improvement.

Please share the command as @yonzhan asked. Thanks.

rdsserrao commented 2 years ago

The performance issue seems to be happening again:

I'm from Portugal by the way.

jiasli commented 2 years ago

It seems with setuptools 62.6.0 installed, disutils imports setuptools and pkg_resources. This causes some performance regression:

& "C:\Program Files (x86)\Microsoft SDKs\Azure\CLI2\python.exe" -m pip list
setuptools             62.6.0

& "C:\Program Files (x86)\Microsoft SDKs\Azure\CLI2\python.exe" -X importtime -m azure.cli version 2>perf.log; python -m tuna .\perf.log

rdsserrao commented 2 years ago

@jiasli thanks for opening this case. Hope it will improve user experience.

Porges commented 1 year ago

If anything this is worse than ever with 2.45.0:

> measure-command { az version }

Days              : 0
Hours             : 0
Minutes           : 0
Seconds           : 3
Milliseconds      : 202
Ticks             : 32024121
TotalDays         : 3.70649548611111E-05
TotalHours        : 0.000889558916666667
TotalMinutes      : 0.053373535
TotalSeconds      : 3.2024121
TotalMilliseconds : 3202.4121

jasonrberk commented 1 year ago

the following pipeline task took 1 minute and 47 seconds!!!!!

- bash: echo "##vso[task.setvariable variable=pipelineId]$(az pipelines runs show --id ${{ parameters.buildId }} --query "definition.id" -o tsv)"

why on earth does that take so long to run????

jessehouwing commented 10 months ago

the following pipeline task took 1 minute and 47 seconds!!!!!
- bash: echo "##vso[task.setvariable variable=pipelineId]$(az pipelines runs show --id ${{ parameters.buildId }} --query "definition.id" -o tsv)"
why on earth does that take so long to run????

az devops speeds up quite a bit by explicitly passing --org and --project, the auto-detect routine eats up quite a bit of time. But the performance is terrible compared to a plain powershell rest-api call especially on the first call on Windows.

The second run only takes .7 seconds.

$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)

It seems Bash@3: is about 50% faster than relying on pwsh: on the first call. All subsequent calls are much faster.

ubuntu-latest is much faster, finishing the exact same commands in under 4 seconds on the first call:

INFO: received PAT from environment variable
INFO: Creating connection with personal access token.
INFO: Command ran in 3.499 seconds (init: 0.724, invoke: 2.776)

INFO: received PAT from environment variable
INFO: Creating connection with personal access token.
INFO: Command ran in 0.805 seconds (init: 0.190, invoke: 0.615)

Pipeline YAML used:

pool:
  vmImage: windows-latest

variables:
  "system.debug": true

steps:
- task: Bash@3
  inputs:
    targetType: 'inline'
    script: |
      az pipelines runs show --id $BUILD_BUILDID --query "definition.id" --verbose --organization $SYSTEM_COLLECTIONURI --project $SYSTEM_TEAMPROJECT
  env:
    AZURE_DEVOPS_EXT_PAT: $(System.AccessToken)

- pwsh: |
      & 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)

Forcing a few settings off works shaving off 50 or so seconds:

- script: |
   c:
   cd %USERPROFILE%
   md .azure 
   cd .azure
   echo [core] > config
   echo first_run = True >> config
   echo collect_telemetry = False >> config

   echo [auto-upgrade] >> config
   echo enable = False >> config

I had to overwrite these settings from a CLI, cause using az config set the first time will hit the same perf issue.

After running the above config code, the perf vastly improves, though first run is still slower:

INFO: received PAT from environment variable
INFO: Creating connection with personal access token.
INFO: Command ran in 36.510 seconds (init: 7.991, invoke: 28.519)

INFO: received PAT from environment variable
INFO: Creating connection with personal access token.
INFO: Command ran in 0.871 seconds (init: 0.381, invoke: 0.490)

64J0 commented 5 months ago

Performance is pretty bad. Not even the login is working properly.

Obs.: I killed this process manually since it's taking forever to finish, and there is no log detailing why it's so slow.

With --debug I noticed that it's stopping here:

Azure / azure-cli

WSL: Why Azure CLI is too slow at each command execution? #7447

time az --version real 0m1.039s user 0m0.328s sys 0m0.060s