[BUG]: AzureFileCopyV6 failed copy to azure vm

[tomo-mae1]

New issue checklist

• I searched for existing GitHub issues
• I read pipeline troubleshooting guide
• I checked how to collect logs

Task name

AzureFileCopy

Task version

6.245.1

Issue Description

I'm testing the AzureFileCopyV6 task because I want to copy a file in a repository to a specific folder on an Azure VM.
After resolving some errors, I was blocked by the following error that I don't know how to solve.

Error:
Failed to perform Auto-login: PSContextCredentialGet-AzAccessToken: -REDACTED-;1mRun Connect-AzAccount to login.

I think task was probably using AzCopy.exe twice, but the error occurs the second time.

• 1. Use AzCopy.exe on the Agent to upload files to storage
• 2. Use AzCopy.exe on the VM to download files from storage

I installed Azure PowerShell on the target VM, but the issue persisted.
Is this a bug? Or is there something missing in my settings?

Environment type (Please select at least one enviroment where you face this issue)

• Self-Hosted
• Microsoft Hosted
• VMSS Pool
• Container

Azure DevOps Server type

dev.azure.com (formerly visualstudio.com)

Azure DevOps Server Version (if applicable)

No response

Operation system

Windows 11

Relevant log output

2024-09-12T01:48:39.9855702Z ##[debug]Evaluating condition for step: 'AzureFileCopy'
2024-09-12T01:48:39.9856668Z ##[debug]Evaluating: SucceededNode()
2024-09-12T01:48:39.9856995Z ##[debug]Evaluating SucceededNode:
2024-09-12T01:48:39.9857536Z ##[debug]=> True
2024-09-12T01:48:39.9857866Z ##[debug]Result: True
2024-09-12T01:48:39.9858191Z ##[section]Starting: AzureFileCopy
2024-09-12T01:48:39.9865614Z ==============================================================================
2024-09-12T01:48:39.9865795Z Task         : Azure file copy
2024-09-12T01:48:39.9865896Z Description  : Copy files to Azure Blob Storage or virtual machines
2024-09-12T01:48:39.9866155Z Version      : 6.245.1
2024-09-12T01:48:39.9866253Z Author       : Microsoft Corporation
2024-09-12T01:48:39.9866355Z Help         : https://docs.microsoft.com/azure/devops/pipelines/tasks/deploy/azure-file-copy
2024-09-12T01:48:39.9866517Z ==============================================================================

(Omitted)

2024-09-12T01:50:00.2684618Z ##[debug]JobId: '2', JobState: 'running', ComputerName: '20.205.143.232'
2024-09-12T01:50:00.2693934Z ================================================ 20.205.143.232 ================================================
2024-09-12T01:50:00.2725596Z ##[debug]Agent environment resources - Disk: D:\ Available 12383.33 MB out of 14334.00 MB, Memory: Used 2429.00 MB out of 7167.00 MB, CPU: Usage 56.00%
2024-09-12T01:50:05.2866831Z ##[debug]JobId: '2', JobState: 'running', ComputerName: '20.205.143.232'
2024-09-12T01:50:05.2868829Z ================================================ 20.205.143.232 ================================================
2024-09-12T01:50:05.2974042Z ##[command]& 'C:\Windows\System32\WindowsPowerShell\v1.0\powershell.exe' -NoLogo -NoProfile -NonInteractive 
2024-09-12T01:50:05.2977818Z -ExecutionPolicy Unrestricted -Command ". 
2024-09-12T01:50:05.2981291Z 'C:\Users\<VMadminuserName>\AppData\Local\Temp\90a70d63-8e9d-480d-ad8d-e4a45045a426.ps1'"
2024-09-12T01:50:05.2982919Z 
2024-09-12T01:50:05.3107486Z VERBOSE: Using default AzCopy arguments for dowloading to VM
2024-09-12T01:50:05.3108112Z 
2024-09-12T01:50:05.3146598Z VERBOSE: ##[command] & azcopy copy 
2024-09-12T01:50:05.3146924Z 
2024-09-12T01:50:05.3169941Z "https://<storageName>.blob.core.windows.net/2065244c-6f26-4e53-862f-83a3e88b01f6" 
2024-09-12T01:50:05.3170482Z 
2024-09-12T01:50:05.3190677Z "c:\test\" --recursive --log-level=INFO
2024-09-12T01:50:05.3191120Z 
2024-09-12T01:50:05.3212587Z INFO: AzCopy.exe 10.25.1: A newer version 10.26.0 is available to download
2024-09-12T01:50:05.3213069Z 
2024-09-12T01:50:05.3234105Z 
2024-09-12T01:50:05.3234862Z 
2024-09-12T01:50:05.3254942Z INFO: Scanning...
2024-09-12T01:50:05.3255658Z 
2024-09-12T01:50:05.5598164Z ##[debug]Agent environment resources - Disk: D:\ Available 12383.33 MB out of 14334.00 MB, Memory: Used 2441.00 MB out of 7167.00 MB, CPU: Usage 10.00%
2024-09-12T01:50:10.3281955Z ##[debug]JobId: '2', JobState: 'completed', ComputerName: '20.205.143.232'
2024-09-12T01:50:10.3294195Z ================================================ 20.205.143.232 ================================================
2024-09-12T01:50:10.3318867Z 
2024-09-12T01:50:10.3319640Z 
2024-09-12T01:50:10.3346214Z Failed to perform Auto-login: PSContextCredential�[31;1mGet-AzAccessToken: -REDACTED-;1mRun Connect-AzAccount to login.�[0m
2024-09-12T01:50:10.3346535Z 
2024-09-12T01:50:10.3374675Z .
2024-09-12T01:50:10.3375072Z 
2024-09-12T01:50:10.3396903Z ##[debug][<azureVMName>]LASTEXITCODE is 1
2024-09-12T01:50:10.3397454Z 
2024-09-12T01:50:10.3473610Z ##[debug]Leaving Get-JobResults.
2024-09-12T01:50:10.3494264Z ##[debug]Leaving Run-RemoteScriptJobs.
2024-09-12T01:50:10.3580874Z ##[debug]Entering Publish-Telemetry.
2024-09-12T01:50:10.3610580Z ##[debug]SYSTEM_JOBID: '12f1170f-54f2-53f3-20dd-22fc7dff55f9'
2024-09-12T01:50:10.3752446Z ##[debug]Telemetry Data is: {    "TelemetryError":  "",    "JobId":  "12f1170f-54f2-53f3-20dd-22fc7dff55f9",    "IsAzureVm":  true,    "AzureSubscriptionId":  "3e797da5-b05f-4904-a0ba-bb6a7e8e9d5f",    "VmUuidHash":  "01172B5D5CE7D960BA41FD88A9A4E779972639434D1E11CF14BD4269CFEDF1AF112404411CC535D27DCB5BAA7CFD93030BF744F425F67CAFCF4104E835149666"}
2024-09-12T01:50:10.4151137Z ##[debug]Processed: ##vso[telemetry.publish area=TaskHub;feature=PowerShellOnTargetMachines]{    "TelemetryError":  "",    "JobId":  "12f1170f-54f2-53f3-20dd-22fc7dff55f9",    "IsAzureVm":  true,    "AzureSubscriptionId":  "3e797da5-b05f-4904-a0ba-bb6a7e8e9d5f",    "VmUuidHash":  "01172B5D5CE7D960BA41FD88A9A4E779972639434D1E11CF14BD4269CFEDF1AF112404411CC535D27DCB5BAA7CFD93030BF744F425F67CAFCF4104E835149666"}
2024-09-12T01:50:10.4152449Z ##[debug]Leaving Publish-Telemetry.
2024-09-12T01:50:10.4152924Z ##[debug]Entering Upload-TargetMachineLogs.
2024-09-12T01:50:10.4153442Z ##[debug] logsFolder: 'D:\a\_temp\29899e04-ea32-43f1-95b6-bb53766c79c7'
2024-09-12T01:50:10.4165367Z ##[debug]Processed: ##vso[task.uploadfile]D:\a\_temp\29899e04-ea32-43f1-95b6-bb53766c79c7\20.205.143.232.log
2024-09-12T01:50:10.4166194Z ##[debug]Leaving Upload-TargetMachineLogs.
2024-09-12T01:50:10.4193013Z ##[debug]Entering Set-TaskResult.
2024-09-12T01:50:10.4538787Z ##[debug]Remote script execution completed for machine: <azureVMName>
2024-09-12T01:50:10.4653695Z ##[debug]Leaving Set-TaskResult.
2024-09-12T01:50:10.4705380Z ##[debug]Entering Disconnect-WinRmConnectionToTargetMachines.
2024-09-12T01:50:10.4759216Z ##[debug]Entering Get-RemoteConnection.
2024-09-12T01:50:10.6491714Z ##[debug]Leaving Get-RemoteConnection.
2024-09-12T01:50:10.6514654Z ##[debug]Trying to disconnect pssession with name: 1569ce82-e358-41b1-8d9c-7e282899365e, computerName: 20.205.143.232
2024-09-12T01:50:10.6600478Z ##[debug]Successfully disconnected session: 1569ce82-e358-41b1-8d9c-7e282899365e on computer: 20.205.143.232
2024-09-12T01:50:10.6620247Z ##[debug]Leaving Disconnect-WinRmConnectionToTargetMachines.
2024-09-12T01:50:10.6638831Z ##[debug]Leaving Invoke-RemoteScript.
2024-09-12T01:50:10.6667348Z ##[debug]Parallel file copy: Invoke-RemoteScript threw exception
2024-09-12T01:50:10.6740679Z ##[debug]Microsoft.PowerShell.Commands.WriteErrorException: Non-Zero exit code: '1' for ComputerName: '<azureVMName>'
2024-09-12T01:50:10.6803308Z ##[debug]Processed: ##vso[task.logissue type=error;code={"Task_Internal_Error":"CopyingToAzureVMFailed"};]
2024-09-12T01:50:10.6862071Z ##[debug][Azure Call]Deleting container: 2065244c-6f26-4e53-862f-83a3e88b01f6 in storage account: <storageName>
2024-09-12T01:50:10.7826778Z ##[debug]Removed container '2065244c-6f26-4e53-862f-83a3e88b01f6' successfully.
2024-09-12T01:50:10.8101479Z ##[debug][Azure Call]Deleted container: 2065244c-6f26-4e53-862f-83a3e88b01f6 in storage account: <storageName>
2024-09-12T01:50:10.8133386Z ##[debug]Completed Azure File Copy Task for Azure VMs Destination
2024-09-12T01:50:10.8185521Z ##[debug]Leaving D:\a\_tasks\AzureFileCopy_eb72cb01-a7e5-427b-a8a1-1b31ccac8a43\6.245.1\AzureFileCopy.ps1.
2024-09-12T01:50:10.8221544Z ##[debug]Trying to disconnect from Azure and clear context at process scope
2024-09-12T01:50:10.8335373Z ##[debug]Cannot verify the Microsoft .NET Framework version 4.7.2 because it is not included in the list of permitted versions.
2024-09-12T01:50:10.8357806Z ##[debug]Populating RepositorySourceLocation property for module Az.Accounts.
2024-09-12T01:50:10.8384556Z ##[debug]Loading module from path 'C:\Modules\az_12.1.0\Az.Accounts\3.0.3\Az.Accounts.psm1'.
2024-09-12T01:50:10.8600981Z ##[debug]Agent environment resources - Disk: D:\ Available 12383.33 MB out of 14334.00 MB, Memory: Used 2331.00 MB out of 7167.00 MB, CPU: Usage 61.00%
2024-09-12T01:50:10.8926636Z ##[command]Disconnect-AzAccount -Scope Process -ErrorAction Stop
2024-09-12T01:50:10.9266427Z ##[command]Clear-AzContext -Scope Process -ErrorAction Stop
2024-09-12T01:50:10.9583052Z ##[debug]Caught exception from task script.
2024-09-12T01:50:10.9622566Z ##[debug]Error record:
2024-09-12T01:50:11.0348462Z ##[debug]Set-TaskResult : Non-Zero exit code: '1' for ComputerName: '<azureVMName>'
2024-09-12T01:50:11.0361952Z ##[debug]At D:\a\_tasks\AzureFileCopy_eb72cb01-a7e5-427b-a8a1-1b31ccac8a43\6.245.1\ps_modules\RemoteDeployer\RemoteDeployer.psm1:134 char:9
2024-09-12T01:50:11.0374345Z ##[debug]+         Set-TaskResult -jobResults $jobResults -machinesCount $target ...
2024-09-12T01:50:11.0386531Z ##[debug]+         ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
2024-09-12T01:50:11.0398908Z ##[debug]    + CategoryInfo          : NotSpecified: (:) [Write-Error], WriteErrorException
2024-09-12T01:50:11.0413261Z ##[debug]    + FullyQualifiedErrorId : Microsoft.PowerShell.Commands.WriteErrorException,Set-TaskResult
2024-09-12T01:50:11.0425722Z ##[debug] 
2024-09-12T01:50:11.0449220Z ##[debug]Script stack trace:
2024-09-12T01:50:11.0481524Z ##[debug]at Set-TaskResult, D:\a\_tasks\AzureFileCopy_eb72cb01-a7e5-427b-a8a1-1b31ccac8a43\6.245.1\ps_modules\RemoteDeployer\RemoteDeployer.Utility.ps1: line 138
2024-09-12T01:50:11.0494257Z ##[debug]at Invoke-RemoteScript, D:\a\_tasks\AzureFileCopy_eb72cb01-a7e5-427b-a8a1-1b31ccac8a43\6.245.1\ps_modules\RemoteDeployer\RemoteDeployer.psm1: line 134
2024-09-12T01:50:11.0507560Z ##[debug]at Copy-FilesParallellyToAzureVMs, D:\a\_tasks\AzureFileCopy_eb72cb01-a7e5-427b-a8a1-1b31ccac8a43\6.245.1\Utility.ps1: line 878
2024-09-12T01:50:11.0519890Z ##[debug]at Copy-FilesToAzureVMsFromStorageContainer, D:\a\_tasks\AzureFileCopy_eb72cb01-a7e5-427b-a8a1-1b31ccac8a43\6.245.1\Utility.ps1: line 1021
2024-09-12T01:50:11.0533400Z ##[debug]at <ScriptBlock>, D:\a\_tasks\AzureFileCopy_eb72cb01-a7e5-427b-a8a1-1b31ccac8a43\6.245.1\AzureFileCopy.ps1: line 225
2024-09-12T01:50:11.0546075Z ##[debug]at <ScriptBlock>, <No file>: line 1
2024-09-12T01:50:11.0558892Z ##[debug]at <ScriptBlock>, <No file>: line 22
2024-09-12T01:50:11.0571667Z ##[debug]at <ScriptBlock>, <No file>: line 18
2024-09-12T01:50:11.0584454Z ##[debug]at <ScriptBlock>, <No file>: line 1
2024-09-12T01:50:11.0604128Z ##[debug]Exception:
2024-09-12T01:50:11.0624068Z ##[debug]Microsoft.PowerShell.Commands.WriteErrorException: Non-Zero exit code: '1' for ComputerName: '<azureVMName>'
2024-09-12T01:50:11.0682030Z ##[error]Non-Zero exit code: '1' for ComputerName: '<azureVMName>'
2024-09-12T01:50:11.0683098Z ##[debug]Processed: ##vso[task.logissue type=error;source=TaskInternal;correlationId=d1c7beee-9334-4afb-8e2b-a756775854aa]Non-Zero exit code: '1' for ComputerName: '<azureVMName>'
2024-09-12T01:50:11.0704321Z ##[debug]Processed: ##vso[task.complete result=Failed]
2024-09-12T01:50:11.1680227Z ##[section]Finishing: AzureFileCopy

Full task logs with system.debug enabled

Azure-file-copy-v6.log

Repro steps

Repro step:
1. Add testing file to repository (test.txt)
2. Create New Azure VM (Target VM)
3. Create target folder to Target VM (c:\test\)
4. Run following command to enable WinRM on Target VM

Command: Enable-PSRemoting -SkipNetworkProfileCheck

5. Add inbound rule to NSG to allow Port 5986 
6. Install PowerShell 7.4.5 to Target VM
7. Install Azure PowerShell to Target VM
8. Run Pipeline

YAML:
trigger:
- main

pool: 
 vmImage: windows-latest

steps:
- task: AzureFileCopy@6
  inputs:
    SourcePath: 'test.txt'
    azureSubscription: '<ARMServiceConnectionName>' # use workload identity federation
    Destination: 'AzureVMs'
    storage: '<storageName>'
    resourceGroup: '<resourcegroupName>'
    MachineNames: '<azureVMName>'
    vmsAdminUserName: '<VMadminuserName>'
    vmsAdminPassword: '$(Admin-Pass)' # set variable in UI to right password.
    TargetPath: 'c:\test\'

[tomo-mae1]

This issue doesn't occur with AzureFileCopyV5.
I believe this is because V5 not use auto-login to authenticate AzCopy.exe.

[v-schhabra]

Hi @tomo-mae1
Could you install Get-AzContext module on your agent machine and check if still the error continues?

[LeftTwixWand]

Hey @tomo-mae1 do you use 1ES Hosted Pool or Azure Pipelines agent pool?

[tomo-mae1]

Hello, @v-schhabra and @LeftTwixWand
I used Azure Pipelines agent pool, that image is windows-latest.
I believe microsoft hosted windows agent has all the azure powershell modules installed.

[v-schhabra]

@tomo-mae1 Yes, If you are using Microsoft hosted windows agent then the agent will have all the modules installed.

[tomo-mae1]

Thank you. If so, I believe the agent machine has Get-AzContext module Installed.