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

[alexsandro-xpt]

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]

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

[alexsandro-xpt]

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

[troydai]

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

[alexsandro-xpt]

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

[andreacassioli]

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.

[NickSuperb]

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]

@NickSuperb Are you run it from Brazil too?

[sasacocic]

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]

Same here, I'm in Paris, France

[gstolz]

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]

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]

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]

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

[andreacassioli]

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

[silkfire]

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

[andreacassioli]

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

[yonzhan]

add to S164.

[CoderKooke]

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]

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

[CoderKooke]

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, [e-mail] 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]

@fengzhou-msft please take a look also.

[gewoonwoutje]

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]

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]

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]

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]

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]

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]

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]

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]

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]

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]

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

[msftbot[bot]]

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