search

microsoft / azure-pipelines-tasks

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

[BUG]: Starting background process via AzureCLI task hangs whereas Bash task does not #19844

Open mvromer opened 6 months ago

mvromer commented 6 months ago

New issue checklist

Task name

AzureCLI

Task version

2.238.5

Issue Description

For context, I have a pipeline where I want to run my web server locally in a background process and subsequently run a set of integration tests against my server so that I can gather coverage data. My server needs to authenticate with Azure so it can access different Azure resources, so I originally had an AzureCLI@2 task in my pipeline that authenticated with Azure and launched via Bash my server as a background process.

The problem is my pipeline always hung on the AzureCLI task. After a lot of trial and error, I learned that something in the AzureCLI task's implementation was causing the hang to occur when the task executed a script that launched a background process. If I run the same script via a Bash@3 task, the pipeline can successfully launch the background process and proceed to the next step in the pipeline, although my server at that point is no longer authenticated to Azure.

As a workaround I can use the AzureCLI task to authenticate with Azure and then write the service principal credentials as secret pipeline variables. A subsequent step can run the Bash task to read in those secret values and forward them to my server, which is then launched in the background successfully. That said, I would have expected the same Bash script to whether it was executed by the Bash task or the AzureCLI task.

I've built a public repo on Azure DevOps that contains a pipeline demonstrating this behavior. The pipeline's YAML is here. It contains three jobs, each containing steps that attempt to launch a simple background process (in this case, a local HTTP server). The first job launches via the Bash task, the second via the AzureCLI task, and the third demonstrates the workaround described above. An example of the pipeline's output can be found here.

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-latest, ubuntu-latest

Relevant log output

This is from the end of the AzureCLI task that hung. It's after the task authenticated with Azure and before it runs my custom inline Bash script.

2024-05-06T13:07:57.6034008Z ##[debug]exec tool: /usr/bin/bash
2024-05-06T13:07:57.6034366Z ##[debug]arguments:
2024-05-06T13:07:57.6034695Z ##[debug]   /home/vsts/work/_temp/azureclitaskscript1715000870942.sh
2024-05-06T13:07:57.6035014Z [command]/usr/bin/bash /home/vsts/work/_temp/azureclitaskscript1715000870942.sh
2024-05-06T13:07:57.6276148Z ##[debug]Processed: ##vso[task.setvariable variable=_BackgroundProcessPid]1697
2024-05-06T13:07:57.6285981Z ##[debug]Exit code 0 received from tool '/usr/bin/bash'
2024-05-06T13:08:01.8206074Z ##[debug]Agent environment resources - Disk: / Available 21039.00 MB out of 74244.00 MB, Memory: Used 711.00 MB out of 6921.00 MB, CPU: Usage 31.49%
2024-05-06T13:08:06.8253916Z ##[debug]Agent environment resources - Disk: / Available 21038.00 MB out of 74244.00 MB, Memory: Used 770.00 MB out of 6921.00 MB, CPU: Usage 24.24%
2024-05-06T13:08:07.6320128Z The STDIO streams did not close within 10 seconds of the exit event from process '/usr/bin/bash'. This may indicate a child process inherited the STDIO streams and has not yet exited.
2024-05-06T13:08:07.6321561Z ##[debug]The STDIO streams did not close within 10 seconds of the exit event from process '/usr/bin/bash'. This may indicate a child process inherited the STDIO streams and has not yet exited.
2024-05-06T13:08:07.6332088Z ##[debug]task result: Succeeded
2024-05-06T13:08:07.6341398Z ##[debug]Processed: ##vso[task.complete result=Succeeded;]Script exited with return code: 0
2024-05-06T13:08:07.6342962Z ##[debug]which 'az'
2024-05-06T13:08:07.6343595Z ##[debug]found: '/usr/bin/az'
2024-05-06T13:08:07.6344500Z ##[debug]/usr/bin/az arg:  account clear
2024-05-06T13:08:07.6344871Z ##[debug]/usr/bin/az arg:  account clear
2024-05-06T13:08:07.6345506Z ##[debug]exec tool: /usr/bin/az
2024-05-06T13:08:07.6345857Z ##[debug]exec tool: /usr/bin/az
2024-05-06T13:08:07.6346153Z ##[debug]arguments:
2024-05-06T13:08:07.6346443Z ##[debug]arguments:
2024-05-06T13:08:07.6346736Z ##[debug]   account
2024-05-06T13:08:07.6347009Z ##[debug]   account
2024-05-06T13:08:07.6347282Z ##[debug]   clear
2024-05-06T13:08:07.6347553Z ##[debug]   clear
2024-05-06T13:08:07.6347741Z [command]/usr/bin/az account clear
2024-05-06T13:08:11.8277320Z ##[debug]Agent environment resources - Disk: / Available 21038.00 MB out of 74244.00 MB, Memory: Used 804.00 MB out of 6921.00 MB, CPU: Usage 19.77%
2024-05-06T13:08:16.8353059Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 883.00 MB out of 6921.00 MB, CPU: Usage 16.66%
2024-05-06T13:08:17.3799085Z  INFO  Accepting connections at http://localhost:3000
2024-05-06T13:08:21.8351035Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 923.00 MB out of 6921.00 MB, CPU: Usage 14.44%
2024-05-06T13:08:26.8371656Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 928.00 MB out of 6921.00 MB, CPU: Usage 12.74%
2024-05-06T13:08:31.8403368Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 928.00 MB out of 6921.00 MB, CPU: Usage 11.42%
2024-05-06T13:08:36.8429965Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 928.00 MB out of 6921.00 MB, CPU: Usage 10.41%
2024-05-06T13:08:41.8446505Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 941.00 MB out of 6921.00 MB, CPU: Usage 9.53%
2024-05-06T13:08:46.8505745Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 886.00 MB out of 6921.00 MB, CPU: Usage 8.79%
2024-05-06T13:08:51.8519340Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 854.00 MB out of 6921.00 MB, CPU: Usage 8.17%
2024-05-06T13:08:56.8549190Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 854.00 MB out of 6921.00 MB, CPU: Usage 7.69%
2024-05-06T13:09:01.8551212Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 870.00 MB out of 6921.00 MB, CPU: Usage 7.25%
2024-05-06T13:09:06.8577223Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 870.00 MB out of 6921.00 MB, CPU: Usage 6.84%
2024-05-06T13:09:11.8596297Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 870.00 MB out of 6921.00 MB, CPU: Usage 6.47%
2024-05-06T13:09:16.8642865Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 870.00 MB out of 6921.00 MB, CPU: Usage 6.14%
2024-05-06T13:09:21.8669243Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 870.00 MB out of 6921.00 MB, CPU: Usage 5.85%
2024-05-06T13:09:26.8670594Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 870.00 MB out of 6921.00 MB, CPU: Usage 5.58%
2024-05-06T13:09:31.8692000Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 870.00 MB out of 6921.00 MB, CPU: Usage 5.35%
2024-05-06T13:09:36.8723348Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 870.00 MB out of 6921.00 MB, CPU: Usage 5.12%
2024-05-06T13:09:41.8769141Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 870.00 MB out of 6921.00 MB, CPU: Usage 4.93%
2024-05-06T13:09:46.8795472Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 870.00 MB out of 6921.00 MB, CPU: Usage 4.74%
2024-05-06T13:09:51.8814689Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 870.00 MB out of 6921.00 MB, CPU: Usage 4.59%
2024-05-06T13:09:56.8829509Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 864.00 MB out of 6921.00 MB, CPU: Usage 4.43%
2024-05-06T13:10:01.8852350Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 864.00 MB out of 6921.00 MB, CPU: Usage 4.29%
2024-05-06T13:10:06.8875922Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 864.00 MB out of 6921.00 MB, CPU: Usage 4.14%
2024-05-06T13:10:11.8891623Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 864.00 MB out of 6921.00 MB, CPU: Usage 4.03%
2024-05-06T13:10:16.8887281Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 864.00 MB out of 6921.00 MB, CPU: Usage 3.91%
2024-05-06T13:10:21.8887644Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 864.00 MB out of 6921.00 MB, CPU: Usage 3.79%
2024-05-06T13:10:26.8879827Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 864.00 MB out of 6921.00 MB, CPU: Usage 3.70%
2024-05-06T13:10:31.8895190Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 868.00 MB out of 6921.00 MB, CPU: Usage 3.60%
2024-05-06T13:10:36.8890380Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 868.00 MB out of 6921.00 MB, CPU: Usage 3.50%
2024-05-06T13:10:41.8882415Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 868.00 MB out of 6921.00 MB, CPU: Usage 3.42%
2024-05-06T13:10:46.8917706Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 868.00 MB out of 6921.00 MB, CPU: Usage 3.34%
2024-05-06T13:10:51.8933881Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 868.00 MB out of 6921.00 MB, CPU: Usage 3.26%
2024-05-06T13:10:56.8933986Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 868.00 MB out of 6921.00 MB, CPU: Usage 3.19%
2024-05-06T13:11:01.8982008Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 868.00 MB out of 6921.00 MB, CPU: Usage 3.12%
2024-05-06T13:11:06.8967551Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 868.00 MB out of 6921.00 MB, CPU: Usage 3.06%
2024-05-06T13:11:11.9001846Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 868.00 MB out of 6921.00 MB, CPU: Usage 2.99%
2024-05-06T13:11:16.9042160Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 868.00 MB out of 6921.00 MB, CPU: Usage 2.93%
2024-05-06T13:11:21.9069574Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 872.00 MB out of 6921.00 MB, CPU: Usage 2.88%
2024-05-06T13:11:26.9064127Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 872.00 MB out of 6921.00 MB, CPU: Usage 2.82%
2024-05-06T13:11:31.9077007Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 872.00 MB out of 6921.00 MB, CPU: Usage 2.78%
2024-05-06T13:11:36.9121340Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 872.00 MB out of 6921.00 MB, CPU: Usage 2.72%
2024-05-06T13:11:41.9154045Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 872.00 MB out of 6921.00 MB, CPU: Usage 2.67%
2024-05-06T13:11:46.9147956Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 872.00 MB out of 6921.00 MB, CPU: Usage 2.63%
2024-05-06T13:11:51.9160423Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 872.00 MB out of 6921.00 MB, CPU: Usage 2.59%
2024-05-06T13:11:56.9190238Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 872.00 MB out of 6921.00 MB, CPU: Usage 2.55%
2024-05-06T13:12:01.9179112Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 872.00 MB out of 6921.00 MB, CPU: Usage 2.50%
2024-05-06T13:12:06.9185475Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 880.00 MB out of 6921.00 MB, CPU: Usage 2.47%
2024-05-06T13:12:11.9192458Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 880.00 MB out of 6921.00 MB, CPU: Usage 2.43%
2024-05-06T13:12:16.9197054Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 880.00 MB out of 6921.00 MB, CPU: Usage 2.39%
2024-05-06T13:12:21.9243550Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 880.00 MB out of 6921.00 MB, CPU: Usage 2.36%
2024-05-06T13:12:26.9274635Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 880.00 MB out of 6921.00 MB, CPU: Usage 2.32%
2024-05-06T13:12:31.9270518Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 880.00 MB out of 6921.00 MB, CPU: Usage 2.29%
2024-05-06T13:12:36.9270879Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 880.00 MB out of 6921.00 MB, CPU: Usage 2.26%
2024-05-06T13:12:41.9433584Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 880.00 MB out of 6921.00 MB, CPU: Usage 2.23%
2024-05-06T13:12:46.9416684Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 881.00 MB out of 6921.00 MB, CPU: Usage 2.20%
2024-05-06T13:12:51.9426401Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 881.00 MB out of 6921.00 MB, CPU: Usage 2.17%
2024-05-06T13:12:56.9442422Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 881.00 MB out of 6921.00 MB, CPU: Usage 2.15%
2024-05-06T13:13:01.9460404Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 881.00 MB out of 6921.00 MB, CPU: Usage 2.12%
2024-05-06T13:13:06.9464897Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 877.00 MB out of 6921.00 MB, CPU: Usage 2.09%
2024-05-06T13:13:11.9458355Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 877.00 MB out of 6921.00 MB, CPU: Usage 2.07%
2024-05-06T13:13:16.9482593Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 877.00 MB out of 6921.00 MB, CPU: Usage 2.04%
2024-05-06T13:13:21.9523711Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 877.00 MB out of 6921.00 MB, CPU: Usage 2.02%
2024-05-06T13:13:26.9571484Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 877.00 MB out of 6921.00 MB, CPU: Usage 2.00%
2024-05-06T13:13:31.9599189Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 877.00 MB out of 6921.00 MB, CPU: Usage 1.98%
2024-05-06T13:13:36.9639934Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 877.00 MB out of 6921.00 MB, CPU: Usage 1.96%
2024-05-06T13:13:41.9681068Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 877.00 MB out of 6921.00 MB, CPU: Usage 1.94%
2024-05-06T13:13:46.9716349Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 877.00 MB out of 6921.00 MB, CPU: Usage 1.92%
2024-05-06T13:13:51.9751403Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 877.00 MB out of 6921.00 MB, CPU: Usage 1.90%
2024-05-06T13:13:56.9763515Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 877.00 MB out of 6921.00 MB, CPU: Usage 1.88%
2024-05-06T13:14:01.9798271Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 877.00 MB out of 6921.00 MB, CPU: Usage 1.86%
2024-05-06T13:14:06.9838851Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 881.00 MB out of 6921.00 MB, CPU: Usage 1.84%
2024-05-06T13:14:11.9842801Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 881.00 MB out of 6921.00 MB, CPU: Usage 1.82%
2024-05-06T13:14:16.9834348Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 885.00 MB out of 6921.00 MB, CPU: Usage 1.81%
2024-05-06T13:14:21.9840264Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 885.00 MB out of 6921.00 MB, CPU: Usage 1.79%
2024-05-06T13:14:26.9839765Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 885.00 MB out of 6921.00 MB, CPU: Usage 1.77%
2024-05-06T13:14:31.9832272Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 885.00 MB out of 6921.00 MB, CPU: Usage 1.75%
2024-05-06T13:14:36.9850976Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 885.00 MB out of 6921.00 MB, CPU: Usage 1.74%
2024-05-06T13:14:41.9881837Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 885.00 MB out of 6921.00 MB, CPU: Usage 1.72%
2024-05-06T13:14:46.9888687Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 885.00 MB out of 6921.00 MB, CPU: Usage 1.71%
2024-05-06T13:14:51.9886180Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 885.00 MB out of 6921.00 MB, CPU: Usage 1.69%
2024-05-06T13:14:56.9882111Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 885.00 MB out of 6921.00 MB, CPU: Usage 1.68%
2024-05-06T13:15:01.9895891Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 885.00 MB out of 6921.00 MB, CPU: Usage 1.67%
2024-05-06T13:15:06.9932452Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 881.00 MB out of 6921.00 MB, CPU: Usage 1.65%
2024-05-06T13:15:11.9935646Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 881.00 MB out of 6921.00 MB, CPU: Usage 1.64%
2024-05-06T13:15:16.9932518Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 881.00 MB out of 6921.00 MB, CPU: Usage 1.63%
2024-05-06T13:15:21.9985311Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 881.00 MB out of 6921.00 MB, CPU: Usage 1.61%
2024-05-06T13:15:26.9967335Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 881.00 MB out of 6921.00 MB, CPU: Usage 1.60%
2024-05-06T13:15:31.9992519Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 881.00 MB out of 6921.00 MB, CPU: Usage 1.59%
2024-05-06T13:15:36.9967299Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 881.00 MB out of 6921.00 MB, CPU: Usage 1.58%
2024-05-06T13:15:42.0007421Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 881.00 MB out of 6921.00 MB, CPU: Usage 1.57%
2024-05-06T13:15:47.0007317Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 881.00 MB out of 6921.00 MB, CPU: Usage 1.56%
2024-05-06T13:15:52.0029206Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 881.00 MB out of 6921.00 MB, CPU: Usage 1.54%
2024-05-06T13:15:57.0027640Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 881.00 MB out of 6921.00 MB, CPU: Usage 1.53%
2024-05-06T13:16:02.0029091Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 870.00 MB out of 6921.00 MB, CPU: Usage 1.52%
2024-05-06T13:16:07.0031698Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 870.00 MB out of 6921.00 MB, CPU: Usage 1.51%
2024-05-06T13:16:12.0048409Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 870.00 MB out of 6921.00 MB, CPU: Usage 1.50%
2024-05-06T13:16:17.0050254Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 870.00 MB out of 6921.00 MB, CPU: Usage 1.49%
2024-05-06T13:16:22.0065978Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 870.00 MB out of 6921.00 MB, CPU: Usage 1.48%
2024-05-06T13:16:27.0063297Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 870.00 MB out of 6921.00 MB, CPU: Usage 1.47%
2024-05-06T13:16:32.0105985Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 870.00 MB out of 6921.00 MB, CPU: Usage 1.46%
2024-05-06T13:16:37.0119877Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 870.00 MB out of 6921.00 MB, CPU: Usage 1.45%
2024-05-06T13:16:42.0173774Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 870.00 MB out of 6921.00 MB, CPU: Usage 1.44%
2024-05-06T13:16:47.0191903Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 870.00 MB out of 6921.00 MB, CPU: Usage 1.44%
2024-05-06T13:16:52.0186295Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 870.00 MB out of 6921.00 MB, CPU: Usage 1.43%
2024-05-06T13:16:57.0197955Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 870.00 MB out of 6921.00 MB, CPU: Usage 1.42%
2024-05-06T13:17:02.0230288Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 870.00 MB out of 6921.00 MB, CPU: Usage 1.41%
2024-05-06T13:17:05.6611190Z ##[debug]Re-evaluate condition on job cancellation for step: 'Start background process via AzureCLI'.
2024-05-06T13:17:05.6621031Z ##[error]The Operation will be canceled. The next steps may not contain expected logs.
2024-05-06T13:17:05.6796759Z ##[error]The operation was canceled.
2024-05-06T13:17:05.6802065Z ##[debug]System.OperationCanceledException: The operation was canceled.
   at System.Threading.CancellationToken.ThrowOperationCanceledException()
   at Microsoft.VisualStudio.Services.Agent.Util.ProcessInvoker.ExecuteAsync(String workingDirectory, String fileName, String arguments, IDictionary`2 environment, Boolean requireExitCodeZero, Encoding outputEncoding, Boolean killProcessOnCancel, InputQueue`1 redirectStandardIn, Boolean inheritConsoleHandler, Boolean keepStandardInOpen, Boolean highPriorityProcess, Boolean continueAfterCancelProcessTreeKillAttempt, CancellationToken cancellationToken) in /mnt/vss/_work/1/s/src/Agent.Sdk/ProcessInvoker.cs:line 376
   at Microsoft.VisualStudio.Services.Agent.ProcessInvokerWrapper.ExecuteAsync(String workingDirectory, String fileName, String arguments, IDictionary`2 environment, Boolean requireExitCodeZero, Encoding outputEncoding, Boolean killProcessOnCancel, InputQueue`1 redirectStandardIn, Boolean inheritConsoleHandler, Boolean keepStandardInOpen, Boolean highPriorityProcess, Boolean continueAfterCancelProcessTreeKillAttempt, CancellationToken cancellationToken) in /mnt/vss/_work/1/s/src/Microsoft.VisualStudio.Services.Agent/ProcessInvoker.cs:line 308
   at Microsoft.VisualStudio.Services.Agent.Worker.Handlers.DefaultStepHost.ExecuteAsync(String workingDirectory, String fileName, String arguments, IDictionary`2 environment, Boolean requireExitCodeZero, Encoding outputEncoding, Boolean killProcessOnCancel, Boolean inheritConsoleHandler, Boolean continueAfterCancelProcessTreeKillAttempt, CancellationToken cancellationToken) in /mnt/vss/_work/1/s/src/Agent.Worker/Handlers/StepHost.cs:line 76
   at Microsoft.VisualStudio.Services.Agent.Worker.Handlers.NodeHandler.RunAsync() in /mnt/vss/_work/1/s/src/Agent.Worker/Handlers/NodeHandler.cs:line 245
   at Microsoft.VisualStudio.Services.Agent.Worker.TaskRunner.RunAsyncInternal() in /mnt/vss/_work/1/s/src/Agent.Worker/TaskRunner.cs:line 454
   at Microsoft.VisualStudio.Services.Agent.Worker.TaskRunner.RunAsync() in /mnt/vss/_work/1/s/src/Agent.Worker/TaskRunner.cs:line 76
   at Microsoft.VisualStudio.Services.Agent.Worker.StepsRunner.RunStepAsync(IStep step, CancellationToken jobCancellationToken) in /mnt/vss/_work/1/s/src/Agent.Worker/StepsRunner.cs:line 264
2024-05-06T13:17:05.6805078Z ##[section]Finishing: Start background process via AzureCLI

Full task logs with system.debug enabled

 2024-05-06T13:07:50.4078817Z ##[debug]Evaluating condition for step: 'Start background process via AzureCLI'
2024-05-06T13:07:50.4080076Z ##[debug]Evaluating: SucceededNode()
2024-05-06T13:07:50.4080289Z ##[debug]Evaluating SucceededNode:
2024-05-06T13:07:50.4080813Z ##[debug]=> True
2024-05-06T13:07:50.4081084Z ##[debug]Result: True
2024-05-06T13:07:50.4081335Z ##[section]Starting: Start background process via AzureCLI
2024-05-06T13:07:50.4087078Z ==============================================================================
2024-05-06T13:07:50.4087206Z Task         : Azure CLI
2024-05-06T13:07:50.4087289Z Description  : Run Azure CLI commands against an Azure subscription in a PowerShell Core/Shell script when running on Linux agent or PowerShell/PowerShell Core/Batch script when running on Windows agent.
2024-05-06T13:07:50.4087482Z Version      : 2.238.5
2024-05-06T13:07:50.4087543Z Author       : Microsoft Corporation
2024-05-06T13:07:50.4087623Z Help         : https://docs.microsoft.com/azure/devops/pipelines/tasks/deploy/azure-cli
2024-05-06T13:07:50.4087775Z ==============================================================================
2024-05-06T13:07:50.6236899Z ##[debug]Using node path: /home/vsts/agents/3.238.0/externals/node20_1/bin/node
2024-05-06T13:07:50.7901135Z ##[debug]agent.TempDirectory=/home/vsts/work/_temp
2024-05-06T13:07:50.7908319Z ##[debug]loading inputs and endpoints
2024-05-06T13:07:50.7915470Z ##[debug]loading INPUT_CONNECTEDSERVICENAMEARM
2024-05-06T13:07:50.7939584Z ##[debug]loading INPUT_SCRIPTTYPE
2024-05-06T13:07:50.7941274Z ##[debug]loading INPUT_SCRIPTLOCATION
2024-05-06T13:07:50.7942516Z ##[debug]loading INPUT_SCRIPTPATH
2024-05-06T13:07:50.7943590Z ##[debug]loading INPUT_INLINESCRIPT
2024-05-06T13:07:50.7944772Z ##[debug]loading INPUT_POWERSHELLERRORACTIONPREFERENCE
2024-05-06T13:07:50.7945861Z ##[debug]loading INPUT_ADDSPNTOENVIRONMENT
2024-05-06T13:07:50.7948068Z ##[debug]loading INPUT_USEGLOBALCONFIG
2024-05-06T13:07:50.7949269Z ##[debug]loading INPUT_CWD
2024-05-06T13:07:50.7951169Z ##[debug]loading INPUT_FAILONSTANDARDERROR
2024-05-06T13:07:50.7953300Z ##[debug]loading INPUT_POWERSHELLIGNORELASTEXITCODE
2024-05-06T13:07:50.7955748Z ##[debug]loading ENDPOINT_AUTH_14e0c714-a205-4981-a08d-65a7117bdb32
2024-05-06T13:07:50.7957609Z ##[debug]loading ENDPOINT_AUTH_SCHEME_14e0c714-a205-4981-a08d-65a7117bdb32
2024-05-06T13:07:50.7959551Z ##[debug]loading ENDPOINT_AUTH_PARAMETER_14e0c714-a205-4981-a08d-65a7117bdb32_SERVICEPRINCIPALID
2024-05-06T13:07:50.7961321Z ##[debug]loading ENDPOINT_AUTH_PARAMETER_14e0c714-a205-4981-a08d-65a7117bdb32_AUTHENTICATIONTYPE
2024-05-06T13:07:50.7962237Z ##[debug]loading ENDPOINT_AUTH_PARAMETER_14e0c714-a205-4981-a08d-65a7117bdb32_TENANTID
2024-05-06T13:07:50.7963166Z ##[debug]loading ENDPOINT_AUTH_PARAMETER_14e0c714-a205-4981-a08d-65a7117bdb32_SERVICEPRINCIPALKEY
2024-05-06T13:07:50.7965130Z ##[debug]loading ENDPOINT_AUTH_SYSTEMVSSCONNECTION
2024-05-06T13:07:50.7966055Z ##[debug]loading ENDPOINT_AUTH_SCHEME_SYSTEMVSSCONNECTION
2024-05-06T13:07:50.7966847Z ##[debug]loading ENDPOINT_AUTH_PARAMETER_SYSTEMVSSCONNECTION_ACCESSTOKEN
2024-05-06T13:07:50.7976184Z ##[debug]loading SECRET_SYSTEM_ACCESSTOKEN
2024-05-06T13:07:50.7978982Z ##[debug]loaded 21
2024-05-06T13:07:50.7983628Z ##[debug]Agent.ProxyUrl=undefined
2024-05-06T13:07:50.7983955Z ##[debug]Agent.CAInfo=undefined
2024-05-06T13:07:50.7984270Z ##[debug]Agent.ClientCert=undefined
2024-05-06T13:07:50.7984597Z ##[debug]Agent.SkipCertValidation=undefined
2024-05-06T13:07:50.9378753Z ##[debug]check path : /home/vsts/work/_tasks/AzureCLI_46e4be58-730b-4389-8a2f-ea10b3e5e815/2.238.5/task.json
2024-05-06T13:07:50.9383195Z ##[debug]adding resource file: /home/vsts/work/_tasks/AzureCLI_46e4be58-730b-4389-8a2f-ea10b3e5e815/2.238.5/task.json
2024-05-06T13:07:50.9386276Z ##[debug]system.culture=en-US
2024-05-06T13:07:50.9398199Z ##[debug]which 'az'
2024-05-06T13:07:50.9405705Z ##[debug]found: '/usr/bin/az'
2024-05-06T13:07:50.9414981Z ##[debug]scriptType=bash
2024-05-06T13:07:50.9418339Z ##[debug]scriptLocation=inlineScript
2024-05-06T13:07:50.9420947Z ##[debug]scriptArguments=undefined
2024-05-06T13:07:50.9425643Z ##[debug]Agent.TempDirectory=/home/vsts/work/_temp
2024-05-06T13:07:50.9429680Z ##[debug]inlineScript=nohup npx --yes serve &
echo "##vso[task.setvariable variable=_BackgroundProcessPid]${!}"
2024-05-06T13:07:50.9434636Z ##[debug]which 'bash'
2024-05-06T13:07:50.9439180Z ##[debug]found: '/usr/bin/bash'
2024-05-06T13:07:50.9442145Z ##[debug]which '/usr/bin/bash'
2024-05-06T13:07:50.9444216Z ##[debug]found: '/usr/bin/bash'
2024-05-06T13:07:50.9446840Z ##[debug]/usr/bin/bash arg: /home/vsts/work/_temp/azureclitaskscript1715000870942.sh
2024-05-06T13:07:50.9450749Z ##[debug]cwd=/home/vsts/work/1/s
2024-05-06T13:07:50.9454592Z ##[debug]scriptLocation=inlineScript
2024-05-06T13:07:50.9457924Z ##[debug]failOnStandardError=false
2024-05-06T13:07:50.9461079Z ##[debug]testing directory '/home/vsts/work/1/s'
2024-05-06T13:07:50.9485591Z ##[debug]which 'az'
2024-05-06T13:07:50.9490257Z ##[debug]found: '/usr/bin/az'
2024-05-06T13:07:50.9492838Z ##[debug]/usr/bin/az arg: --version
2024-05-06T13:07:50.9494584Z ##[debug]/usr/bin/az arg: --version
2024-05-06T13:07:50.9498126Z ##[debug]exec tool: /usr/bin/az
2024-05-06T13:07:50.9498527Z ##[debug]exec tool: /usr/bin/az
2024-05-06T13:07:50.9500380Z ##[debug]arguments:
2024-05-06T13:07:50.9501067Z ##[debug]arguments:
2024-05-06T13:07:50.9501797Z ##[debug]   --version
2024-05-06T13:07:50.9502157Z ##[debug]   --version
2024-05-06T13:07:50.9505780Z [command]/usr/bin/az --version
2024-05-06T13:07:51.8148782Z ##[debug]Agent environment resources - Disk: / Available 21039.00 MB out of 74244.00 MB, Memory: Used 724.00 MB out of 6921.00 MB, CPU: Usage 72.37%
2024-05-06T13:07:52.4533928Z WARNING: You have 2 update(s) available. Consider updating your CLI installation with 'az upgrade'
2024-05-06T13:07:52.4534291Z azure-cli                         2.59.0 *
2024-05-06T13:07:52.4534655Z 
2024-05-06T13:07:52.4534863Z core                              2.59.0 *
2024-05-06T13:07:52.4535125Z telemetry                          1.1.0
2024-05-06T13:07:52.4535201Z 
2024-05-06T13:07:52.4535426Z Extensions:
2024-05-06T13:07:52.4535640Z azure-devops                       1.0.0
2024-05-06T13:07:52.4536095Z 
2024-05-06T13:07:52.4536272Z Dependencies:
2024-05-06T13:07:52.4536737Z msal                              1.27.0
2024-05-06T13:07:52.4537379Z azure-mgmt-resource             23.1.0b2
2024-05-06T13:07:52.4537756Z 
2024-05-06T13:07:52.4538006Z Python location '/opt/az/bin/python3'
2024-05-06T13:07:52.4538486Z Extensions directory '/opt/az/azcliextensions'
2024-05-06T13:07:52.4538849Z 
2024-05-06T13:07:52.4539106Z Python (Linux) 3.11.8 (main, Mar 27 2024, 04:03:04) [GCC 11.4.0]
2024-05-06T13:07:52.4539215Z 
2024-05-06T13:07:52.4539456Z Legal docs and information: aka.ms/AzureCliLegal
2024-05-06T13:07:52.4539875Z 
2024-05-06T13:07:52.4539963Z 
2024-05-06T13:07:52.4540690Z ##[debug]useGlobalConfig=false
2024-05-06T13:07:52.4541452Z ##[debug]Agent.TempDirectory=/home/vsts/work/_temp
2024-05-06T13:07:52.4542584Z ##[debug]Agent.TempDirectory=/home/vsts/work/_temp
2024-05-06T13:07:52.4542962Z Setting AZURE_CONFIG_DIR env variable to: /home/vsts/work/_temp/.azclitask
2024-05-06T13:07:52.4543685Z ##[debug]connectedServiceNameARM=14e0c714-a205-4981-a08d-65a7117bdb32
2024-05-06T13:07:52.4544161Z ##[debug]14e0c714-a205-4981-a08d-65a7117bdb32 data environment = AzureCloud
2024-05-06T13:07:52.4544491Z Setting active cloud to: AzureCloud
2024-05-06T13:07:52.4545226Z ##[debug]which 'az'
2024-05-06T13:07:52.4545860Z ##[debug]found: '/usr/bin/az'
2024-05-06T13:07:52.4546279Z ##[debug]/usr/bin/az arg: cloud set -n AzureCloud
2024-05-06T13:07:52.4547289Z ##[debug]/usr/bin/az arg: cloud set -n AzureCloud
2024-05-06T13:07:52.4549564Z ##[debug]exec tool: /usr/bin/az
2024-05-06T13:07:52.4551289Z ##[debug]exec tool: /usr/bin/az
2024-05-06T13:07:52.4552987Z ##[debug]arguments:
2024-05-06T13:07:52.4554648Z ##[debug]arguments:
2024-05-06T13:07:52.4556352Z ##[debug]   cloud
2024-05-06T13:07:52.4558288Z ##[debug]   cloud
2024-05-06T13:07:52.4560016Z ##[debug]   set
2024-05-06T13:07:52.4561987Z ##[debug]   set
2024-05-06T13:07:52.4563697Z ##[debug]   -n
2024-05-06T13:07:52.4565351Z ##[debug]   -n
2024-05-06T13:07:52.4567003Z ##[debug]   AzureCloud
2024-05-06T13:07:52.4568656Z ##[debug]   AzureCloud
2024-05-06T13:07:52.4570684Z [command]/usr/bin/az cloud set -n AzureCloud
2024-05-06T13:07:56.0982185Z ##[debug]connectedServiceNameARM=14e0c714-a205-4981-a08d-65a7117bdb32
2024-05-06T13:07:56.0986115Z ##[debug]14e0c714-a205-4981-a08d-65a7117bdb32 auth scheme = ServicePrincipal
2024-05-06T13:07:56.0986870Z ##[debug]14e0c714-a205-4981-a08d-65a7117bdb32 data SubscriptionID = 1609dab0-c433-4b2e-8e4d-3a32f9606e7f
2024-05-06T13:07:56.0990149Z ##[debug]14e0c714-a205-4981-a08d-65a7117bdb32 auth param authenticationType = spnKey
2024-05-06T13:07:56.0991354Z ##[debug]14e0c714-a205-4981-a08d-65a7117bdb32 auth param serviceprincipalid = ***
2024-05-06T13:07:56.0992083Z ##[debug]14e0c714-a205-4981-a08d-65a7117bdb32 auth param tenantid = ad8c8ccf-022f-42d6-97ea-6460763e0afe
2024-05-06T13:07:56.0992747Z ##[debug]key based endpoint
2024-05-06T13:07:56.0993384Z ##[debug]14e0c714-a205-4981-a08d-65a7117bdb32 auth param serviceprincipalkey = ***
2024-05-06T13:07:56.1010195Z ##[debug]Processed: ##vso[task.setsecret]***
2024-05-06T13:07:56.1010738Z ##[debug]which 'az'
2024-05-06T13:07:56.1011036Z ##[debug]found: '/usr/bin/az'
2024-05-06T13:07:56.1011572Z ##[debug]/usr/bin/az arg: login --service-principal -u "***" --password=*** --tenant "ad8c8ccf-022f-42d6-97ea-6460763e0afe" --allow-no-subscriptions
2024-05-06T13:07:56.1012159Z ##[debug]/usr/bin/az arg: login --service-principal -u "***" --password=*** --tenant "ad8c8ccf-022f-42d6-97ea-6460763e0afe" --allow-no-subscriptions
2024-05-06T13:07:56.1012552Z ##[debug]exec tool: /usr/bin/az
2024-05-06T13:07:56.1012864Z ##[debug]exec tool: /usr/bin/az
2024-05-06T13:07:56.1013150Z ##[debug]arguments:
2024-05-06T13:07:56.1013446Z ##[debug]arguments:
2024-05-06T13:07:56.1013721Z ##[debug]   login
2024-05-06T13:07:56.1013991Z ##[debug]   login
2024-05-06T13:07:56.1014280Z ##[debug]   --service-principal
2024-05-06T13:07:56.1014593Z ##[debug]   --service-principal
2024-05-06T13:07:56.1014871Z ##[debug]   -u
2024-05-06T13:07:56.1015138Z ##[debug]   -u
2024-05-06T13:07:56.1015440Z ##[debug]   ***
2024-05-06T13:07:56.1015743Z ##[debug]   ***
2024-05-06T13:07:56.1016084Z ##[debug]   --password=***
2024-05-06T13:07:56.1016421Z ##[debug]   --password=***
2024-05-06T13:07:56.1016706Z ##[debug]   --tenant
2024-05-06T13:07:56.1016982Z ##[debug]   --tenant
2024-05-06T13:07:56.1017299Z ##[debug]   ad8c8ccf-022f-42d6-97ea-6460763e0afe
2024-05-06T13:07:56.1017635Z ##[debug]   ad8c8ccf-022f-42d6-97ea-6460763e0afe
2024-05-06T13:07:56.1017947Z ##[debug]   --allow-no-subscriptions
2024-05-06T13:07:56.1018254Z ##[debug]   --allow-no-subscriptions
2024-05-06T13:07:56.1019075Z [command]/usr/bin/az login --service-principal -u *** --password=*** --tenant ad8c8ccf-022f-42d6-97ea-6460763e0afe --allow-no-subscriptions
2024-05-06T13:07:56.8157156Z ##[debug]Agent environment resources - Disk: / Available 21039.00 MB out of 74244.00 MB, Memory: Used 744.00 MB out of 6921.00 MB, CPU: Usage 45.21%
2024-05-06T13:07:57.1388864Z [
2024-05-06T13:07:57.1389599Z   {
2024-05-06T13:07:57.1389839Z     "cloudName": "AzureCloud",
2024-05-06T13:07:57.1390343Z     "homeTenantId": "ad8c8ccf-022f-42d6-97ea-6460763e0afe",
2024-05-06T13:07:57.1390699Z     "id": "1609dab0-c433-4b2e-8e4d-3a32f9606e7f",
2024-05-06T13:07:57.1390855Z     "isDefault": true,
2024-05-06T13:07:57.1391006Z     "managedByTenants": [],
2024-05-06T13:07:57.1391154Z     "name": "mvromer",
2024-05-06T13:07:57.1391281Z     "state": "Enabled",
2024-05-06T13:07:57.1391529Z     "tenantId": "ad8c8ccf-022f-42d6-97ea-6460763e0afe",
2024-05-06T13:07:57.1391678Z     "user": {
2024-05-06T13:07:57.1392040Z       "name": "***",
2024-05-06T13:07:57.1392174Z       "type": "servicePrincipal"
2024-05-06T13:07:57.1392313Z     }
2024-05-06T13:07:57.1392454Z   }
2024-05-06T13:07:57.1392551Z ]
2024-05-06T13:07:57.1393000Z ##[debug]which 'az'
2024-05-06T13:07:57.1393301Z ##[debug]found: '/usr/bin/az'
2024-05-06T13:07:57.1394031Z ##[debug]/usr/bin/az arg: account set --subscription "1609dab0-c433-4b2e-8e4d-3a32f9606e7f"
2024-05-06T13:07:57.1394445Z ##[debug]/usr/bin/az arg: account set --subscription "1609dab0-c433-4b2e-8e4d-3a32f9606e7f"
2024-05-06T13:07:57.1394792Z ##[debug]exec tool: /usr/bin/az
2024-05-06T13:07:57.1395089Z ##[debug]exec tool: /usr/bin/az
2024-05-06T13:07:57.1395377Z ##[debug]arguments:
2024-05-06T13:07:57.1395658Z ##[debug]arguments:
2024-05-06T13:07:57.1395935Z ##[debug]   account
2024-05-06T13:07:57.1396224Z ##[debug]   account
2024-05-06T13:07:57.1396755Z ##[debug]   set
2024-05-06T13:07:57.1397036Z ##[debug]   set
2024-05-06T13:07:57.1397315Z ##[debug]   --subscription
2024-05-06T13:07:57.1397609Z ##[debug]   --subscription
2024-05-06T13:07:57.1397923Z ##[debug]   1609dab0-c433-4b2e-8e4d-3a32f9606e7f
2024-05-06T13:07:57.1398270Z ##[debug]   1609dab0-c433-4b2e-8e4d-3a32f9606e7f
2024-05-06T13:07:57.1398642Z [command]/usr/bin/az account set --subscription 1609dab0-c433-4b2e-8e4d-3a32f9606e7f
2024-05-06T13:07:57.6032012Z ##[debug]addSpnToEnvironment=true
2024-05-06T13:07:57.6033014Z ##[debug]14e0c714-a205-4981-a08d-65a7117bdb32 auth scheme = ServicePrincipal
2024-05-06T13:07:57.6034008Z ##[debug]exec tool: /usr/bin/bash
2024-05-06T13:07:57.6034366Z ##[debug]arguments:
2024-05-06T13:07:57.6034695Z ##[debug]   /home/vsts/work/_temp/azureclitaskscript1715000870942.sh
2024-05-06T13:07:57.6035014Z [command]/usr/bin/bash /home/vsts/work/_temp/azureclitaskscript1715000870942.sh
2024-05-06T13:07:57.6276148Z ##[debug]Processed: ##vso[task.setvariable variable=_BackgroundProcessPid]1697
2024-05-06T13:07:57.6285981Z ##[debug]Exit code 0 received from tool '/usr/bin/bash'
2024-05-06T13:08:01.8206074Z ##[debug]Agent environment resources - Disk: / Available 21039.00 MB out of 74244.00 MB, Memory: Used 711.00 MB out of 6921.00 MB, CPU: Usage 31.49%
2024-05-06T13:08:06.8253916Z ##[debug]Agent environment resources - Disk: / Available 21038.00 MB out of 74244.00 MB, Memory: Used 770.00 MB out of 6921.00 MB, CPU: Usage 24.24%
2024-05-06T13:08:07.6320128Z The STDIO streams did not close within 10 seconds of the exit event from process '/usr/bin/bash'. This may indicate a child process inherited the STDIO streams and has not yet exited.
2024-05-06T13:08:07.6321561Z ##[debug]The STDIO streams did not close within 10 seconds of the exit event from process '/usr/bin/bash'. This may indicate a child process inherited the STDIO streams and has not yet exited.
2024-05-06T13:08:07.6332088Z ##[debug]task result: Succeeded
2024-05-06T13:08:07.6341398Z ##[debug]Processed: ##vso[task.complete result=Succeeded;]Script exited with return code: 0
2024-05-06T13:08:07.6342962Z ##[debug]which 'az'
2024-05-06T13:08:07.6343595Z ##[debug]found: '/usr/bin/az'
2024-05-06T13:08:07.6344500Z ##[debug]/usr/bin/az arg:  account clear
2024-05-06T13:08:07.6344871Z ##[debug]/usr/bin/az arg:  account clear
2024-05-06T13:08:07.6345506Z ##[debug]exec tool: /usr/bin/az
2024-05-06T13:08:07.6345857Z ##[debug]exec tool: /usr/bin/az
2024-05-06T13:08:07.6346153Z ##[debug]arguments:
2024-05-06T13:08:07.6346443Z ##[debug]arguments:
2024-05-06T13:08:07.6346736Z ##[debug]   account
2024-05-06T13:08:07.6347009Z ##[debug]   account
2024-05-06T13:08:07.6347282Z ##[debug]   clear
2024-05-06T13:08:07.6347553Z ##[debug]   clear
2024-05-06T13:08:07.6347741Z [command]/usr/bin/az account clear
2024-05-06T13:08:11.8277320Z ##[debug]Agent environment resources - Disk: / Available 21038.00 MB out of 74244.00 MB, Memory: Used 804.00 MB out of 6921.00 MB, CPU: Usage 19.77%
2024-05-06T13:08:16.8353059Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 883.00 MB out of 6921.00 MB, CPU: Usage 16.66%
2024-05-06T13:08:17.3799085Z  INFO  Accepting connections at http://localhost:3000
2024-05-06T13:08:21.8351035Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 923.00 MB out of 6921.00 MB, CPU: Usage 14.44%
2024-05-06T13:08:26.8371656Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 928.00 MB out of 6921.00 MB, CPU: Usage 12.74%
2024-05-06T13:08:31.8403368Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 928.00 MB out of 6921.00 MB, CPU: Usage 11.42%
2024-05-06T13:08:36.8429965Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 928.00 MB out of 6921.00 MB, CPU: Usage 10.41%
2024-05-06T13:08:41.8446505Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 941.00 MB out of 6921.00 MB, CPU: Usage 9.53%
2024-05-06T13:08:46.8505745Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 886.00 MB out of 6921.00 MB, CPU: Usage 8.79%
2024-05-06T13:08:51.8519340Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 854.00 MB out of 6921.00 MB, CPU: Usage 8.17%
2024-05-06T13:08:56.8549190Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 854.00 MB out of 6921.00 MB, CPU: Usage 7.69%
2024-05-06T13:09:01.8551212Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 870.00 MB out of 6921.00 MB, CPU: Usage 7.25%
2024-05-06T13:09:06.8577223Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 870.00 MB out of 6921.00 MB, CPU: Usage 6.84%
2024-05-06T13:09:11.8596297Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 870.00 MB out of 6921.00 MB, CPU: Usage 6.47%
2024-05-06T13:09:16.8642865Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 870.00 MB out of 6921.00 MB, CPU: Usage 6.14%
2024-05-06T13:09:21.8669243Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 870.00 MB out of 6921.00 MB, CPU: Usage 5.85%
2024-05-06T13:09:26.8670594Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 870.00 MB out of 6921.00 MB, CPU: Usage 5.58%
2024-05-06T13:09:31.8692000Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 870.00 MB out of 6921.00 MB, CPU: Usage 5.35%
2024-05-06T13:09:36.8723348Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 870.00 MB out of 6921.00 MB, CPU: Usage 5.12%
2024-05-06T13:09:41.8769141Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 870.00 MB out of 6921.00 MB, CPU: Usage 4.93%
2024-05-06T13:09:46.8795472Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 870.00 MB out of 6921.00 MB, CPU: Usage 4.74%
2024-05-06T13:09:51.8814689Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 870.00 MB out of 6921.00 MB, CPU: Usage 4.59%
2024-05-06T13:09:56.8829509Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 864.00 MB out of 6921.00 MB, CPU: Usage 4.43%
2024-05-06T13:10:01.8852350Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 864.00 MB out of 6921.00 MB, CPU: Usage 4.29%
2024-05-06T13:10:06.8875922Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 864.00 MB out of 6921.00 MB, CPU: Usage 4.14%
2024-05-06T13:10:11.8891623Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 864.00 MB out of 6921.00 MB, CPU: Usage 4.03%
2024-05-06T13:10:16.8887281Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 864.00 MB out of 6921.00 MB, CPU: Usage 3.91%
2024-05-06T13:10:21.8887644Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 864.00 MB out of 6921.00 MB, CPU: Usage 3.79%
2024-05-06T13:10:26.8879827Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 864.00 MB out of 6921.00 MB, CPU: Usage 3.70%
2024-05-06T13:10:31.8895190Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 868.00 MB out of 6921.00 MB, CPU: Usage 3.60%
2024-05-06T13:10:36.8890380Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 868.00 MB out of 6921.00 MB, CPU: Usage 3.50%
2024-05-06T13:10:41.8882415Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 868.00 MB out of 6921.00 MB, CPU: Usage 3.42%
2024-05-06T13:10:46.8917706Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 868.00 MB out of 6921.00 MB, CPU: Usage 3.34%
2024-05-06T13:10:51.8933881Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 868.00 MB out of 6921.00 MB, CPU: Usage 3.26%
2024-05-06T13:10:56.8933986Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 868.00 MB out of 6921.00 MB, CPU: Usage 3.19%
2024-05-06T13:11:01.8982008Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 868.00 MB out of 6921.00 MB, CPU: Usage 3.12%
2024-05-06T13:11:06.8967551Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 868.00 MB out of 6921.00 MB, CPU: Usage 3.06%
2024-05-06T13:11:11.9001846Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 868.00 MB out of 6921.00 MB, CPU: Usage 2.99%
2024-05-06T13:11:16.9042160Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 868.00 MB out of 6921.00 MB, CPU: Usage 2.93%
2024-05-06T13:11:21.9069574Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 872.00 MB out of 6921.00 MB, CPU: Usage 2.88%
2024-05-06T13:11:26.9064127Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 872.00 MB out of 6921.00 MB, CPU: Usage 2.82%
2024-05-06T13:11:31.9077007Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 872.00 MB out of 6921.00 MB, CPU: Usage 2.78%
2024-05-06T13:11:36.9121340Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 872.00 MB out of 6921.00 MB, CPU: Usage 2.72%
2024-05-06T13:11:41.9154045Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 872.00 MB out of 6921.00 MB, CPU: Usage 2.67%
2024-05-06T13:11:46.9147956Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 872.00 MB out of 6921.00 MB, CPU: Usage 2.63%
2024-05-06T13:11:51.9160423Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 872.00 MB out of 6921.00 MB, CPU: Usage 2.59%
2024-05-06T13:11:56.9190238Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 872.00 MB out of 6921.00 MB, CPU: Usage 2.55%
2024-05-06T13:12:01.9179112Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 872.00 MB out of 6921.00 MB, CPU: Usage 2.50%
2024-05-06T13:12:06.9185475Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 880.00 MB out of 6921.00 MB, CPU: Usage 2.47%
2024-05-06T13:12:11.9192458Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 880.00 MB out of 6921.00 MB, CPU: Usage 2.43%
2024-05-06T13:12:16.9197054Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 880.00 MB out of 6921.00 MB, CPU: Usage 2.39%
2024-05-06T13:12:21.9243550Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 880.00 MB out of 6921.00 MB, CPU: Usage 2.36%
2024-05-06T13:12:26.9274635Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 880.00 MB out of 6921.00 MB, CPU: Usage 2.32%
2024-05-06T13:12:31.9270518Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 880.00 MB out of 6921.00 MB, CPU: Usage 2.29%
2024-05-06T13:12:36.9270879Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 880.00 MB out of 6921.00 MB, CPU: Usage 2.26%
2024-05-06T13:12:41.9433584Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 880.00 MB out of 6921.00 MB, CPU: Usage 2.23%
2024-05-06T13:12:46.9416684Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 881.00 MB out of 6921.00 MB, CPU: Usage 2.20%
2024-05-06T13:12:51.9426401Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 881.00 MB out of 6921.00 MB, CPU: Usage 2.17%
2024-05-06T13:12:56.9442422Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 881.00 MB out of 6921.00 MB, CPU: Usage 2.15%
2024-05-06T13:13:01.9460404Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 881.00 MB out of 6921.00 MB, CPU: Usage 2.12%
2024-05-06T13:13:06.9464897Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 877.00 MB out of 6921.00 MB, CPU: Usage 2.09%
2024-05-06T13:13:11.9458355Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 877.00 MB out of 6921.00 MB, CPU: Usage 2.07%
2024-05-06T13:13:16.9482593Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 877.00 MB out of 6921.00 MB, CPU: Usage 2.04%
2024-05-06T13:13:21.9523711Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 877.00 MB out of 6921.00 MB, CPU: Usage 2.02%
2024-05-06T13:13:26.9571484Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 877.00 MB out of 6921.00 MB, CPU: Usage 2.00%
2024-05-06T13:13:31.9599189Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 877.00 MB out of 6921.00 MB, CPU: Usage 1.98%
2024-05-06T13:13:36.9639934Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 877.00 MB out of 6921.00 MB, CPU: Usage 1.96%
2024-05-06T13:13:41.9681068Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 877.00 MB out of 6921.00 MB, CPU: Usage 1.94%
2024-05-06T13:13:46.9716349Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 877.00 MB out of 6921.00 MB, CPU: Usage 1.92%
2024-05-06T13:13:51.9751403Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 877.00 MB out of 6921.00 MB, CPU: Usage 1.90%
2024-05-06T13:13:56.9763515Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 877.00 MB out of 6921.00 MB, CPU: Usage 1.88%
2024-05-06T13:14:01.9798271Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 877.00 MB out of 6921.00 MB, CPU: Usage 1.86%
2024-05-06T13:14:06.9838851Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 881.00 MB out of 6921.00 MB, CPU: Usage 1.84%
2024-05-06T13:14:11.9842801Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 881.00 MB out of 6921.00 MB, CPU: Usage 1.82%
2024-05-06T13:14:16.9834348Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 885.00 MB out of 6921.00 MB, CPU: Usage 1.81%
2024-05-06T13:14:21.9840264Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 885.00 MB out of 6921.00 MB, CPU: Usage 1.79%
2024-05-06T13:14:26.9839765Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 885.00 MB out of 6921.00 MB, CPU: Usage 1.77%
2024-05-06T13:14:31.9832272Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 885.00 MB out of 6921.00 MB, CPU: Usage 1.75%
2024-05-06T13:14:36.9850976Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 885.00 MB out of 6921.00 MB, CPU: Usage 1.74%
2024-05-06T13:14:41.9881837Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 885.00 MB out of 6921.00 MB, CPU: Usage 1.72%
2024-05-06T13:14:46.9888687Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 885.00 MB out of 6921.00 MB, CPU: Usage 1.71%
2024-05-06T13:14:51.9886180Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 885.00 MB out of 6921.00 MB, CPU: Usage 1.69%
2024-05-06T13:14:56.9882111Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 885.00 MB out of 6921.00 MB, CPU: Usage 1.68%
2024-05-06T13:15:01.9895891Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 885.00 MB out of 6921.00 MB, CPU: Usage 1.67%
2024-05-06T13:15:06.9932452Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 881.00 MB out of 6921.00 MB, CPU: Usage 1.65%
2024-05-06T13:15:11.9935646Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 881.00 MB out of 6921.00 MB, CPU: Usage 1.64%
2024-05-06T13:15:16.9932518Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 881.00 MB out of 6921.00 MB, CPU: Usage 1.63%
2024-05-06T13:15:21.9985311Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 881.00 MB out of 6921.00 MB, CPU: Usage 1.61%
2024-05-06T13:15:26.9967335Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 881.00 MB out of 6921.00 MB, CPU: Usage 1.60%
2024-05-06T13:15:31.9992519Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 881.00 MB out of 6921.00 MB, CPU: Usage 1.59%
2024-05-06T13:15:36.9967299Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 881.00 MB out of 6921.00 MB, CPU: Usage 1.58%
2024-05-06T13:15:42.0007421Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 881.00 MB out of 6921.00 MB, CPU: Usage 1.57%
2024-05-06T13:15:47.0007317Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 881.00 MB out of 6921.00 MB, CPU: Usage 1.56%
2024-05-06T13:15:52.0029206Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 881.00 MB out of 6921.00 MB, CPU: Usage 1.54%
2024-05-06T13:15:57.0027640Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 881.00 MB out of 6921.00 MB, CPU: Usage 1.53%
2024-05-06T13:16:02.0029091Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 870.00 MB out of 6921.00 MB, CPU: Usage 1.52%
2024-05-06T13:16:07.0031698Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 870.00 MB out of 6921.00 MB, CPU: Usage 1.51%
2024-05-06T13:16:12.0048409Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 870.00 MB out of 6921.00 MB, CPU: Usage 1.50%
2024-05-06T13:16:17.0050254Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 870.00 MB out of 6921.00 MB, CPU: Usage 1.49%
2024-05-06T13:16:22.0065978Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 870.00 MB out of 6921.00 MB, CPU: Usage 1.48%
2024-05-06T13:16:27.0063297Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 870.00 MB out of 6921.00 MB, CPU: Usage 1.47%
2024-05-06T13:16:32.0105985Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 870.00 MB out of 6921.00 MB, CPU: Usage 1.46%
2024-05-06T13:16:37.0119877Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 870.00 MB out of 6921.00 MB, CPU: Usage 1.45%
2024-05-06T13:16:42.0173774Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 870.00 MB out of 6921.00 MB, CPU: Usage 1.44%
2024-05-06T13:16:47.0191903Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 870.00 MB out of 6921.00 MB, CPU: Usage 1.44%
2024-05-06T13:16:52.0186295Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 870.00 MB out of 6921.00 MB, CPU: Usage 1.43%
2024-05-06T13:16:57.0197955Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 870.00 MB out of 6921.00 MB, CPU: Usage 1.42%
2024-05-06T13:17:02.0230288Z ##[debug]Agent environment resources - Disk: / Available 21019.00 MB out of 74244.00 MB, Memory: Used 870.00 MB out of 6921.00 MB, CPU: Usage 1.41%
2024-05-06T13:17:05.6611190Z ##[debug]Re-evaluate condition on job cancellation for step: 'Start background process via AzureCLI'.
2024-05-06T13:17:05.6621031Z ##[error]The Operation will be canceled. The next steps may not contain expected logs.
2024-05-06T13:17:05.6796759Z ##[error]The operation was canceled.
2024-05-06T13:17:05.6802065Z ##[debug]System.OperationCanceledException: The operation was canceled.
   at System.Threading.CancellationToken.ThrowOperationCanceledException()
   at Microsoft.VisualStudio.Services.Agent.Util.ProcessInvoker.ExecuteAsync(String workingDirectory, String fileName, String arguments, IDictionary`2 environment, Boolean requireExitCodeZero, Encoding outputEncoding, Boolean killProcessOnCancel, InputQueue`1 redirectStandardIn, Boolean inheritConsoleHandler, Boolean keepStandardInOpen, Boolean highPriorityProcess, Boolean continueAfterCancelProcessTreeKillAttempt, CancellationToken cancellationToken) in /mnt/vss/_work/1/s/src/Agent.Sdk/ProcessInvoker.cs:line 376
   at Microsoft.VisualStudio.Services.Agent.ProcessInvokerWrapper.ExecuteAsync(String workingDirectory, String fileName, String arguments, IDictionary`2 environment, Boolean requireExitCodeZero, Encoding outputEncoding, Boolean killProcessOnCancel, InputQueue`1 redirectStandardIn, Boolean inheritConsoleHandler, Boolean keepStandardInOpen, Boolean highPriorityProcess, Boolean continueAfterCancelProcessTreeKillAttempt, CancellationToken cancellationToken) in /mnt/vss/_work/1/s/src/Microsoft.VisualStudio.Services.Agent/ProcessInvoker.cs:line 308
   at Microsoft.VisualStudio.Services.Agent.Worker.Handlers.DefaultStepHost.ExecuteAsync(String workingDirectory, String fileName, String arguments, IDictionary`2 environment, Boolean requireExitCodeZero, Encoding outputEncoding, Boolean killProcessOnCancel, Boolean inheritConsoleHandler, Boolean continueAfterCancelProcessTreeKillAttempt, CancellationToken cancellationToken) in /mnt/vss/_work/1/s/src/Agent.Worker/Handlers/StepHost.cs:line 76
   at Microsoft.VisualStudio.Services.Agent.Worker.Handlers.NodeHandler.RunAsync() in /mnt/vss/_work/1/s/src/Agent.Worker/Handlers/NodeHandler.cs:line 245
   at Microsoft.VisualStudio.Services.Agent.Worker.TaskRunner.RunAsyncInternal() in /mnt/vss/_work/1/s/src/Agent.Worker/TaskRunner.cs:line 454
   at Microsoft.VisualStudio.Services.Agent.Worker.TaskRunner.RunAsync() in /mnt/vss/_work/1/s/src/Agent.Worker/TaskRunner.cs:line 76
   at Microsoft.VisualStudio.Services.Agent.Worker.StepsRunner.RunStepAsync(IStep step, CancellationToken jobCancellationToken) in /mnt/vss/_work/1/s/src/Agent.Worker/StepsRunner.cs:line 264
2024-05-06T13:17:05.6805078Z ##[section]Finishing: Start background process via AzureCLI

Repro steps

# This is the definition of the job that is failing. Note, it references
# a service connection in my Azure DevOps project.
jobs:
- job: ViaAzureCLI
  displayName: Run via AzureCLI@2 task
  pool:
    vmImage: ubuntu-latest
  steps:
  - task: AzureCLI@2
    displayName: Start background process via AzureCLI
    inputs:
      scriptType: bash
      scriptLocation: inlineScript
      azureSubscription: test-service-principal
      addSpnToEnvironment: true
      inlineScript: |
        nohup npx --yes serve &
        echo "##vso[task.setvariable variable=_BackgroundProcessPid]${!}"

  - bash: echo $(_BackgroundProcessPid)
    displayName: Print background process PID

  - bash: ps | grep $(_BackgroundProcessPid)
    displayName: Search for background process

  - bash: kill $(_BackgroundProcessPid)
    displayName: Stop background process
mahomedalid commented 5 months ago

I am having this issue too, this is my inlineScript:

 inlineScript: |
      echo "* Starting proxy"
      az connectedk8s proxy --name $CLUSTER_NAME --resource-group $RESOURCE_GROUP --port 8001
      PID=$!
      echo "* Proxy started with PID $PID"
      # some deploy code
      echo "* Stopping proxy with PID $PID"
      kill $PID

I have also tried kill -9 $PID, no luck.

WebdeveloperIsaac commented 3 months ago

Hi Team,
Even I am Facing Similar Issue https://github.com/microsoft/azure-pipelines-tasks/issues/19844, The STDIO streams did not close within 10 seconds of the exit event from process '/usr/bin/bash'. This may indicate a child process inherited the STDIO streams and has not yet exited. In my Use Case I am Running a python Script from my azure pipeline which Internally Calls A python Script to Return Some Value which takes some 5 mins but during this Call, I am Facing this image I Have Already Tried adding this timeoutInMinutes: 30 as well So Do we Have Any Resolution on this or any Workaround also is fine. Please Drop A suggestion Thank you.

gracewehner commented 1 month ago

I am also facing the same exact issue