Azure-cli: Local command execution's performance is still not ideal

[troydai]

Reference: https://github.com/Azure/azure-cli/issues/4524

The az cloud list and az resource list -h run both locally, however, their performance is difference.

[leidegre]

I did some additional timings on this and consistently it's the package sf that's consuming all the time (can't say if this is the initial load cost). Here's what it looks like on my machine.

~
DEBUG: File logging enabled - Writing logs to 'C:Usersleidegre.azurelogs'.
DEBUG: Command arguments []
DEBUG: Installed command modules ['acr', 'acs', 'appservice', 'batch', 'billing', 'cdn', 'cloud', 'cognitiveservices', 'component', 'configure', 'consumption', 'container', 'cosmosdb', 'dla', 'dls', 'eventgrid', 'feedback', 'find', 'interactive', 'iot', 'keyvault', 'lab', 'monitor', 'network', 'profile', 'rdbms', 'redis', 'resource', 'role', 'servicefabric', 'sf', 'sql', 'storage', 'vm']
DEBUG: Current cloud config:
{'endpoints': {'active_directory': 'https://login.microsoftonline.com',
'active_directory_data_lake_resource_id': 'https://datalake.azure.net/',
'active_directory_graph_resource_id': 'https://graph.windows.net/',
'active_directory_resource_id': 'https://management.core.windows.net/',
'batch_resource_id': 'https://batch.core.windows.net/',
'gallery': 'https://gallery.azure.com/',
'management': 'https://management.core.windows.net/',
'resource_manager': 'https://management.azure.com/',
'sql_management': 'https://management.core.windows.net:8443/',
'vm_image_alias_doc': 'https://raw.githubusercontent.com/Azure/azure-rest-api-specs/master/arm-compute/quickstart-templates/aliases.json'},
'is_active': True,
'name': 'AzureCloud',
'profile': 'latest',
'suffixes': {'azure_datalake_analytics_catalog_and_job_endpoint': 'azuredatalakeanalytics.net',
'azure_datalake_store_file_system_endpoint': 'azuredatalakestore.net',
'keyvault_dns': '.vault.azure.net',
'sql_server_hostname': '.database.windows.net',
'storage_endpoint': 'core.windows.net'}}
DEBUG: Registered application event handler 'CommandTableParams.Loaded' at
DEBUG: Registered application event handler 'CommandTable.Loaded' at
DEBUG: Loaded module 'acr' in 0.013 seconds.
DEBUG: Loaded module 'acs' in 0.002 seconds.
DEBUG: Registered application event handler 'CommandParser.Parsing' at
DEBUG: Loaded module 'appservice' in 0.003 seconds.
DEBUG: Did not load Batch Extensions module
DEBUG: No module named 'azure.cli.command_modules.batch_extensions'
DEBUG: Loaded module 'batch' in 0.012 seconds.
DEBUG: Loaded module 'billing' in 0.002 seconds.
DEBUG: Loaded module 'cdn' in 0.004 seconds.
DEBUG: Loaded module 'cloud' in 0.001 seconds.
DEBUG: Loaded module 'cognitiveservices' in 0.002 seconds.
DEBUG: Loaded module 'component' in 0.001 seconds.
DEBUG: Loaded module 'configure' in 0.001 seconds.
DEBUG: Loaded module 'consumption' in 0.002 seconds.
DEBUG: Loaded module 'container' in 0.002 seconds.
DEBUG: Registered application event handler 'CommandParser.Parsing' at
DEBUG: Loaded module 'cosmosdb' in 0.003 seconds.
DEBUG: Loaded module 'dla' in 0.002 seconds.
DEBUG: Loaded module 'dls' in 0.002 seconds.
DEBUG: Loaded module 'eventgrid' in 0.002 seconds.
DEBUG: Loaded module 'feedback' in 0.001 seconds.
DEBUG: Loaded module 'find' in 0.001 seconds.
DEBUG: Loaded module 'interactive' in 0.002 seconds.
DEBUG: Loaded module 'iot' in 0.002 seconds.
DEBUG: Loaded module 'keyvault' in 0.003 seconds.
DEBUG: Loaded module 'lab' in 0.003 seconds.
DEBUG: Loaded module 'monitor' in 0.003 seconds.
DEBUG: Loaded module 'network' in 0.010 seconds.
DEBUG: Loaded module 'profile' in 0.001 seconds.
DEBUG: Loaded module 'rdbms' in 0.002 seconds.
DEBUG: Loaded module 'redis' in 0.002 seconds.
DEBUG: Loaded module 'resource' in 0.003 seconds.
DEBUG: Loaded module 'role' in 0.002 seconds.
DEBUG: Loaded module 'servicefabric' in 0.002 seconds.
DEBUG: Loaded module 'sf' in 0.315 seconds. <-- HERE
DEBUG: Loaded module 'sql' in 0.003 seconds.
DEBUG: Loaded module 'storage' in 0.012 seconds.
DEBUG: Loaded module 'vm' in 0.004 seconds.
DEBUG: Loaded all modules in 0.426 seconds. (note: there's always an overhead with the first module loaded)
DEBUG: Application event 'CommandTable.Loaded' with event data {'command_table': {' acr': , ' acs': , ' webapp': , ' appservice': , ' functionapp': , ' batch': , ' billing': DEBUG: Application event 'CommandParser.Loaded' with event data {'parser': AzCliCommandParser(prog='az', usage=None, description=None, formatter_class=, conflict_handler='error', add_help=True)}
~

[troydai]

We removed sf module in the latest release which was shipped last Friday. So when you have a chance please give it a try. In the meantime, I will keep this issue open till I did a full test.

[leidegre]

I'm referencing my post from this issue https://github.com/Azure/azure-cli/issues/4526#issuecomment-373898855 as it outlines additional information relating to this topic.

[tjprescott]

@troydai since merging PR #5418, we have a mechanism to detect and prevent the kinds of performance regression, so arguably this issue could be closed. Issue #4526 is Windows specific and should remain open.

[troydai]

@leidegre thank you for raising this issue. I will look into this again. This is a specific scenario about CLI's performance on Windows platform.

[leidegre]

@troydai yes it is. But please understand, were using the Azure CLI 2.0 because it's not Windows specific. Our dev team is running all kinds of OSes including Windows.

[troydai]

@leidegre Absolutely.

[troydai]

Update. I'm __now__ working on another round of performance profiling and tuning