Skip to content

Image Copy Failure Due to a Warning Message from Secrets Awareness in a Command Line Tool #28384

@jyama4ta

Description

@jyama4ta

Describe the bug

When executing the az image copy command, the process of issuing a SAS token to the snapshot is accompanied by a warning message. This warning message causes a failure in JSON decoding, which subsequently leads to the failure of the image copy operation.

In CloudShell, warnings are enabled by default. As a workaround, users need to set AZURE_CLIENTS_SHOW_SECRETS_WARNING to False.
https://techcommunity.microsoft.com/t5/azure-tools-blog/hardening-your-defense-in-depth-with-secrets-awareness-in-azure/ba-p/4049883

Related command

az image copy

Errors

command ended with an error: ['/usr/bin/python3.9', '-m', 'azure.cli', 'snapshot', 'grant-access', '--name', 'srcVM-image-20240218120529_os_disk_snapshot', '--resource-group', '{resouce group}', '--duration-in-seconds', '3600', '--output', 'json']
args: ('Expecting value: line 1 column 2 (char 1)',)
The command failed with an unexpected error. Here is the traceback:
Expecting value: line 1 column 2 (char 1)
Traceback (most recent call last):
File "/usr/lib64/az/lib/python3.9/site-packages/knack/cli.py", line 233, in invoke
cmd_result = self.invocation.execute(args)
File "/usr/lib64/az/lib/python3.9/site-packages/azure/cli/core/commands/init.py", line 664, in execute
raise ex
File "/usr/lib64/az/lib/python3.9/site-packages/azure/cli/core/commands/init.py", line 729, in _run_jobs_serially
results.append(self._run_job(expanded_arg, cmd_copy))
File "/usr/lib64/az/lib/python3.9/site-packages/azure/cli/core/commands/init.py", line 698, in _run_job
result = cmd_copy(params)
File "/usr/lib64/az/lib/python3.9/site-packages/azure/cli/core/commands/init.py", line 334, in call
return self.handler(*args, **kwargs)
File "/usr/lib64/az/lib/python3.9/site-packages/azure/cli/core/commands/command_operation.py", line 121, in handler
return op(**command_args)
File "/home/azureuser/.azure/cliextensions/image-copy-extension/azext_imagecopy/custom.py", line 143, in imagecopy
json_output = run_cli_command(cli_cmd, return_as_json=True)
File "/home/azureuser/.azure/cliextensions/image-copy-extension/azext_imagecopy/cli_utils.py", line 49, in run_cli_command
raise ex
File "/home/azureuser/.azure/cliextensions/image-copy-extension/azext_imagecopy/cli_utils.py", line 37, in run_cli_command
json_output = json.loads(cmd_output)
File "/usr/lib64/python3.9/json/init.py", line 346, in loads
return _default_decoder.decode(s)
File "/usr/lib64/python3.9/json/decoder.py", line 337, in decode
obj, end = self.raw_decode(s, idx=_w(s, 0).end())
File "/usr/lib64/python3.9/json/decoder.py", line 355, in raw_decode
raise JSONDecodeError("Expecting value", s, err.value) from None
json.decoder.JSONDecodeError: Expecting value: line 1 column 2 (char 1)

Issue script & Debug output

$ az image copy --source-resource-group {resource group} --source-object-name {source image} --source-type image --target-location japanwest --target-resource-group {resource group} --target-name destImage --cleanup --debug
cli.knack.cli: Command arguments: ['image', 'copy', '--source-resource-group', '{resource group}', '--source-object-name', '{source image}', '--source-type', 'image', '--target-location', 'japanwest', '--target-resource-group', '{resource group}', '--target-name', 'destImage', '--cleanup', '--debug']
cli.knack.cli: init debug log:
Enable color in terminal.
cli.knack.cli: Event: Cli.PreExecute []
cli.knack.cli: Event: CommandParser.OnGlobalArgumentsCreate [<function CLILogging.on_global_arguments at 0x7f85e2a8b4c0>, <function OutputProducer.on_global_arguments at 0x7f85e29a9040>, <function CLIQuery.on_global_arguments at 0x7f85e293f5e0>]
cli.knack.cli: Event: CommandInvoker.OnPreCommandTableCreate []
cli.azure.cli.core: Modules found from index for 'image': ['azure.cli.command_modules.vm', 'azext_imagecopy']
cli.azure.cli.core: Loading command modules:
cli.azure.cli.core: Name Load Time Groups Commands
cli.azure.cli.core: vm 0.239 59 237
cli.azure.cli.core: Total (1) 0.239 59 237
cli.azure.cli.core: These extensions are not installed and will be skipped: ['azext_ai_examples', 'azext_next']
cli.azure.cli.core: Loading extensions:
cli.azure.cli.core: Name Load Time Groups Commands Directory
cli.azure.cli.core: image-copy-extension 0.001 1 1 /home/azureuser/.azure/cliextensions/image-copy-extension
cli.azure.cli.core: Total (1) 0.001 1 1
cli.azure.cli.core: Loaded 59 groups, 238 commands.
cli.azure.cli.core: Found a match in the command table.
cli.azure.cli.core: Raw command : image copy
cli.azure.cli.core: Command table: image copy
cli.knack.cli: Event: CommandInvoker.OnPreCommandTableTruncate [<function AzCliLogging.init_command_file_logging at 0x7f85e1d2ef70>]
cli.azure.cli.core.azlogging: metadata file logging enabled - writing logs to '/home/azureuser/.azure/commands/2024-02-18.05-48-48.image_copy.10301.log'.
az_command_data_logger: command args: image copy --source-resource-group {} --source-object-name {} --source-type {} --target-location {} --target-resource-group {} --target-name {} --cleanup --debug
cli.knack.cli: Event: CommandInvoker.OnPreArgumentLoad [<function register_global_subscription_argument..add_subscription_parameter at 0x7f85e1cfc9d0>]
cli.knack.cli: Event: CommandInvoker.OnPostArgumentLoad []
cli.knack.cli: Event: CommandInvoker.OnPostCommandTableCreate [<function register_ids_argument..add_ids_arguments at 0x7f85e1cfcc10>, <function register_cache_arguments..add_cache_arguments at 0x7f85e1cbca60>]
cli.knack.cli: Event: CommandInvoker.OnCommandTableLoaded []
cli.knack.cli: Event: CommandInvoker.OnPreParseArgs []
cli.knack.cli: Event: CommandInvoker.OnPostParseArgs [<function OutputProducer.handle_output_argument at 0x7f85e29a90d0>, <function CLIQuery.handle_query_parameter at 0x7f85e293f670>, <function register_ids_argument..parse_ids_arguments at 0x7f85e1cbc9d0>]
az_command_data_logger: extension name: image-copy-extension
az_command_data_logger: extension version: 0.2.13
cli.azext_imagecopy.cli_utils: command: ['/usr/bin/python3.9', '-m', 'azure.cli', 'group', 'exists', '-n', 'image-copy-rg', '--output', 'tsv'] ended with output: false

cli.azext_imagecopy.custom: subscription id - {subscription id}
cli.azext_imagecopy.custom: Getting OS disk ID of the source VM/image
cli.azext_imagecopy.cli_utils: command: ['/usr/bin/python3.9', '-m', 'azure.cli', 'image', 'show', '--name', '{source image}', '--resource-group', '{resource group}', '--output', 'json'] ended with output: {
"hyperVGeneration": "V1",
"id": "/subscriptions/{subscription id}/resourceGroups/{resource group}/providers/Microsoft.Compute/images/{source image}",
"location": "japaneast",
"name": "{source image}",
"provisioningState": "Succeeded",
"resourceGroup": "{resource group}",
"sourceVirtualMachine": {
"id": "/subscriptions/{subscription id}/resourceGroups/{resource group}/providers/Microsoft.Compute/virtualMachines/srcVM",
"resourceGroup": "{resource group}"
},
"storageProfile": {
"dataDisks": [],
"osDisk": {
"caching": "ReadWrite",
"diskSizeGB": 30,
"managedDisk": {
"id": "/subscriptions/{subscription id}/resourceGroups/{resource group}/providers/Microsoft.Compute/disks/srcVM_disk1_19d4a5c3cce94f3da6a4269c34ca7c9a",
"resourceGroup": "{resource group}"
},
"osState": "Generalized",
"osType": "Linux",
"storageAccountType": "Premium_LRS"
},
"zoneResilient": false
},
"tags": {},
"type": "Microsoft.Compute/images"
}

cli.azext_imagecopy.cli_utils: json output starts at position: 0
cli.azext_imagecopy.cli_utils: command: ['/usr/bin/python3.9', '-m', 'azure.cli', 'disk', 'show', '--ids', '/subscriptions/{subscription id}/resourceGroups/{resource group}/providers/Microsoft.Compute/disks/srcVM_disk1_19d4a5c3cce94f3da6a4269c34ca7c9a', '--output', 'tsv'] ended with output: 2024-02-18T03:05:19.9799221+00:00 120 25 32213303296 30 Reserved V1 /subscriptions/{subscription id}/resourceGroups/{resource group}/providers/Microsoft.Compute/disks/srcVM_disk1_19d4a5c3cce94f3da6a4269c34ca7c9a japaneast /subscriptions/{subscription id}/resourceGroups/{resource group}/providers/Microsoft.Compute/virtualMachines/srcVM srcVM_disk1_19d4a5c3cce94f3da6a4269c34ca7c9a AllowAll Linux Succeeded Enabled {resource group} True P4 2024-02-18T03:00:08.5227914+00:00 Microsoft.Compute/disks 19d4a5c3-cce9-4f3d-a6a4-269c34ca7c9a

cli.azext_imagecopy.custom: found DISK: /subscriptions/{subscription id}/resourceGroups/{resource group}/providers/Microsoft.Compute/disks/srcVM_disk1_19d4a5c3cce94f3da6a4269c34ca7c9a
cli.azext_imagecopy.custom: source_os_disk_type: DISK. source_os_disk_id: /subscriptions/{subscription id}/resourceGroups/{resource group}/providers/Microsoft.Compute/disks/srcVM_disk1_19d4a5c3cce94f3da6a4269c34ca7c9a. source_os_type: Linux
cli.azext_imagecopy.custom: Creating source snapshot
cli.azext_imagecopy.cli_utils: command: ['/usr/bin/python3.9', '-m', 'azure.cli', 'snapshot', 'create', '--name', '{source image}_os_disk_snapshot', '--location', 'japaneast', '--resource-group', '{resource group}', '--source', '/subscriptions/{subscription id}/resourceGroups/{resource group}/providers/Microsoft.Compute/disks/srcVM_disk1_19d4a5c3cce94f3da6a4269c34ca7c9a', '--hyper-v-generation', 'V1', '--output', 'json', '--tags', 'created_by=image-copy-extension'] ended with output: {
"completionPercent": null,
"copyCompletionError": null,
"creationData": {
"createOption": "Copy",
"elasticSanResourceId": null,
"galleryImageReference": null,
"imageReference": null,
"logicalSectorSize": null,
"performancePlus": null,
"securityDataUri": null,
"sourceResourceId": "/subscriptions/{subscription id}/resourceGroups/{resource group}/providers/Microsoft.Compute/disks/srcVM_disk1_19d4a5c3cce94f3da6a4269c34ca7c9a",
"sourceUniqueId": "19d4a5c3-cce9-4f3d-a6a4-269c34ca7c9a",
"sourceUri": null,
"storageAccountId": null,
"uploadSizeBytes": null
},
"dataAccessAuthMode": null,
"diskAccessId": null,
"diskSizeBytes": 32213303296,
"diskSizeGb": 30,
"diskState": "Unattached",
"encryption": {
"diskEncryptionSetId": null,
"type": "EncryptionAtRestWithPlatformKey"
},
"encryptionSettingsCollection": null,
"extendedLocation": null,
"hyperVGeneration": "V1",
"id": "/subscriptions/{subscription id}/resourceGroups/{resource group}/providers/Microsoft.Compute/snapshots/{source image}_os_disk_snapshot",
"incremental": false,
"incrementalSnapshotFamilyId": null,
"location": "japaneast",
"managedBy": null,
"name": "{source image}_os_disk_snapshot",
"networkAccessPolicy": "AllowAll",
"osType": "Linux",
"provisioningState": "Succeeded",
"publicNetworkAccess": "Enabled",
"purchasePlan": null,
"resourceGroup": "{resource group}",
"securityProfile": null,
"sku": {
"name": "Standard_LRS",
"tier": "Standard"
},
"supportedCapabilities": {
"acceleratedNetwork": true,
"architecture": "x64",
"diskControllerTypes": "SCSI, NVMe"
},
"supportsHibernation": true,
"tags": {
"created_by": "image-copy-extension"
},
"timeCreated": "2024-02-18T05:48:52.942621+00:00",
"type": "Microsoft.Compute/snapshots",
"uniqueId": "4684738a-0727-4e01-a02c-7b0411d7b714"
}

cli.azext_imagecopy.custom: Getting sas url for the source snapshot with timeout: 3600 seconds
cli.azext_imagecopy.cli_utils: command: ['/usr/bin/python3.9', '-m', 'azure.cli', 'snapshot', 'grant-access', '--name', '{source image}_os_disk_snapshot', '--resource-group', '{resource group}', '--duration-in-seconds', '3600', '--output', 'json'] ended with output: WARNING: [Warning] This output may compromise security by showing the following secrets: accessSas. Learn more at: https://go.microsoft.com/fwlink/?linkid=2258669
{
"accessSas": "https://{md- storage account}.blob.core.windows.net/sdt2fvrhvdfb/abcd?sv=2018-03-28&sr=b&si=a4cfa503-f80d-4300-8dd9-348f7554e429&sig=XXXXX",
"securityDataAccessSas": null
}

cli.azext_imagecopy.cli_utils: json output starts at position: 9
cli.azext_imagecopy.cli_utils: json output did not start at position 0, stripping the prefix.
cli.azext_imagecopy.cli_utils: json output after fix:
cli.azext_imagecopy.cli_utils: [Warning] This output may compromise security by showing the following secrets: accessSas. Learn more at: https://go.microsoft.com/fwlink/?linkid=2258669
{
"accessSas": "https://{md- storage account}.blob.core.windows.net/sdt2fvrhvdfb/abcd?sv=2018-03-28&sr=b&si=a4cfa503-f80d-4300-8dd9-348f7554e429&sig=XXXXX",
"securityDataAccessSas": null
}

cli.azext_imagecopy.cli_utils: command ended with an error: ['/usr/bin/python3.9', '-m', 'azure.cli', 'snapshot', 'grant-access', '--name', '{source image}_os_disk_snapshot', '--resource-group', '{resource group}', '--duration-in-seconds', '3600', '--output', 'json']
cli.azext_imagecopy.cli_utils: args: ('Expecting value: line 1 column 2 (char 1)',)
cli.azure.cli.core.azclierror: Traceback (most recent call last):
File "/usr/lib64/az/lib/python3.9/site-packages/knack/cli.py", line 233, in invoke
cmd_result = self.invocation.execute(args)
File "/usr/lib64/az/lib/python3.9/site-packages/azure/cli/core/commands/init.py", line 664, in execute
raise ex
File "/usr/lib64/az/lib/python3.9/site-packages/azure/cli/core/commands/init.py", line 729, in _run_jobs_serially
results.append(self._run_job(expanded_arg, cmd_copy))
File "/usr/lib64/az/lib/python3.9/site-packages/azure/cli/core/commands/init.py", line 698, in _run_job
result = cmd_copy(params)
File "/usr/lib64/az/lib/python3.9/site-packages/azure/cli/core/commands/init.py", line 334, in call
return self.handler(*args, **kwargs)
File "/usr/lib64/az/lib/python3.9/site-packages/azure/cli/core/commands/command_operation.py", line 121, in handler
return op(**command_args)
File "/home/azureuser/.azure/cliextensions/image-copy-extension/azext_imagecopy/custom.py", line 143, in imagecopy
json_output = run_cli_command(cli_cmd, return_as_json=True)
File "/home/azureuser/.azure/cliextensions/image-copy-extension/azext_imagecopy/cli_utils.py", line 49, in run_cli_command
raise ex
File "/home/azureuser/.azure/cliextensions/image-copy-extension/azext_imagecopy/cli_utils.py", line 37, in run_cli_command
json_output = json.loads(cmd_output)
File "/usr/lib64/python3.9/json/init.py", line 346, in loads
return _default_decoder.decode(s)
File "/usr/lib64/python3.9/json/decoder.py", line 337, in decode
obj, end = self.raw_decode(s, idx=_w(s, 0).end())
File "/usr/lib64/python3.9/json/decoder.py", line 355, in raw_decode
raise JSONDecodeError("Expecting value", s, err.value) from None
json.decoder.JSONDecodeError: Expecting value: line 1 column 2 (char 1)

cli.azure.cli.core.azclierror: The command failed with an unexpected error. Here is the traceback:
az_command_data_logger: The command failed with an unexpected error. Here is the traceback:
cli.azure.cli.core.azclierror: Expecting value: line 1 column 2 (char 1)
Traceback (most recent call last):
File "/usr/lib64/az/lib/python3.9/site-packages/knack/cli.py", line 233, in invoke
cmd_result = self.invocation.execute(args)
File "/usr/lib64/az/lib/python3.9/site-packages/azure/cli/core/commands/init.py", line 664, in execute
raise ex
File "/usr/lib64/az/lib/python3.9/site-packages/azure/cli/core/commands/init.py", line 729, in _run_jobs_serially
results.append(self._run_job(expanded_arg, cmd_copy))
File "/usr/lib64/az/lib/python3.9/site-packages/azure/cli/core/commands/init.py", line 698, in _run_job
result = cmd_copy(params)
File "/usr/lib64/az/lib/python3.9/site-packages/azure/cli/core/commands/init.py", line 334, in call
return self.handler(*args, **kwargs)
File "/usr/lib64/az/lib/python3.9/site-packages/azure/cli/core/commands/command_operation.py", line 121, in handler
return op(**command_args)
File "/home/azureuser/.azure/cliextensions/image-copy-extension/azext_imagecopy/custom.py", line 143, in imagecopy
json_output = run_cli_command(cli_cmd, return_as_json=True)
File "/home/azureuser/.azure/cliextensions/image-copy-extension/azext_imagecopy/cli_utils.py", line 49, in run_cli_command
raise ex
File "/home/azureuser/.azure/cliextensions/image-copy-extension/azext_imagecopy/cli_utils.py", line 37, in run_cli_command
json_output = json.loads(cmd_output)
File "/usr/lib64/python3.9/json/init.py", line 346, in loads
return _default_decoder.decode(s)
File "/usr/lib64/python3.9/json/decoder.py", line 337, in decode
obj, end = self.raw_decode(s, idx=_w(s, 0).end())
File "/usr/lib64/python3.9/json/decoder.py", line 355, in raw_decode
raise JSONDecodeError("Expecting value", s, err.value) from None
json.decoder.JSONDecodeError: Expecting value: line 1 column 2 (char 1)
az_command_data_logger: Expecting value: line 1 column 2 (char 1)
Traceback (most recent call last):
File "/usr/lib64/az/lib/python3.9/site-packages/knack/cli.py", line 233, in invoke
cmd_result = self.invocation.execute(args)
File "/usr/lib64/az/lib/python3.9/site-packages/azure/cli/core/commands/init.py", line 664, in execute
raise ex
File "/usr/lib64/az/lib/python3.9/site-packages/azure/cli/core/commands/init.py", line 729, in _run_jobs_serially
results.append(self._run_job(expanded_arg, cmd_copy))
File "/usr/lib64/az/lib/python3.9/site-packages/azure/cli/core/commands/init.py", line 698, in _run_job
result = cmd_copy(params)
File "/usr/lib64/az/lib/python3.9/site-packages/azure/cli/core/commands/init.py", line 334, in call
return self.handler(*args, **kwargs)
File "/usr/lib64/az/lib/python3.9/site-packages/azure/cli/core/commands/command_operation.py", line 121, in handler
return op(**command_args)
File "/home/azureuser/.azure/cliextensions/image-copy-extension/azext_imagecopy/custom.py", line 143, in imagecopy
json_output = run_cli_command(cli_cmd, return_as_json=True)
File "/home/azureuser/.azure/cliextensions/image-copy-extension/azext_imagecopy/cli_utils.py", line 49, in run_cli_command
raise ex
File "/home/azureuser/.azure/cliextensions/image-copy-extension/azext_imagecopy/cli_utils.py", line 37, in run_cli_command
json_output = json.loads(cmd_output)
File "/usr/lib64/python3.9/json/init.py", line 346, in loads
return _default_decoder.decode(s)
File "/usr/lib64/python3.9/json/decoder.py", line 337, in decode
obj, end = self.raw_decode(s, idx=_w(s, 0).end())
File "/usr/lib64/python3.9/json/decoder.py", line 355, in raw_decode
raise JSONDecodeError("Expecting value", s, err.value) from None
json.decoder.JSONDecodeError: Expecting value: line 1 column 2 (char 1)
To check existing issues, please visit: https://github.com/Azure/azure-cli/issues
cli.knack.cli: Event: Cli.PostExecute [<function AzCliLogging.deinit_cmd_metadata_logging at 0x7f85e1d301f0>]
az_command_data_logger: exit code: 1
cli.main: Command ran in 47.456 seconds (init: 0.162, invoke: 47.293)
telemetry.main: Begin splitting cli events and extra events, total events: 1
telemetry.client: Accumulated 0 events. Flush the clients.
telemetry.main: Finish splitting cli events and extra events, cli events: 1
telemetry.save: Save telemetry record of length 7673 in cache
telemetry.main: Begin creating telemetry upload process.
telemetry.process: Creating upload process: "/usr/bin/python3.9 /usr/lib64/az/lib/python3.9/site-packages/azure/cli/telemetry/init.py /home/azureuser/.azure"
telemetry.process: Return from creating process
telemetry.main: Finish creating telemetry upload process.

Expected behavior

The copy operation completes successfully without any errors.

Environment Summary

$ az version
{
"azure-cli": "2.57.0",
"azure-cli-core": "2.57.0",
"azure-cli-telemetry": "1.1.0",
"extensions": {
"image-copy-extension": "0.2.13"
}
}

Additional context

No response

Metadata

Metadata

Labels

Auto-AssignAuto assign by botAuto-ResolveAuto resolve by botAzure CLI TeamThe command of the issue is owned by Azure CLI teamComputeaz vm/vmss/image/disk/snapshotSimilar-Issueact-observability-squadquestionThe issue doesn't require a change to the product in order to be resolved. Most issues start as that

Type

No type

Projects

No projects

Relationships

None yet

Development

No branches or pull requests

Issue actions