az repos take 100+ seconds to run

[jiasli]

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

Originally posted by @PushkarVaity in #7447 (comment)

[ghost]

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

Issue Details

---

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

Originally posted by @PushkarVaity in #7447 (comment)

Author:	jiasli
Assignees:	-
Labels:	DevOps, Service Attention, needs-triage
Milestone:	-

[yonzhan]

route to service team to take a look

[greghenderson]

I have this same issue intermittently, probably every 2 to 3 weeks... is happening right now since noticing it early this morning.

Will start adding to this ticket per occurrence.

Here are a couple of timed commands for reference, run at about 12:10pm US eastern time 2021-Aug-25.

$ time az pipelines list
This command is in preview and under development. Reference and support levels: https://aka.ms/CLI_refstatus
[
… JSON cut for brevity…
]

real 3m50.184s
user 0m0.983s
sys 0m0.248s

$ time az devops user list
This command is in preview and under development. Reference and support levels: https://aka.ms/CLI_refstatus
{
… JSON cut for brevity…
}

real 3m51.281s
user 0m1.048s
sys 0m0.268s

As of 4:17pm, still have the same painful performance.

[greghenderson]

Encountering this issue again, over 9 minutes this time.... Here's a sample timing:

$ time az pipelines list
This command is in preview and under development. Reference and support levels: https://aka.ms/CLI_refstatus
[]

real 9m6.522s
user 0m1.063s
sys 0m0.318s

[greghenderson]

Another day, another slow access to az devops related commands:

$ time az pipelines list
This command is in preview and under development. Reference and support levels: https://aka.ms/CLI_refstatus
[]

real 3m49.625s
user 0m0.913s
sys 0m0.288s

Also noted a 5m10s run in my terminal from a couple days ago that I forgot to add here.

[greghenderson]

Nowadays this issue seems to be the norm when I reach for the az devops tools.

$ time az pipelines list
This command is in preview and under development. Reference and support levels: https://aka.ms/CLI_refstatus
[
...
]

real 5m18.021s
user 0m0.925s
sys 0m0.268s

[greghenderson]

Found at least a partial cause of my az devops command woes.

After examining the debug logs for a typical 5+ minute "az pipelines list" call, saw a line that was puzzling:

84736 : 2021-09-15 16:16:04,796 : DEBUG : cli.azext_devops.dev.common.services : trying to get token (temp) for tenant e49ea3fe-87f8-44df-a7ba-2131f4fb91f1 and user [email protected]

There were various token related exceptions following this.

Notice my fake greg.henderson address? Well at the time I was not logged in via "az login" with that personal credential, but with a different admin credential. Also the devops PAT in use was created by the admin cred, not by the personal greg.henderson cred. Definitely some mismatch there...

Tried some combinations of az logout, login, devops login, etc.... with no effect.

So I cleared the ~/.azure/accessTokens.json and ~/.azure/azureProfile.json files and tried the "az pipelines list" again.... Some improvement at least, no various token exceptions and the command only took 2.5 minutes. Still really slow, but at least some improvement. My guess is that I've been hitting 2 different bugs and worked around one of them, with the remaining slowness on the server side.

For reference:
$ az version
{
"azure-cli": "2.28.0",
"azure-cli-core": "2.28.0",
"azure-cli-telemetry": "1.0.6",
"extensions": {
"application-insights": "0.1.13",
"azure-devops": "0.20.0",
"front-door": "1.0.16"
}
}

I've got logging turned on in case the logs might be helpful for some nice dev person....

[froblesmartin]

I am facing the same issue. It was working some weeks ago really fast (less than 5 seconds) and not it is taken >2 mins.

I have also tried doing az logout + az login, cleaned up the azureProfile.json and msal_token_cache.json files, but still facing the same issue.

As @greghenderson, I am also switching from time to time between an "admin" account and my "personal" account.

[greghenderson]

Just for follow-up, I continue to encounter the issue in my MacOS environment. So I don't use that for az devops interaction any more... use WSL Ubuntu in Windows 11 for that. No issues there.