{Core} Build and use command index #13294

jiasli · 2020-05-01T18:49:36Z

Description

A command index is built and saved in file .azure/commandIndex.json. It contains a mapping from top-level commands / command group names to their command module namespaces.

Both built-in modules and extensions are included in the index:

{
    "version": "2.7.0",
    "cloudProfile": "latest",
    "commandIndex": {
        "acr": [
            "azure.cli.command_modules.acr"
        ],
        ...
        "network": [
            "azure.cli.command_modules.natgateway",
            "azure.cli.command_modules.network",
            "azure.cli.command_modules.privatedns"
        ],
        ...
        "sql": [
            "azure.cli.command_modules.sql",
            "azure.cli.command_modules.sqlvm"
        ],
        ...
        "timeseriesinsights": [
            "azext_timeseriesinsights"
        ]
    }
}

CLI checks if a command can be found from the index (either from built-in modules, extensions, or both):

✔ Yes, then only corresponding modules from the index are loaded. Then check if the loaded modules do have the command, in case of an outdated cache:
- ✔ Yes, continue parsing with only the loaded modules
- ❌ No, go to (*)
❌ (*) No, then all modules and extensions will be loaded and a new index will be built from the loaded command table

This significantly decreases the run time of commands, since unnecessary modules are not loaded anymore.

Together with other PRs, Azure CLI's run time are improved from 2.3s to 0.6s (az version, without the loading time of pkg_resources):

Fix built-in timer ({Misc} Fix timer for __main__.py #13844): Previous it only takes invoke duration into account, while forgetting about the init duration. The timing logic is fixed to include both init and invoke duration.
Delay unnecessary imports ({Core} Delay import #13843): Previously during CLI initialization, importing azure.core and msrestazure.tools are very time-consuming, but actually unnecessary. This PR delays the import until azure.core and msrestazure.tools are actually used.
Remove unnecessary imports of msrest: Follow EAFP (Easier to Ask for Forgiveness than Permission) style to remove unnecessary imports of msrest. Also see https://stackoverflow.com/a/11360880/2199657
Add util module for az rest and az version: ({Util} Add util module for version and rest #13783): Peel off az rest and az version from resource module. A new module util is created. Thus they don't carry the burden of mgmt SDK initialization, thus making them faster.

Testing Guide

Test with the built-in timer

First time run:

az version --debug

No module found from index for 'version'
Discovered command modules: ['acr', ... 'util', 'vm']
Loaded module 'acr' in 0.008 seconds.
...
Loaded module 'storage' in 0.059 seconds.
Loaded module 'util' in 0.004 seconds.
Loaded module 'vm' in 0.020 seconds.
Loaded all modules in 0.988 seconds. (note: there's always an overhead with the first module loaded)
Loading extensions: ['interactive', 'resource-graph', 'support', 'timeseriesinsights']
...
Extensions directory: 'D:\cli\azure-cli-extensions\src\timeseriesinsights'
Loaded extension 'timeseriesinsights' in 0.027 seconds.
Index updated: {'acr': ['azure.cli.command_modules.acr'], ... 'timeseriesinsights': ['azext_timeseriesinsights']}

Command ran in 2.007 seconds (init: 0.082, invoke: 1.926)

Second time run:

az version --debug

Modules found from index for 'version': ['azure.cli.command_modules.util']
Loading command modules: ['util']
Loaded module 'util' in 0.005 seconds.
Loaded all modules in 0.005 seconds. (note: there's always an overhead with the first module loaded)

Command ran in 0.283 seconds (init: 0.075, invoke: 0.208)

Test with PowerShell

Before:

> Measure-Command {az version}

Days              : 0
Hours             : 0
Minutes           : 0
Seconds           : 2
Milliseconds      : 343
Ticks             : 23430150
TotalDays         : 2.71182291666667E-05
TotalHours        : 0.0006508375
TotalMinutes      : 0.03905025
TotalSeconds      : 2.343015
TotalMilliseconds : 2343.015

After:

> Measure-Command {az version}

Days              : 0
Hours             : 0
Minutes           : 0
Seconds           : 0
Milliseconds      : 676
Ticks             : 6760268
TotalDays         : 7.82438425925926E-06
TotalHours        : 0.000187785222222222
TotalMinutes      : 0.0112671133333333
TotalSeconds      : 0.6760268
TotalMilliseconds : 676.0268

Test with Linux

Before:

$ time python -m azure.cli version

real    0m0.708s
user    0m0.629s
sys     0m0.080s

After:

$ time python -m azure.cli version

real    0m0.335s
user    0m0.314s
sys     0m0.020s

Profile the import time

`az version -h`

python -X importtime -m azure.cli version -h 2>perf.log
tuna .\perf.log

Before:

After:

`az version`

python -X importtime -m azure.cli version 2>perf.log
tuna .\perf.log

Before:

After:

Remark

pkg_resources is still causing significant delay (0.272s) during the package initialization. That's where the extra time came from, compared to the built-in timer. This needs to be addressed separately in Support PEP 420 -- Implicit Namespace Packages #13293
See Command line and environment for the usage of python -X importtime
To quit tuna, on Window press Ctrl+Break, on Linux press Ctrl+C. See this stackoverflow thread

yonzhan · 2020-05-02T00:03:14Z

add to S169

lmazuel · 2020-05-05T19:08:44Z

src/azure-cli-core/azure/cli/core/commands/arm.py

@@ -305,6 +304,7 @@ def assemble_json(ids):
        if full_id_list:
            setattr(namespace, '_ids', full_id_list)

+        from msrestazure.tools import parse_resource_id, is_valid_resource_id


You should move to azure-mgmt-core, since it's where future update will be. This is the same code I copy pasted without any changes:

from azure.mgmt.core.tools import parse_resource_id, is_valid_resource_id

+@jsntcy Could you help address this, and do necessary tests in a separate PR?

Did the change in this PR already.

lmazuel · 2020-05-05T19:11:48Z

src/azure-cli-core/azure/cli/core/util.py

@@ -47,6 +43,8 @@ def handle_exception(ex):  # pylint: disable=too-many-return-statements
    from msrestazure.azure_exceptions import CloudError
    from msrest.exceptions import HttpOperationError, ValidationError, ClientRequestError
    from azure.cli.core.azlogging import CommandLoggerContext
+    from azure.common import AzureException


There is only ONE SDK that is still using azure.common.AzureException and it's storage. If that helps, you should be able to move that to storage data-plane specific commands (until you can move to full track2 storage)

@Juliehzl @jsntcy

yes, as what Laurent said, we are still using AzureExeption with existing track 1 storage commands and we cannot fully move to track 2 now.

what I mean is that this import is not necessary in cli-core, if only on particular set of SDKs is using it (just trying to save some more :))

fengzhou-msft · 2020-05-06T05:15:47Z

When an extension is removed, will the command index be updated or invalidated?

jiasli · 2020-05-06T08:47:18Z

This also drastically shortens the running time of CI. Previously CLI Automation Full Test takes 1h 4m 2s.
https://github.com/Azure/azure-cli/runs/628276350

Now it only takes 27m 36s. https://github.com/Azure/azure-cli/runs/648374336

jiasli · 2020-05-06T08:50:55Z

When an extension is removed, will the command index be updated or invalidated?

Yes. In such case, the second check will fail and the index will be refreshed. https://github.com/Azure/azure-cli/blob/90c4ba188c87bec8ee634c63748d1dc4fac2be3b/src/azure-cli-core/azure/cli/core/__init__.py#L413

jiasli · 2020-05-08T09:45:21Z

src/azure-cli-core/azure/cli/core/__init__.py

+# Extensions that will always be loaded if installed. These extensions don't expose commands but hook into CLI core.
+ALWAYS_LOADED_EXTENSION_MODNAMES = ['azext_ai_examples', 'azext_ai_did_you_mean_this']


@mirdaki, @christopher-o-toole, I have allowed azext_ai_examples (Azure/azure-cli-extensions#1345) and azext_ai_did_you_mean_this (Azure/azure-cli-extensions#1536) to be always loaded. Please member to change this const list in CLI core if you are going to change the namespace in the future.

what if the extensions not installed ?

This is only a filter applied to installed extensions. If they are not installed, they will simply be ignored. https://github.com/Azure/azure-cli/blob/3632dc0fa87a4c9c928f204cfb61d448c304a208/src/azure-cli-core/azure/cli/core/__init__.py#L272-L279

arrownj · 2020-05-09T09:26:39Z

src/azure-cli-core/azure/cli/core/__init__.py

            cumulative_elapsed_time = 0
-            for mod in [m for m in installed_command_modules if m not in BLACKLISTED_MODS]:
+            for mod in [m for m in command_modules if m not in BLACKLISTED_MODS]:


We can remove if m not in BLACKLISTED_MODS as it is already done in line 224?

Nice catch, but the index may be out-dated and contains a blocked mod. I will remove it from L224 instead.

Also, I have changed the name BLACKLISTED_MODS to the neutral BLOCKED_MODS, as per https://bugs.chromium.org/p/chromium/issues/detail?id=981129

arrownj · 2020-05-09T09:32:29Z

src/azure-cli-core/azure/cli/core/__init__.py

+            # Found modules from index
+            logger.debug("Modules found from index for '%s': %s", top_command, index_modules)
+            for m in index_modules:
+                command_module_prefix = 'azure.cli.command_modules.'


can move it outside the for loop.

Thanks. Changed.

arrownj · 2020-05-09T09:42:25Z

src/azure-cli-core/azure/cli/core/__init__.py

+# Extensions that will always be loaded if installed. These extensions don't expose commands but hook into CLI core.
+ALWAYS_LOADED_EXTENSION_MODNAMES = ['azext_ai_examples', 'azext_ai_did_you_mean_this']


what if the extensions not installed ?

yonzhan · 2020-05-16T05:12:56Z

add to S170

haroldrandom · 2020-05-18T06:56:00Z

Where represent the 3rd point, Remove unnecessary imports of msrest ?

haroldrandom · 2020-05-18T07:09:14Z

How do we maintain the commandIndex.json? (and considering the features/objective we discussed at brain storm)

jiasli · 2020-05-19T04:55:00Z

How do we maintain the commandIndex.json? (and considering the features/objective we discussed at brain storm)

We don't need to maintain it. It is transparent and gets updated totally automatically.

src/azure-cli-core/azure/cli/core/commands/__init__.py

jiasli · 2020-06-11T09:01:03Z

src/azure-cli-core/azure/cli/core/__init__.py

+        index_version = INDEX[_COMMAND_INDEX_VERSION]
+        if not (index_version and index_version == __version__):
+            logger.debug("Command index version is invalid or outdated.")
+            invalidate_command_index()


Added version information in the command index.

{ "version": "2.7.0", "commandIndex": { "acr": [ "azure.cli.command_modules.acr" ],

CLI version may change when

Users update or downgrade Azure CLI to another version.

Users install multiple versions and use them alternately.

This includes a dev environment configured side-by-side with the released version.

When a command is run with an incompatible version (invalid or mismatch), we manually call invalidate_command_index to force an update to avoid all possible edge cases.

@fengzhou-msft to help verify this is the correct way to use __version__.

jiasli · 2020-06-11T09:01:20Z

src/azure-cli-core/azure/cli/core/__init__.py

@@ -295,15 +350,102 @@ def _get_extension_suppressions(mod_loaders):
                            res.append(sup)
            return res

+        def _update_command_index():
+            start_time = timeit.default_timer()
+            INDEX[_COMMAND_INDEX_VERSION] = __version__


_COMMAND_INDEX_VERSION is set here.

jiasli · 2020-06-28T03:46:31Z

src/azure-cli-core/azure/cli/core/__init__.py

+        # Set fallback=False to turn off command index in case of regression
+        use_command_index = self.cli_ctx.config.getboolean('core', 'use_command_index', fallback=True)


This is the switch to disable command index.

yonzhan

LGTM

jiasli requested review from arrownj, fengzhou-msft, haroldrandom, Juliehzl, qianwens and zhoxing-ms as code owners May 1, 2020 18:49

jiasli marked this pull request as draft May 1, 2020 18:49

yonzhan assigned jiasli May 2, 2020

yonzhan added this to the S169 - For Build milestone May 2, 2020

lmazuel reviewed May 5, 2020

View reviewed changes

jiasli marked this pull request as ready for review May 6, 2020 04:40

jiasli requested review from jsntcy, yonzhan, yungezz, mmyyrroonn and qwordy May 6, 2020 09:19

jiasli commented May 8, 2020

View reviewed changes

arrownj reviewed May 9, 2020

View reviewed changes

yonzhan modified the milestones: S169 - For Build, S170 May 16, 2020

jiasli commented May 19, 2020

View reviewed changes

src/azure-cli-core/azure/cli/core/commands/__init__.py Outdated Show resolved Hide resolved

Detect index version mismatch

9bf72d1

jiasli commented Jun 11, 2020

View reviewed changes

jiasli added 7 commits June 12, 2020 14:16

Invalidate command index for cloud profile change

f1915fc

Extract class CommandIndex

8defa9f

Pass cli_ctx conditionally

cdff038

Sort classes

f3747e2

Doc

1b3b033

Add use_command_index config

0c02c0b

Patch test_command_index

5c52141

yonzhan modified the milestones: S171, S172 Jun 19, 2020

jiasli added 2 commits June 28, 2020 11:37

Enable by default

3d9261a

Add comments

4157378

jiasli force-pushed the performance branch from e2091c0 to 4157378 Compare June 28, 2020 03:42

jiasli commented Jun 28, 2020

View reviewed changes

haroldrandom approved these changes Jun 28, 2020

View reviewed changes

yonzhan approved these changes Jun 29, 2020

View reviewed changes

Count more accurately

32108ad

jiasli merged commit 026016e into Azure:dev Jun 29, 2020

jiasli mentioned this pull request Jun 30, 2020

Fail to run "az connectedk8s connect" Azure/azure-cli-extensions#1943

Closed

fengzhou-msft mentioned this pull request Jul 2, 2020

ai-did-you-mean-this extension is not loaded after a first run #14175

Closed

jiasli mentioned this pull request Jul 29, 2020

Build extension command tree Azure/azure-cli-extensions#2078

Merged

3 tasks

jiasli deleted the performance branch July 29, 2020 05:38

jiasli mentioned this pull request Jul 30, 2020

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

Closed

fengzhou-msft mentioned this pull request Mar 22, 2021

[Interactive] Fix #16931: Fix KeyError in az interactive --update #17389

Merged

3 tasks

jiasli mentioned this pull request Jun 21, 2021

Tab completion is incredibly slow and picky about formatting #9157

Open

jiasli mentioned this pull request Sep 16, 2021

Built-in examples are replaced by generated ones in Cloud Shell #19575

Open

jiasli mentioned this pull request Nov 13, 2021

az account show performance #20314

Open

bebound mentioned this pull request Jan 6, 2023

{Core} Improve autocomplete performance by preventing loading all modules #24765

Merged

3 tasks

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

{Core} Build and use command index #13294

{Core} Build and use command index #13294

jiasli commented May 1, 2020 •

edited

Loading

yonzhan commented May 2, 2020

lmazuel May 5, 2020

jiasli May 5, 2020

jiasli May 6, 2020

lmazuel May 5, 2020

jiasli May 5, 2020

Juliehzl May 6, 2020

lmazuel May 16, 2020

fengzhou-msft commented May 6, 2020

jiasli commented May 6, 2020 •

edited

Loading

jiasli commented May 6, 2020

jiasli May 8, 2020

arrownj May 9, 2020

jiasli May 12, 2020

arrownj May 9, 2020

jiasli May 12, 2020

jiasli May 12, 2020

arrownj May 9, 2020

jiasli May 12, 2020

arrownj May 9, 2020

yonzhan commented May 16, 2020

haroldrandom commented May 18, 2020

haroldrandom commented May 18, 2020

jiasli commented May 19, 2020

jiasli Jun 11, 2020

jiasli Jun 11, 2020

jiasli Jun 28, 2020

yonzhan left a comment

		# Extensions that will always be loaded if installed. These extensions don't expose commands but hook into CLI core.
		ALWAYS_LOADED_EXTENSION_MODNAMES = ['azext_ai_examples', 'azext_ai_did_you_mean_this']

		# Set fallback=False to turn off command index in case of regression
		use_command_index = self.cli_ctx.config.getboolean('core', 'use_command_index', fallback=True)

{Core} Build and use command index #13294

{Core} Build and use command index #13294

Conversation

jiasli commented May 1, 2020 • edited Loading

Description

Testing Guide

Test with the built-in timer

Test with PowerShell

Test with Linux

Profile the import time

az version -h

az version

Remark

yonzhan commented May 2, 2020

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

fengzhou-msft commented May 6, 2020

jiasli commented May 6, 2020 • edited Loading

jiasli commented May 6, 2020

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

yonzhan commented May 16, 2020

haroldrandom commented May 18, 2020

haroldrandom commented May 18, 2020

jiasli commented May 19, 2020

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

yonzhan left a comment

Choose a reason for hiding this comment

jiasli commented May 1, 2020 •

edited

Loading

`az version -h`

`az version`

jiasli commented May 6, 2020 •

edited

Loading