search

microsoft / azure-pipelines-tasks

Tasks for Azure Pipelines
https://aka.ms/tfbuild
MIT License
3.42k stars 2.59k forks source link

[Bug]: Failed to perform Auto-login: PSContextCredentialexec: "pwsh": executable file not found in %PATH%. #19876

Open fifuente opened 1 month ago

fifuente commented 1 month ago

New issue checklist

Task name

Azure file copy

Breaking task version

6.240.1

Last working task version

6.239.5

Regression Description

I started to see this error message whenever I tried to copy files to a VM: Failed to perform Auto-login: PSContextCredentialexec: "pwsh": executable file not found in %PATH%.

This is happening in our self-hosted pool and was working yesterday.

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

Azure DevOps Server type

dev.azure.com (formerly visualstudio.com)

Azure DevOps Server Version (if applicable)

No response

Operation system

Windows Server 2019 Datacenter

Relevant log output

2024-05-15T23:11:29.7532693Z ##[command]& 'C:\Windows\System32\WindowsPowerShell\v1.0\powershell.exe' -NoLogo -NoProfile -NonInteractive 
2024-05-15T23:11:29.7533026Z -ExecutionPolicy Unrestricted -Command ". 
2024-05-15T23:11:29.7533371Z 'C:\Users\devcanvasadmin-ppe\AppData\Local\Temp\003bc9e0-95e3-4f88-91f8-dd3edf59b7c1.ps1'"
2024-05-15T23:11:29.7533481Z 
2024-05-15T23:11:34.7551218Z ================================================ 20.120.212.34 ================================================
2024-05-15T23:11:34.7585889Z INFO: Scanning...
2024-05-15T23:11:34.7587268Z 
2024-05-15T23:11:34.7599320Z 
2024-05-15T23:11:34.7600719Z 
2024-05-15T23:11:34.7612140Z Failed to perform Auto-login: PSContextCredentialexec: "pwsh": executable file not found in %PATH%.
2024-05-15T23:11:34.7612748Z 
2024-05-15T23:11:34.7624970Z 
2024-05-15T23:11:38.1188452Z ##[error]Non-Zero exit code: '1' for ComputerName: 'DATAPROCESSORSP'

Full task logs with system.debug enabled

2024-05-15T23:24:47.8230536Z ##[command]& 'C:\Windows\System32\WindowsPowerShell\v1.0\powershell.exe' -NoLogo -NoProfile -NonInteractive 2024-05-15T23:24:47.8231275Z -ExecutionPolicy Unrestricted -Command ". 2024-05-15T23:24:47.8231689Z 'C:\Users\devcanvasadmin-ppe\AppData\Local\Temp\5a083b79-4b69-4e3e-aa8a-1373a5e26eae.ps1'" 2024-05-15T23:24:47.8231832Z 2024-05-15T23:24:47.8356751Z VERBOSE: Destination location cleaned 2024-05-15T23:24:47.8357079Z 2024-05-15T23:24:47.8392596Z VERBOSE: Using default AzCopy arguments for dowloading to VM 2024-05-15T23:24:47.8393876Z 2024-05-15T23:24:47.8413778Z VERBOSE: ##[command] & "" copy 2024-05-15T23:24:47.8414670Z 2024-05-15T23:24:47.8433957Z "https://xxxxxxx.blob.core.windows.net/e501336e-4960-411d-8111-f3ae29935273*****" 2024-05-15T23:24:47.8434371Z 2024-05-15T23:24:47.8453665Z "E:\release_drop\VelocityStandalonePipeline" --recursive --log-level=INFO 2024-05-15T23:24:47.8455185Z 2024-05-15T23:24:47.8473988Z INFO: Scanning... 2024-05-15T23:24:47.8474786Z 2024-05-15T23:24:47.8491852Z 2024-05-15T23:24:47.8494103Z 2024-05-15T23:24:47.8512992Z Failed to perform Auto-login: PSContextCredentialexec: "pwsh": executable file not found in %PATH%. 2024-05-15T23:24:47.8513314Z 2024-05-15T23:24:47.8537626Z ##[debug][DATAPROCESSORSP]LASTEXITCODE is 1 2024-05-15T23:24:47.8537800Z 2024-05-15T23:24:47.8607493Z ##[debug]Leaving Get-JobResults. 2024-05-15T23:24:47.8645356Z ##[debug]Leaving Run-RemoteScriptJobs. 2024-05-15T23:24:47.8722277Z ##[debug]Entering Publish-Telemetry. 2024-05-15T23:24:47.8748208Z ##[debug]SYSTEM_JOBID: 'eba7c8e8-91cf-51cb-52ed-be6e200cbfc2' 2024-05-15T23:24:47.8861514Z ##[debug]Telemetry Data is: { "TelemetryError": "", "JobId": "eba7c8e8-91cf-51cb-52ed-be6e200cbfc2", "IsAzureVm": true, "AzureSubscriptionId": "XXXXXXX", "VmUuidHash": "51EC58DEFE9D6D2E25ADD492B6CC1FBF560885F2CD761D79BC0134D57FFC3BB96EC395C39E773FAECF470F6AF130E42F8C9A9863FF721723B72BBB6C78CDD55B"} 2024-05-15T23:24:47.8924675Z ##[debug]Processed: ##vso[telemetry.publish area=TaskHub;feature=PowerShellOnTargetMachines]{ "TelemetryError": "", "JobId": "eba7c8e8-91cf-51cb-52ed-be6e200cbfc2", "IsAzureVm": true, "AzureSubscriptionId": "XXXXXXX", "VmUuidHash": "51EC58DEFE9D6D2E25ADD492B6CC1FBF560885F2CD761D79BC0134D57FFC3BB96EC395C39E773FAECF470F6AF130E42F8C9A9863FF721723B72BBB6C78CDD55B"} 2024-05-15T23:24:47.8925758Z ##[debug]Leaving Publish-Telemetry. 2024-05-15T23:24:47.9036302Z ##[debug]Entering Upload-TargetMachineLogs. 2024-05-15T23:24:47.9053885Z ##[debug] logsFolder: 'D:\a_work_temp\490d2502-a532-4e7e-a770-dc0874222ca2' 2024-05-15T23:24:47.9085345Z ##[debug]Processed: ##vso[task.uploadfile]D:\a_work_temp\490d2502-a532-4e7e-a770-dc0874222ca2\20.120.212.34.log 2024-05-15T23:24:47.9101331Z ##[debug]Leaving Upload-TargetMachineLogs. 2024-05-15T23:24:47.9223564Z ##[debug]Entering Set-TaskResult. 2024-05-15T23:24:47.9306808Z ##[debug]Remote script execution completed for machine: DATAPROCESSORSP 2024-05-15T23:24:47.9385870Z ##[debug]Leaving Set-TaskResult. 2024-05-15T23:24:47.9449027Z ##[debug]Entering Disconnect-WinRmConnectionToTargetMachines. 2024-05-15T23:24:47.9495023Z ##[debug]Entering Get-RemoteConnection. 2024-05-15T23:24:49.1555181Z ##[debug]Leaving Get-RemoteConnection. 2024-05-15T23:24:49.1590945Z ##[debug]Trying to disconnect pssession with name: d88a19ab-171f-496e-bdb9-a2c9057e1f41, computerName: 20.120.212.34 2024-05-15T23:24:49.2311772Z ##[debug]Successfully disconnected session: d88a19ab-171f-496e-bdb9-a2c9057e1f41 on computer: 20.120.212.34 2024-05-15T23:24:49.2332979Z ##[debug]Leaving Disconnect-WinRmConnectionToTargetMachines. 2024-05-15T23:24:49.2352507Z ##[debug]Leaving Invoke-RemoteScript. 2024-05-15T23:24:49.2516323Z ##[debug]Parallel file copy: Invoke-RemoteScript threw exception 2024-05-15T23:24:49.2584759Z ##[debug]Microsoft.PowerShell.Commands.WriteErrorException: Non-Zero exit code: '1' for ComputerName: 'DATAPROCESSORSP' 2024-05-15T23:24:49.2642255Z ##[debug]Processed: ##vso[task.logissue type=error;code={"Task_Internal_Error":"CopyingToAzureVMFailed"};] 2024-05-15T23:24:49.2696175Z ##[debug][Azure Call]Deleting container: e501336e-4960-411d-8111-f3ae29935273 in storage account: safordeploymentsonly 2024-05-15T23:24:49.4781902Z ##[debug]Removed container 'e501336e-4960-411d-8111-f3ae29935273' successfully. 2024-05-15T23:24:49.5066284Z ##[debug][Azure Call]Deleted container: e501336e-4960-411d-8111-f3ae29935273 in storage account: safordeploymentsonly 2024-05-15T23:24:49.5080367Z ##[debug]Completed Azure File Copy Task for Azure VMs Destination 2024-05-15T23:24:49.5124125Z ##[debug]Leaving D:\a_work_tasks\AzureFileCopy_eb72cb01-a7e5-427b-a8a1-1b31ccac8a43\6.240.1\AzureFileCopy.ps1. 2024-05-15T23:24:49.5185790Z ##[debug]Caught exception from task script. 2024-05-15T23:24:49.5217856Z ##[debug]Error record: 2024-05-15T23:24:49.5803404Z ##[debug]Set-TaskResult : Non-Zero exit code: '1' for ComputerName: 'DATAPROCESSORSP' 2024-05-15T23:24:49.5815433Z ##[debug]At D:\a_work_tasks\AzureFileCopy_eb72cb01-a7e5-427b-a8a1-1b31ccac8a43\6.240.1\ps_modules\RemoteDeployer\RemoteDeployer.psm1:134 char:9 2024-05-15T23:24:49.5827638Z ##[debug]+ Set-TaskResult -jobResults $jobResults -machinesCount $target ... 2024-05-15T23:24:49.5838616Z ##[debug]+ ~~~~~~~~~~~~~ 2024-05-15T23:24:49.5849382Z ##[debug] + CategoryInfo : NotSpecified: (:) [Write-Error], WriteErrorException 2024-05-15T23:24:49.5860022Z ##[debug] + FullyQualifiedErrorId : Microsoft.PowerShell.Commands.WriteErrorException,Set-TaskResult 2024-05-15T23:24:49.5870900Z ##[debug] 2024-05-15T23:24:49.5889993Z ##[debug]Script stack trace: 2024-05-15T23:24:49.5923977Z ##[debug]at Set-TaskResult, D:\a_work_tasks\AzureFileCopy_eb72cb01-a7e5-427b-a8a1-1b31ccac8a43\6.240.1\ps_modules\RemoteDeployer\RemoteDeployer.Utility.ps1: line 138 2024-05-15T23:24:49.5934584Z ##[debug]at Invoke-RemoteScript, D:\a_work_tasks\AzureFileCopy_eb72cb01-a7e5-427b-a8a1-1b31ccac8a43\6.240.1\ps_modules\RemoteDeployer\RemoteDeployer.psm1: line 134 2024-05-15T23:24:49.5945348Z ##[debug]at Copy-FilesParallellyToAzureVMs, D:\a_work_tasks\AzureFileCopy_eb72cb01-a7e5-427b-a8a1-1b31ccac8a43\6.240.1\Utility.ps1: line 882 2024-05-15T23:24:49.5956420Z ##[debug]at Copy-FilesToAzureVMsFromStorageContainer, D:\a_work_tasks\AzureFileCopy_eb72cb01-a7e5-427b-a8a1-1b31ccac8a43\6.240.1\Utility.ps1: line 1025 2024-05-15T23:24:49.5967177Z ##[debug]at , D:\a_work_tasks\AzureFileCopy_eb72cb01-a7e5-427b-a8a1-1b31ccac8a43\6.240.1\AzureFileCopy.ps1: line 225 2024-05-15T23:24:49.5978034Z ##[debug]at , : line 1 2024-05-15T23:24:49.5989046Z ##[debug]at , : line 22 2024-05-15T23:24:49.5999788Z ##[debug]at , : line 18 2024-05-15T23:24:49.6010730Z ##[debug]at , : line 1 2024-05-15T23:24:49.6029715Z ##[debug]Exception: 2024-05-15T23:24:49.6047120Z ##[debug]Microsoft.PowerShell.Commands.WriteErrorException: Non-Zero exit code: '1' for ComputerName: 'DATAPROCESSORSP' 2024-05-15T23:24:49.6102869Z ##[error]Non-Zero exit code: '1' for ComputerName: 'DATAPROCESSORSP' 2024-05-15T23:24:49.6103562Z ##[debug]Processed: ##vso[task.logissue type=error;source=TaskInternal]Non-Zero exit code: '1' for ComputerName: 'DATAPROCESSORSP' 2024-05-15T23:24:49.6114646Z ##[debug]Processed: ##vso[task.complete result=Failed] 2024-05-15T23:24:49.6213688Z ##[debug]Agent environment resources - Disk: D:\ Available 59824.00 MB out of 65533.00 MB, Memory: Used 3041.00 MB out of 32767.00 MB, CPU: Usage 3.20% 2024-05-15T23:24:49.6795348Z ##[debug]Failure attempting to call the restapi and retry counter is exhausted 2024-05-15T23:24:49.6795775Z ##[debug]PERF: RetryHelper Method:System.Threading.Tasks.Task b9() : took 52661.0527 ms 2024-05-15T23:24:49.6796088Z ##[debug]PERF WARNING: RetryHelper Method:System.Threading.Tasks.Task b9() : took 52661.0527 ms 2024-05-15T23:24:49.6797089Z ##[section]Finishing: AzureVMs File Copy

Repro steps

#Your build pipeline references an undefined variable named ‘Password’. Create or edit the build pipeline for this YAML file, define the variable on the Variables tab. See https://go.microsoft.com/fwlink/?linkid=865972

steps:
- task: AzureFileCopy@6
  displayName: 'AzureVMs File Copy'
  inputs:
    SourcePath: '$(System.DefaultWorkingDirectory)/zzzzzz/drop_build_main/*'
    azureSubscription: 'Service Connection Workload ID Federation'
    Destination: AzureVMs
    storage: xxxxx
    resourceGroup: XXXXX
    MachineNames: 'XXXX'
    vmsAdminUserName: 'XXXX'
    vmsAdminPassword: '$(Password)'
    TargetPath: 'E:\release_drop\'
    CleanTargetBeforeCopy: true
  retryCountOnTaskFailure: 2
v-snalawade commented 1 month ago

@fifuente - what is powershell version installed, Can you please update the powershell version to v7 and try running the pipeline again.

fifuente commented 1 month ago

@v-snalawade Let me try checking the version and will make sure v7 is installed. Will get back with the results

fifuente commented 1 month ago

@v-snalawade Installing PowerShell 7 kind of work. After that the task failed because none of the Az. modules could not be found so I went ahead and install all of them - not sure which ones were required, installed everything within Az..

And then when re-running the task, it failed again because I had to manually connect to an Azure Account by running Connect-AzAccount. After running Connect-AzAccount -identity, then the task succeeded.

Thanks for the help!

Also, is there a way to ask for adding those extra steps in the task? To me, it sounds like those are requirements to run the AzCopy task and should at least verify that everything is in place before moving forward. Also, using Managed Identity sounds like the normal approach to me to auth to access other azure resources.

But if it is not possible, could those extra requirements at least be added to the documentation of the task to know what is needed to deploy to Azure VMs by using the AzCopy task?

fifuente commented 1 month ago

@v-snalawade Another issue I just found, is that the task used to copy all the binaries I needed into the VM. With the same directories and files. And with the new update, it now copies everything but within a new directory with a random guid (which is the one used to copy the files to the storage account in the middle of the process) and that breaks all of our processes since the binaries are now in a different subdirectory.

Is there a way for us to indicate to not create any new random directories at the root of the binaries we want to copy?

As an example, if you tried to deploy the following to the VM in the root of E:\

You got the following:

fifuente commented 1 month ago

@v-schhabra any update on this? I was able to fix by myself the initial issue, but the task is still deploying to the VM and creating a directory with a random guid. This is breaking our data processors.

I need to know if I need to make changes to my pipelines or use another approach to deploy to get my team unblocked with this. Also, I need to know what the default behavior will be for the task to avoid breaking my pipelines again in the future.

Thanks!

v-snalawade commented 1 month ago

@fifuente - We are checking on it, we are trying to repro the same scenario. will keep you posted on updates.

richRubie commented 1 month ago

And then when re-running the task, it failed again because I had to manually connect to an Azure Account by running Connect-AzAccount. After running Connect-AzAccount -identity, then the task succeeded.

@fifuente where did you run this command, on the target vm? What identity should it be using?

I agree why are the prequisites of powershell 7 and az.Account not advertised / checked when deploying to a VM.

Can anyone point me in the direction of the docs for deploying code to a vm using AzureFileCopyV6?

richRubie commented 1 month ago

So I added a managed identity to the vm and then ran Connect-AzAccount -identity I got further but then failed to access the container....

How should this work? It's really frustrating

fifuente commented 1 month ago

@richRubie I ran the Connect-AzAccount -identity command on the target VM where the files are going to be copied to. It used the system assigned managed identity assigned to the resource. That identity is the one that needs to have access to the storage account that works as an intermediary to download the files to the VM.