Azure CLI is slow to start on first instantiation
- Dominant language
- Python
- Stars
- 4.6k
- Forks
- 3.5k
- Avg merge
- 3d 2h
- Merged PRs (30d)
- 60
Description
### Describe the bug
It looks like when the Azure CLI starts for the first time on Linux based Github Actions runners (could be the case elsewhere too?). It loads *all* command modules by default, which can take considerable time on a system that hasn't done it before.
While this is only on the version command, this impacts other commands such as `az login`, and `az acr login` which can substantially slow down CI pipelines in Github Actions (and other CI platforms likely too?).
-----------------
Is it possible to make the `Discovered command modules:` / `Loading command modules:` logic either just-in-time and/or configurable which modules to load, as a means of speeding up startup?
I can see references to `BLOCKED_MODS` in the source code already, but that's a hardcoded list at the moment.
Curious, is this `Loading command modules:` done into RAM or cached to disk? If its cached to disk, this might be solveable using https://github.com/actions/cache to cache the loaded state and restore it...
### Related command
`az version --debug` (same duration outcomes without `--debug`, it just hangs for a while before outputting)
### Errors
First run, commands executed:
```
date
az version --debug
date
```
This allows seeing the elapsed time between start and end clearly.
Output:
```
Thu May 22 20:36:56 UTC 2025
DEBUG: cli.knack.cli: Command arguments: ['version', '--debug']
DEBUG: cli.knack.cli: __init__ debug log:
Cannot enable color.
DEBUG: cli.knack.cli: Event: Cli.PreExecute []
DEBUG: cli.knack.cli: Event: CommandParser.OnGlobalArgumentsCreate [, , ]
DEBUG: cli.knack.cli: Event: CommandInvoker.OnPreCommandTableCreate []
DEBUG: cli.azure.cli.core: Command index version or cloud profile is invalid or doesn't match the current command.
DEBUG: cli.azure.cli.core: Command index has been invalidated.
DEBUG: cli.azure.cli.core: No module found from index for '['version', '--debug']'
DEBUG: cli.azure.cli.core: Loading all modules and extensions
DEBUG: cli.azure.cli.core: Discovered command modules: ['acr', 'acs', 'advisor', 'ams', 'apim', 'appconfig', 'appservice', 'aro', 'backup', 'batch', 'batchai', 'billing', 'botservice', 'cdn', 'cloud', 'cognitiveservices', 'compute_recommender', 'computefleet', 'config', 'configure', 'consumption', 'container', 'containerapp', 'cosmosdb', 'databoxedge', 'dls', 'dms', 'eventgrid', 'eventhubs', 'extension', 'feedback', 'find', 'hdinsight', 'identity', 'interactive', 'iot', 'keyvault', 'lab', 'managedservices', 'maps', 'marketplaceordering', 'monitor', 'mysql', 'netappfiles', 'network', 'policyinsights', 'privatedns', 'profile', 'rdbms', 'redis', 'relay', 'resource', 'role', 'search', 'security', 'servicebus', 'serviceconnector', 'servicefabric', 'signalr', 'sql', 'sqlvm', 'storage', 'synapse', 'util', 'vm']
DEBUG: cli.azure.cli.core: Loading command modules:
DEBUG: cli.azure.cli.core: Name Load Time Groups Commands
DEBUG: cli.azure.cli.core: acr 1.009 36 149
DEBUG: cli.azure.cli.core: acs 0.341 15 79
DEBUG: cli.azure.cli.core: advisor 0.026 3 6
DEBUG: cli.azure.cli.core: ams 0.034 22 100
DEBUG: cli.azure.cli.core: apim 0.055 14 69
DEBUG: cli.azure.cli.core: appconfig 0.041 9 47
DEBUG: cli.azure.cli.core: appservice 0.540 [8](https://github.com/REDACTED/test-actions-runner-vnet/actions/runs/REDACTED/job/REDACTED#step:2:9)0 277
DEBUG: cli.azure.cli.core: aro 0.15[9](https://github.com/REDACTED/test-actions-runner-vnet/actions/runs/REDACTED/job/REDACTED#step:2:10) 1 10
DEBUG: cli.azure.cli.core: backup 0.028 16 60
DEBUG: cli.azure.cli.core: batch 0.295 32 96
DEBUG: cli.azure.cli.core: batchai 0.027 [10](https://github.com/REDACTED/test-actions-runner-vnet/actions/runs/REDACTED/job/REDACTED#step:2:11) 30
DEBUG: cli.azure.cli.core: billing 0.182 20 53
DEBUG: cli.azure.cli.core: botservice 0.058 12 42
DEBUG: cli.azure.cli.core: cdn 1.557 8 50
DEBUG: cli.azure.cli.core: cloud 0.028 1 7
DEBUG: cli.azure.cli.core: cognitiveservices 0.018 10 33
DEBUG: cli.azure.cli.core: compute_recommender 0.028 1 1
DEBUG: cli.azure.cli.core: computefleet 0.103 1 1
DEBUG: cli.azure.cli.core: config 0.063 2 7
DEBUG: cli.azure.cli.core: configure 0.034 2 5
DEBUG: cli.azure.cli.core: consumption 0.340 8 9
DEBUG: cli.azure.cli.core: container 0.[11](https://github.com/REDACTED/test-actions-runner-vnet/actions/runs/REDACTED/job/REDACTED#step:2:12)8 2 17
DEBUG: cli.azure.cli.core: containerapp 1.594 37 123
DEBUG: cli.azure.cli.core: cosmosdb 0.081 58 200
DEBUG: cli.azure.cli.core: databoxedge 0.104 5 28
DEBUG: cli.azure.cli.core: dls 0.016 6 36
DEBUG: cli.azure.cli.core: dms 0.015 3 22
DEBUG: cli.azure.cli.core: eventgrid 0.049 25 96
DEBUG: cli.azure.cli.core: eventhubs 0.216 13 20
DEBUG: cli.azure.cli.core: extension 0.014 1 7
DEBUG: cli.azure.cli.core: feedback 0.001 1 2
DEBUG: cli.azure.cli.core: find 0.015 1 1
DEBUG: cli.azure.cli.core: hdinsight 0.085 9 42
DEBUG: cli.azure.cli.core: identity 0.015 2 11
DEBUG: cli.azure.cli.core: interactive 0.015 1 1
DEBUG: cli.azure.cli.core: iot 1.496 19 82
DEBUG: cli.azure.cli.core: keyvault 0.058 20 113
DEBUG: cli.azure.cli.core: lab 0.490 9 30
DEBUG: cli.azure.cli.core: managedservices 0.074 3 8
DEBUG: cli.azure.cli.core: maps 0.026 5 13
DEBUG: cli.azure.cli.core: marketplaceordering 0.028 1 2
DEBUG: cli.azure.cli.core: monitor 7.248 18 61
DEBUG: cli.azure.cli.core: mysql 0.978 16 56
DEBUG: cli.azure.cli.core: netappfiles 0.448 8 17
DEBUG: cli.azure.cli.core: network 1.846 104 345
DEBUG: cli.azure.cli.core: policyinsights 0.[12](https://github.com/REDACTED/test-actions-runner-vnet/actions/runs/REDACTED/job/REDACTED#step:2:13)5 9 17
DEBUG: cli.azure.cli.core: privatedns 0.156 14 60
DEBUG: cli.azure.cli.core: profile 0.014 2 8
DEBUG: cli.azure.cli.core: rdbms 0.943 53 223
DEBUG: cli.azure.cli.core: redis 0.048 7 38
DEBUG: cli.azure.cli.core: relay 0.545 7 8
DEBUG: cli.azure.cli.core: resource 0.103 52 232
DEBUG: cli.azure.cli.core: role 0.015 17 62
DEBUG: cli.azure.cli.core: search 0.060 7 19
DEBUG: cli.azure.cli.core: security 0.[13](https://github.com/REDACTED/test-actions-runner-vnet/actions/runs/REDACTED/job/REDACTED#step:2:14)9 47 98
DEBUG: cli.azure.cli.core: servicebus 0.200 13 17
DEBUG: cli.azure.cli.core: serviceconnector 0.178 20 323
DEBUG: cli.azure.cli.core: servicefabric 0.155 27 80
DEBUG: cli.azure.cli.core: signalr 0.015 10 42
DEBUG: cli.azure.cli.core: sql 0.121 56 215
DEBUG: cli.azure.cli.core: sqlvm 0.430 4 20
DEBUG: cli.azure.cli.core: storage 0.255 60 275
DEBUG: cli.azure.cli.core: synapse 0.097 54 246
DEBUG: cli.azure.cli.core: util 0.0[14](https://github.com/REDACTED/test-actions-runner-vnet/actions/runs/REDACTED/job/REDACTED#step:2:15) 3 7
DEBUG: cli.azure.cli.core: vm 1.631 59 217
DEBUG: cli.azure.cli.core: Total (65) 25.238 1191 4671
DEBUG: cli.azure.cli.core: Loading extensions:
DEBUG: cli.azure.cli.core: Name Load Time Groups Commands Directory
DEBUG: cli.azure.cli.core: azure-devops 0.667 60 192 /opt/az/azcliextensions/azure-devops
DEBUG: cli.azure.cli.core: Total (1) 0.667 60 192
DEBUG: cli.azure.cli.core: Loaded 1237 groups, 4863 commands.
DEBUG: cli.azure.cli.core: Updated command index in 0.003 seconds.
DEBUG: cli.knack.cli: Event: CommandInvoker.OnPreCommandTableTruncate []
DEBUG: cli.azure.cli.core.azlogging: metadata file logging enabled - writing logs to '/home/runner/.azure/commands/2025-05-22.20-37-29.version.2021.log'.
INFO: az_command_data_logger: command args: version --debug
DEBUG: cli.knack.cli: Event: CommandInvoker.OnPreArgumentLoad [.add_subscription_parameter at 0x7fc7f01a39c0>]
DEBUG: cli.knack.cli: Event: CommandInvoker.OnPostArgumentLoad []
DEBUG: cli.knack.cli: Event: CommandInvoker.OnPostCommandTableCreate [.add_ids_arguments at 0x7fc7f01a3a60>, .add_cache_arguments at 0x7fc7f01a3ba0>, .update_breaking_change_info at 0x7fc7f01a3c40>]
DEBUG: cli.knack.cli: Event: CommandInvoker.OnCommandTableLoaded []
DEBUG: cli.knack.cli: Event: CommandInvoker.OnPreParseArgs []
DEBUG: cli.knack.cli: Event: CommandInvoker.OnPostParseArgs [, , .parse_ids_arguments at 0x7fc7f01a3b00>, ]
DEBUG: cli.knack.cli: Event: CommandInvoker.OnTransformResult [, ]
DEBUG: cli.knack.cli: Event: CommandInvoker.OnFilterResult []
DEBUG: cli.knack.cli: Event: Cli.SuccessfulExecute []
DEBUG: cli.knack.cli: Event: Cli.PostExecute []
INFO: az_command_data_logger: exit code: 0
INFO: cli.__main__: Command ran in 31.046 seconds (init: 4.449, invoke: 26.597)
DEBUG: cli.azure.cli.core._profile: Failed to load installationId from AzureRmSurvey.json. [Errno 2] No such file or directory: '/home/runner/.azure/AzureRmContextSettings.json'
INFO: telemetry.main: Begin splitting cli events and extra events, total events: 1
INFO: telemetry.client: Accumulated 0 events. Flush the clients.
INFO: telemetry.main: Finish splitting cli events and extra events, cli events: 1
INFO: telemetry.save: Save telemetry record of length 3674 in cache file under /home/runner/.azure/telemetry/[20](https://github.com/REDACTED/test-actions-runner-vnet/actions/runs/REDACTED/job/REDACTED#step:2:21)250522203729357
INFO: telemetry.main: Begin creating telemetry upload process.
INFO: telemetry.process: Creating upload process: "/opt/az/bin/python3 /opt/az/lib/python3.12/site-packages/azure/cli/telemetry/__init__.py /home/runner/.azure /home/runner/.azure/telemetry/202505[22](https://github.com/REDACTED/test-actions-runner-vnet/actions/runs/REDACTED/job/REDACTED#step:2:23)203729357"
INFO: telemetry.process: Return from creating process 2052
INFO: telemetry.main: Finish creating telemetry upload process.
{
"azure-cli": "2.72.0",
"azure-cli-core": "2.72.0",
"azure-cli-telemetry": "1.1.0",
"extensions": {
"azure-devops": "1.0.1"
}
}
Thu May 22 20:37:29 UTC
```
-------------------------------------------------
-------------------------------------------------
Second execution, second step in the same job (so same Github Actions runner VM under the hood):
```
Thu May 22 20:37:29 UTC 2025
DEBUG: cli.knack.cli: Command arguments: ['version', '--debug']
DEBUG: cli.knack.cli: __init__ debug log:
Cannot enable color.
DEBUG: cli.knack.cli: Event: Cli.PreExecute []
DEBUG: cli.knack.cli: Event: CommandParser.OnGlobalArgumentsCreate [, , ]
DEBUG: cli.knack.cli: Event: CommandInvoker.OnPreCommandTableCreate []
DEBUG: cli.azure.cli.core: Modules found from index for 'version': ['azure.cli.command_modules.util']
DEBUG: cli.azure.cli.core: Loading command modules:
DEBUG: cli.azure.cli.core: Name Load Time Groups Commands
DEBUG: cli.azure.cli.core: util 0.002 3 7
DEBUG: cli.azure.cli.core: Total (1) 0.002 3 7
DEBUG: cli.azure.cli.core: These extensions are not installed and will be skipped: ['azext_ai_examples', 'azext_next']
DEBUG: cli.azure.cli.core: Loading extensions:
DEBUG: cli.azure.cli.core: Name Load Time Groups Commands Directory
DEBUG: cli.azure.cli.core: Total (0) 0.000 0 0
DEBUG: cli.azure.cli.core: Loaded 3 groups, 7 commands.
DEBUG: cli.azure.cli.core: Found a match in the command table.
DEBUG: cli.azure.cli.core: Raw command : version
DEBUG: cli.azure.cli.core: Command table: version
DEBUG: cli.knack.cli: Event: CommandInvoker.OnPreCommandTableTruncate []
DEBUG: cli.azure.cli.core.azlogging: metadata file logging enabled - writing logs to '/home/runner/.azure/commands/2025-05-22.20-37-2[9](https://github.com/REDACTED/test-actions-runner-vnet/actions/runs/REDACTED/job/REDACTED#step:3:10).version.2059.log'.
INFO: az_command_data_logger: command args: version --debug
DEBUG: cli.knack.cli: Event: CommandInvoker.OnPreArgumentLoad [.add_subscription_parameter at 0x7f5931150860>]
DEBUG: cli.knack.cli: Event: CommandInvoker.OnPostArgumentLoad []
DEBUG: cli.knack.cli: Event: CommandInvoker.OnPostCommandTableCreate [.add_ids_arguments at 0x7f5931153060>, .add_cache_arguments at 0x7f59311531a0>, .update_breaking_change_info at 0x7f5931153240>]
DEBUG: cli.knack.cli: Event: CommandInvoker.OnCommandTableLoaded []
DEBUG: cli.knack.cli: Event: CommandInvoker.OnPreParseArgs []
DEBUG: cli.knack.cli: Event: CommandInvoker.OnPostParseArgs [, , .parse_ids_arguments at 0x7f5931153[10](https://github.com/REDACTED/test-actions-runner-vnet/actions/runs/REDACTED/job/REDACTED#step:3:11)0>]
DEBUG: cli.knack.cli: Event: CommandInvoker.OnTransformResult [, ]
DEBUG: cli.knack.cli: Event: CommandInvoker.OnFilterResult []
DEBUG: cli.knack.cli: Event: Cli.SuccessfulExecute []
DEBUG: cli.knack.cli: Event: Cli.PostExecute []
INFO: az_command_data_logger: exit code: 0
INFO: cli.__main__: Command ran in 0.[12](https://github.com/REDACTED/test-actions-runner-vnet/actions/runs/REDACTED/job/REDACTED#step:3:13)9 seconds (init: 0.119, invoke: 0.011)
INFO: telemetry.main: Begin splitting cli events and extra events, total events: 1
INFO: telemetry.client: Accumulated 0 events. Flush the clients.
INFO: telemetry.main: Finish splitting cli events and extra events, cli events: 1
INFO: telemetry.save: Save telemetry record of length 3673 in cache file under /home/runner/.azure/telemetry/20250522203729898
INFO: telemetry.main: Begin creating telemetry upload process.
INFO: telemetry.process: Creating upload process: "/opt/az/bin/python3 /opt/az/lib/python3.12/site-packages/azure/cli/telemetry/__init__.py /home/runner/.azure /home/runner/.azure/telemetry/[20](https://github.com/REDACTED/test-actions-runner-vnet/actions/runs/REDACTED/job/REDACTED#step:3:21)250522203729898"
INFO: telemetry.process: Return from creating process 2077
INFO: telemetry.main: Finish creating telemetry upload process.
{
"azure-cli": "2.72.0",
"azure-cli-core": "2.72.0",
"azure-cli-telemetry": "1.1.0",
"extensions": {
"azure-devops": "1.0.1"
}
}
Thu May 22 20:37:29 UTC 2025
```
### Issue script & Debug output
```
date
az version --debug
date
```
### Expected behavior
For `az` to start in under a second the first time its executed on a fresh VM/system/CI runner, at least to be able to perform `login` and/or `acr login` operations.
Intensive system resource operations can take longer of course if they exist...
### Environment Summary
Run az --version
WARNING: You have 2 update(s) available. Consider updating your CLI installation with 'az upgrade'
azure-cli 2.72.0 *
core 2.72.0 *
telemetry 1.1.0
Extensions:
azure-devops 1.0.1
Dependencies:
msal 1.32.3
azure-mgmt-resource 23.1.1
Python location '/opt/az/bin/python3'
Config directory '/home/runner/.azure'
Extensions directory '/opt/az/azcliextensions'
Python (Linux) 3.12.8 (main, Apr 28 2025, 09:2[4](https://github.com/REDACTED/test-actions-runner-vnet/actions/runs/REDACTED/job/REDACTED#step:2:5):33) [GCC 13.3.0]
Legal docs and information: aka.ms/AzureCliLegal
### Additional context
**NOTE: I'm using Hosted Compute Networking in Github Actions**, which does mean there's less "warm" VMs spooled up by Github, so runners tend to be spun up cold more often, and that makes this problem more visible. Github does not provide any control over that warm pool size, but that's unrelated to the root cause here - trying to get `az` calls to run fast from a "cold" started VM.
A related issue https://github.com/Azure/login/issues/527 which is what prompted me to raise this separately
Contributor guide
Assessment
This issue has not been assessed yet.