Azure-devops-cli-extension: Using devops commands in Azure Pipelines

Created on 25 Jun 2019  Â·  10Comments  Â·  Source: Azure/azure-devops-cli-extension

Describe the bug
The powershell plugin inside azure devops won't run "az devops project create". It keeps telling me there's an authentication error. I have logged in previously and run the "az pipelines create" command and that works just fine.

To Reproduce
create an azure devops multistage pipeline similar to this one. (using the azure cli won't work)
[---------------------------------------------------------------------------------------------------------]

Starter pipeline

trigger:

  • master

pool:
vmImage: 'ubuntu-latest'

steps:

[---------------------------------------------------------------------------------------------------------]

Azure-Devops extension version:
azure-cli 2.0.64 *

Steps to reproduce the behavior:

  1. login to azure devops
  2. create a new pipeline
  3. replace the hello world code in the .yml with the code above
  4. See error

Expected behavior
I should be able to create an azure devops project with this command using the powershell plugin.

image

question
Source
picture elderrollins

Most helpful comment

I am not sure what the difference was, but I copied and pasted your .yml file, changed the org to my org name, and it worked. So I think it was a synthax error, or magic. I'm banking on magic, because clearly it wasn't my fault. Anyways thanks for the help with this.

Here is the .yml file that finally worked for me.

trigger:

  • master

pool:
vmImage: 'ubuntu-latest'

steps:

  • task: PowerShell@2
    inputs:
    targetType: 'inline'
    script:
    az extension add --name azure-devops
  • task: PowerShell@2
    inputs:
    targetType: 'inline'
    script:
    az devops project create --name "test1223" --organization https://dev.azure.com/
    env:
    AZURE_DEVOPS_EXT_PAT: $(PAT)
picture elderrollins on 28 Jun 2019
😄2

All 10 comments

@elderrollins The following works for me which has minor changes compared to yours like 'echo' in the command and mostly formatting which might have messed up when you copy pasted yml to this issue.

In your script I would expect the log of command "$PAT" | az devops login --organization https://dev.azure.com/; failing first before the create project failure log which you posted, so it is hard to comment on what went wrong in your case.

trigger:
- master

pool:
  vmImage: 'ubuntu-latest'

steps:
- task: PowerShell@2
  inputs:
    targetType: 'inline'
    script: |
      az extension add --name azure-devops 
      echo $(PAT) | az devops login --organization https://dev.azure.com/testorg
      az devops project create --name test12345 --organization https://dev.azure.com/testorg

But I suggest you should prefer this route of environment variable compared to piped login. If the Environment variable is set as below you should be able to run commands without running the login command explicitly.

steps:
- task: PowerShell@2
  inputs:
    targetType: 'inline'
    script:
      az extension add --name azure-devops
      az devops project create --name "test1234" --organization https://dev.azure.com/testorg
  env:
    AZURE_DEVOPS_EXT_PAT: $(PAT)

This is NOT a bug. I will wait for your response before closing the issue.

Hope this helps!

atbagga picture atbagga on 25 Jun 2019

Still getting the same result. Here is the code I inputted based on your feedback.

[----------------------------------------------------------------------------------------------------------------------------------------------------------------]
steps:

  • task: PowerShell@2
    inputs:
    targetType: 'inline'
    script: 'az extension add --name azure-devops;
    az devops project create --name "test1234" --organization https://dev.azure.com/OrgName'
    env:
    AZURE_DEVOPS_EXT_PAT: $(PAT)
    [----------------------------------------------------------------------------------------------------------------------------------------------------------------]

Here is the result.
I have tried as many formats as I can think of, and any of the plugins that use the Azure CLI. None of them work. I Keep getting the same login error.

[cid:[email protected]]

From: Atul Bagga notifications@github.com
Sent: Tuesday, June 25, 2019 2:20 AM
To: Azure/azure-devops-cli-extension azure-devops-cli-extension@noreply.github.com
Cc: John Michael Rollins michael.rollins@churchofjesuschrist.org; Mention mention@noreply.github.com
Subject: Re: [Azure/azure-devops-cli-extension] Using devops commands in Azure Pipelines (#693)

@elderrollinshttps://nam01.safelinks.protection.outlook.com/?url=https%3A%2F%2Fgithub.com%2Felderrollins&data=02%7C01%7Cmichael.rollins%40churchofjesuschrist.org%7C836a3abfe8304194ab7808d6f945f964%7C61e6eeb35fd74aaaae3c61e8deb09b79%7C0%7C0%7C636970476280963452&sdata=qjRpgWW9wLbs89xK0q%2BuQSaIGyCNLC2IEaX9srZ17%2FQ%3D&reserved=0 The following works for me which has minor changes compared to yours like 'echo' in the command and mostly formatting which might have messed up when you copy pasted yml to this issue.

In your script I would expect the log of command "$PAT" | az devops login --organization https://dev.azure.com/https://nam01.safelinks.protection.outlook.com/?url=https%3A%2F%2Fdev.azure.com%2F&data=02%7C01%7Cmichael.rollins%40churchofjesuschrist.org%7C836a3abfe8304194ab7808d6f945f964%7C61e6eeb35fd74aaaae3c61e8deb09b79%7C0%7C0%7C636970476280963452&sdata=l4%2BVxio6MExl5aJPzpgtoPwGniM%2F3x4BamQ5vtLC%2B2c%3D&reserved=0; failing first before the create project failure log which you posted, so it is hard to comment on what went wrong in your case.

trigger:

  • master

pool:

vmImage: 'ubuntu-latest'

steps:

But I suggest you should prefer this route of environment variable compared to piped login. If the Environment variable is set as below you should be able to run commands without running the login command explicitly.

steps:

This is NOT a bug. I will wait for your response before closing the issue.

Hope this helps!

—
You are receiving this because you were mentioned.
Reply to this email directly, view it on GitHubhttps://nam01.safelinks.protection.outlook.com/?url=https%3A%2F%2Fgithub.com%2FAzure%2Fazure-devops-cli-extension%2Fissues%2F693%3Femail_source%3Dnotifications%26email_token%3DALSGNFYBIDATTZWA2F6FOO3P4HIMPA5CNFSM4H3DAQD2YY3PNVWWK3TUL52HS4DFVREXG43VMVBW63LNMVXHJKTDN5WW2ZLOORPWSZGODYPOCGI%23issuecomment-505340185&data=02%7C01%7Cmichael.rollins%40churchofjesuschrist.org%7C836a3abfe8304194ab7808d6f945f964%7C61e6eeb35fd74aaaae3c61e8deb09b79%7C0%7C0%7C636970476280983442&sdata=CVAUAjm5S5BN9K4WB1P3Z2txS0dH4oM5v482znPVeOE%3D&reserved=0, or mute the threadhttps://nam01.safelinks.protection.outlook.com/?url=https%3A%2F%2Fgithub.com%2Fnotifications%2Funsubscribe-auth%2FALSGNF5WVAWTD3GFSQEIBW3P4HIMPANCNFSM4H3DAQDQ&data=02%7C01%7Cmichael.rollins%40churchofjesuschrist.org%7C836a3abfe8304194ab7808d6f945f964%7C61e6eeb35fd74aaaae3c61e8deb09b79%7C0%7C0%7C636970476280993439&sdata=PNgJUvcsud%2FJxCRS1moV9T5jsgdK%2FiCxOD5zy8V7xQc%3D&reserved=0.

elderrollins picture elderrollins on 25 Jun 2019

Apparently replying on emails doesn't post the images on GitHub so not sure about your error still since I cannot see your message correctly.

Check this sample pipeline -

  1. Yaml file - https://dev.azure.com/atbagga/atbagga/_git/atbagga?path=%2Fazure-pipelines.yml&version=GBmaster&_a=contents
  2. Successful pipeline run - https://dev.azure.com/atbagga/atbagga/_build?definitionId=3&_a=summary

If you set the PAT variable with correct permissions (Minimum-Required _Code (Read); Project and Team (Read, write, & manage_). It should work.

If you still face issues share the full logs of the task running the commands with --debug flag. Remove any tokens and account names etc.

atbagga picture atbagga on 26 Jun 2019

My PAT has all access, and this is the error that’s being thrown. For this run I went to your .yml file, copied and pasted it then ran it. This is the error string that it came back with.

Starting: PowerShell

Task : PowerShell
Description : Run a PowerShell script on Linux, macOS, or Windows
Version : 2.151.1
Author : Microsoft Corporation

Help : https://docs.microsoft.com/azure/devops/pipelines/tasks/utility/powershell

Generating script.
========================== Starting Command Output ===========================
sr/bin/pwsh -NoLogo -NoProfile -NonInteractive -Command . '/home/vsts/work/_temp/541cf1cf-9e01-41df-9ce5-4877013f23ee.ps1'
ERROR: The command failed with an unexpected error. Here is the traceback:
ERROR: The requested resource requires user authentication: https://dev.azure.com/orgName/_apis/projects
Traceback (most recent call last):
File "/opt/az/lib/python3.6/site-packages/knack/cli.py", line 206, in invoke
cmd_result = self.invocation.execute(args)
File "/opt/az/lib/python3.6/site-packages/azure/cli/core/commands/__init__.py", line 560, in execute
raise ex
File "/opt/az/lib/python3.6/site-packages/azure/cli/core/commands/__init__.py", line 618, in _run_jobs_serially
results.append(self._run_job(expanded_arg, cmd_copy))
File "/opt/az/lib/python3.6/site-packages/azure/cli/core/commands/__init__.py", line 609, in _run_job
cmd_copy.exception_handler(ex)
File "/home/vsts/.azure/cliextensions/azure-devops/azext_devops/dev/common/exception_handler.py", line 26, in azure_devops_exception_handler
reraise(sys.exc_info())
File "/opt/az/lib/python3.6/site-packages/six.py", line 693, in reraise
raise value
File "/opt/az/lib/python3.6/site-packages/azure/cli/core/commands/__init__.py", line 588, in _run_job
result = cmd_copy(params)
File "/opt/az/lib/python3.6/site-packages/azure/cli/core/commands/__init__.py", line 297, in __call__
return self.handler(args, kwargs)
File "/opt/az/lib/python3.6/site-packages/azure/cli/core/__init__.py", line 461, in default_command_handler
return op(command_args)
File "/home/vsts/.azure/cliextensions/azure-devops/azext_devops/dev/team/project.py", line 74, in create_project
operation_reference = core_client.queue_create_project(project_to_create=team_project)
File "/home/vsts/.azure/cliextensions/azure-devops/azext_devops/devops_sdk/v5_0/core/core_client.py", line 151, in queue_create_project
content=content)
File "/home/vsts/.azure/cliextensions/azure-devops/azext_devops/devops_sdk/client.py", line 90, in _send
response = self._send_request(request=request, headers=headers, content=content, media_type=media_type)
File "/home/vsts/.azure/cliextensions/azure-devops/azext_devops/devops_sdk/client.py", line 54, in _send_request
self._handle_error(request, response)
File "/home/vsts/.azure/cliextensions/azure-devops/azext_devops/devops_sdk/client.py", line 254, in _handle_error
url=request.url))
azext_devops.devops_sdk.exceptions.AzureDevOpsAuthenticationError: The requested resource requires user authentication: https://dev.azure.com/orgName/_apis/projects
WARNING:
To open an issue, please run: 'az feedback'

[error]PowerShell exited with code '1'.

Finishing: PowerShell

From: Atul Bagga notifications@github.com
Sent: Wednesday, June 26, 2019 12:19 AM
To: Azure/azure-devops-cli-extension azure-devops-cli-extension@noreply.github.com
Subject: Re: [Azure/azure-devops-cli-extension] Using devops commands in Azure Pipelines (#693)

Apparently replying on emails doesn't post the images on GitHub so not sure about your error still since I cannot see your message correctly.

Check this sample pipeline -

  1. Yaml file - https://dev.azure.com/atbagga/atbagga/_git/atbagga?path=%2Fazure-pipelines.yml&version=GBmaster&_a=contentshttps://nam01.safelinks.protection.outlook.com/?url=https%3A%2F%2Fdev.azure.com%2Fatbagga%2Fatbagga%2F_git%2Fatbagga%3Fpath%3D%252Fazure-pipelines.yml%26version%3DGBmaster%26_a%3Dcontents&data=02%7C01%7Cmichael.rollins%40churchofjesuschrist.org%7Cb33206d585b74ddcfe7908d6f9fe2bd8%7C61e6eeb35fd74aaaae3c61e8deb09b79%7C0%7C0%7C636971267397571145&sdata=f21Xipj6irpjKYYSqbhezB2JmGzoWyYTN6CIb8%2F6N1A%3D&reserved=0
  2. Successful pipeline run - https://dev.azure.com/atbagga/atbagga/_build?definitionId=3&_a=summaryhttps://nam01.safelinks.protection.outlook.com/?url=https%3A%2F%2Fdev.azure.com%2Fatbagga%2Fatbagga%2F_build%3FdefinitionId%3D3%26_a%3Dsummary&data=02%7C01%7Cmichael.rollins%40churchofjesuschrist.org%7Cb33206d585b74ddcfe7908d6f9fe2bd8%7C61e6eeb35fd74aaaae3c61e8deb09b79%7C0%7C0%7C636971267397571145&sdata=jCmW9WEY9zVtlcanbGS3r1Wu3bOOJ0%2FHsWxA3W7fE84%3D&reserved=0

If you set the PAT variable with correct permissions (Minimum-Required Code (Read); Project and Team (Read, write, & manage). It should work.

If you still face issues share the full logs of the task running the commands with --debug flag. Remove any tokens and account names etc.

—
You are receiving this because you were mentioned.
Reply to this email directly, view it on GitHubhttps://nam01.safelinks.protection.outlook.com/?url=https%3A%2F%2Fgithub.com%2FAzure%2Fazure-devops-cli-extension%2Fissues%2F693%3Femail_source%3Dnotifications%26email_token%3DALSGNF3NIKZZRBC273PRJP3P4MC47A5CNFSM4H3DAQD2YY3PNVWWK3TUL52HS4DFVREXG43VMVBW63LNMVXHJKTDN5WW2ZLOORPWSZGODYSOV3Y%23issuecomment-505735919&data=02%7C01%7Cmichael.rollins%40churchofjesuschrist.org%7Cb33206d585b74ddcfe7908d6f9fe2bd8%7C61e6eeb35fd74aaaae3c61e8deb09b79%7C0%7C0%7C636971267397581144&sdata=s9EU8VBKKm3wb8bPL6cy7%2Bu0zkjWp%2BnXz2dS4u6huOA%3D&reserved=0, or mute the threadhttps://nam01.safelinks.protection.outlook.com/?url=https%3A%2F%2Fgithub.com%2Fnotifications%2Funsubscribe-auth%2FALSGNF3YVV43ZCS4MMOI62LP4MC47ANCNFSM4H3DAQDQ&data=02%7C01%7Cmichael.rollins%40churchofjesuschrist.org%7Cb33206d585b74ddcfe7908d6f9fe2bd8%7C61e6eeb35fd74aaaae3c61e8deb09b79%7C0%7C0%7C636971267397581144&sdata=uDEL8aRlYZvTSZCinDDC5tAQd3cvXFI2VRQccjClQ8c%3D&reserved=0.

elderrollins picture elderrollins on 26 Jun 2019

image

elderrollins picture elderrollins on 27 Jun 2019

Here's the feedback I get no matter which synthax I use.

elderrollins picture elderrollins on 27 Jun 2019

Here's the feedback from the debug

2019-06-27T16:13:56.3029708Z ##[section]Starting: Job
2019-06-27T16:13:56.5622131Z ##[section]Starting: Initialize job
2019-06-27T16:13:56.5622325Z Current agent version: '2.153.2'
2019-06-27T16:13:56.5785945Z Prepare build directory.
2019-06-27T16:13:56.6014758Z Set build variables.
2019-06-27T16:13:56.6056612Z Download all required tasks.
2019-06-27T16:13:56.6201975Z Downloading task: PowerShell
2019-06-27T16:13:57.5904830Z Start tracking orphan processes.
2019-06-27T16:13:57.6018296Z ##[section]Finishing: Initialize job
2019-06-27T16:13:57.6486277Z ##[section]Starting: Checkout
2019-06-27T16:13:57.6720712Z ==============================================================================
2019-06-27T16:13:57.6720799Z Task : Get sources
2019-06-27T16:13:57.6720857Z Description : Get sources from a repository. Supports Git, TfsVC, and SVN repositories.
2019-06-27T16:13:57.6720895Z Version : 1.0.0
2019-06-27T16:13:57.6720930Z Author : Microsoft
2019-06-27T16:13:57.6720975Z Help : More Information
2019-06-27T16:13:57.6721046Z ==============================================================================
2019-06-27T16:13:58.1973835Z Syncing repository: repoName (Git)
2019-06-27T16:13:58.9071211Z ##[command]git version
2019-06-27T16:13:59.5504613Z git version 2.21.0
2019-06-27T16:13:59.5506763Z ##[command]git lfs version
2019-06-27T16:13:59.9287976Z git-lfs/2.7.2 (GitHub; linux amd64; go 1.12.4)
2019-06-27T16:13:59.9608265Z ##[command]git init "/home/vsts/work/1/s"
2019-06-27T16:14:00.015xxx9Z Initialized empty Git repository in /home/vsts/work/1/s/.git/
2019-06-27T16:14:00.0195205Z ##[command]git remote add origin https://[email protected]/orgName/projectName/_git/repoName
2019-06-27T16:14:00.0421898Z ##[command]git config gc.auto 0
2019-06-27T16:14:00.0493581Z ##[command]git config --get-all http.https://[email protected]/orgName/projectName/_git/repoName.extraheader
2019-06-27T16:14:00.0553159Z ##[command]git config --get-all http.proxy
2019-06-27T16:14:00.0685013Z ##[command]git -c http.extraheader="AUTHORIZATION: bearer " fetch --force --tags --prune --progress --no-recurse-submodules origin
2019-06-27T16:14:00.7158153Z remote: Azure Repos
2019-06-27T16:14:00.9634604Z remote:
2019-06-27T16:14:00.9635082Z remote: Found 559 objects to send. (248 ms)
2019-06-27T16:14:00.9827144Z Receiving objects: 0% (1/559)
2019-06-27T16:14:00.9828957Z Receiving objects: 1% (6/559)
2019-06-27T16:14:00.9831009Z Receiving objects: 2% (12/559)
2019-06-27T16:14:00.9833316Z Receiving objects: 3% (17/559)
2019-06-27T16:14:00.9836200Z Receiving objects: 4% (23/559)
2019-06-27T16:14:00.9838811Z Receiving objects: 5% (28/559)
2019-06-27T16:14:00.9840752Z Receiving objects: 6% (34/559)
2019-06-27T16:14:00.9843876Z Receiving objects: 7% (40/559)
2019-06-27T16:14:00.9846629Z Receiving objects: 8% (45/559)
2019-06-27T16:14:00.9848594Z Receiving objects: 9% (51/559)
2019-06-27T16:14:00.9850204Z Receiving objects: 10% (56/559)
2019-06-27T16:14:00.9852833Z Receiving objects: 11% (62/559)
2019-06-27T16:14:00.9855944Z Receiving objects: 12% (68/559)
2019-06-27T16:14:00.9857576Z Receiving objects: 13% (73/559)
2019-06-27T16:14:00.9859740Z Receiving objects: 14% (79/559)
2019-06-27T16:14:00.9862164Z Receiving objects: 15% (84/559)
2019-06-27T16:14:00.9864127Z Receiving objects: 16% (90/559)
2019-06-27T16:14:00.9866565Z Receiving objects: 17% (96/559)
2019-06-27T16:14:00.9868187Z Receiving objects: 18% (101/559)
2019-06-27T16:14:00.9870146Z Receiving objects: 19% (107/559)
2019-06-27T16:14:00.9872888Z Receiving objects: 20% (112/559)
2019-06-27T16:14:00.9874631Z Receiving objects: 21% (118/559)
2019-06-27T16:14:00.9876671Z Receiving objects: 22% (123/559)
2019-06-27T16:14:00.9878337Z Receiving objects: 23% (129/559)
2019-06-27T16:14:00.9879867Z Receiving objects: 24% (135/559)
2019-06-27T16:14:00.9882463Z Receiving objects: 25% (140/559)
2019-06-27T16:14:00.9884413Z Receiving objects: 26% (146/559)
2019-06-27T16:14:00.9886651Z Receiving objects: 27% (151/559)
2019-06-27T16:14:00.9888565Z Receiving objects: 28% (157/559)
2019-06-27T16:14:00.9890140Z Receiving objects: 29% (163/559)
2019-06-27T16:14:00.9892959Z Receiving objects: 30% (168/559)
2019-06-27T16:14:00.9896133Z Receiving objects: 31% (174/559)
2019-06-27T16:14:00.9897804Z Receiving objects: 32% (179/559)
2019-06-27T16:14:00.9899544Z Receiving objects: 33% (185/559)
2019-06-27T16:14:00.9902040Z Receiving objects: 34% (191/559)
2019-06-27T16:14:00.9905065Z Receiving objects: 35% (196/559)
2019-06-27T16:14:00.9905282Z Receiving objects: 36% (202/559)
2019-06-27T16:14:00.9907752Z Receiving objects: 37% (207/559)
2019-06-27T16:14:00.9909387Z Receiving objects: 38% (213/559)
2019-06-27T16:14:00.9911621Z Receiving objects: 39% (219/559)
2019-06-27T16:14:00.9914053Z Receiving objects: 40% (224/559)
2019-06-27T16:14:00.9914249Z Receiving objects: 41% (230/559)
2019-06-27T16:14:00.9958560Z Receiving objects: 42% (235/559)
2019-06-27T16:14:01.1277126Z Receiving objects: 43% (241/559)
2019-06-27T16:14:01.1316782Z Receiving objects: 44% (246/559)
2019-06-27T16:14:01.1317882Z Receiving objects: 45% (252/559)
2019-06-27T16:14:01.1318195Z Receiving objects: 46% (258/559)
2019-06-27T16:14:01.1318810Z Receiving objects: 47% (263/559)
2019-06-27T16:14:01.1318882Z Receiving objects: 48% (269/559)
2019-06-27T16:14:01.1318939Z Receiving objects: 49% (274/559)
2019-06-27T16:14:01.1366471Z Receiving objects: 50% (280/559)
2019-06-27T16:14:01.1370338Z Receiving objects: 51% (286/559)
2019-06-27T16:14:01.1371043Z Receiving objects: 52% (291/559)
2019-06-27T16:14:01.1371139Z Receiving objects: 53% (297/559)
2019-06-27T16:14:01.1371261Z Receiving objects: 54% (302/559)
2019-06-27T16:14:01.1371318Z Receiving objects: 55% (308/559)
2019-06-27T16:14:01.1371569Z Receiving objects: 56% (314/559)
2019-06-27T16:14:01.1372658Z Receiving objects: 57% (319/559)
2019-06-27T16:14:01.1372757Z Receiving objects: 58% (325/559)
2019-06-27T16:14:01.1373342Z Receiving objects: 59% (330/559)
2019-06-27T16:14:01.1374444Z Receiving objects: 60% (336/559)
2019-06-27T16:14:01.1374701Z Receiving objects: 61% (341/559)
2019-06-27T16:14:01.1409882Z Receiving objects: 62% (347/559)
2019-06-27T16:14:01.1413343Z Receiving objects: 63% (353/559)
2019-06-27T16:14:01.1414946Z Receiving objects: 64% (358/559)
2019-06-27T16:14:01.1416930Z Receiving objects: 65% (364/559)
2019-06-27T16:14:01.1418343Z Receiving objects: 66% (369/559)
2019-06-27T16:14:01.1419524Z Receiving objects: 67% (375/559)
2019-06-27T16:14:01.1426326Z Receiving objects: 68% (381/559)
2019-06-27T16:14:01.1426448Z Receiving objects: 69% (386/559)
2019-06-27T16:14:01.1426484Z Receiving objects: 70% (392/559)
2019-06-27T16:14:01.1426575Z Receiving objects: 71% (397/559)
2019-06-27T16:14:01.1426610Z Receiving objects: 72% (403/559)
2019-06-27T16:14:01.1426659Z Receiving objects: 73% (409/559)
2019-06-27T16:14:01.1426731Z Receiving objects: 74% (414/559)
2019-06-27T16:14:01.1426766Z Receiving objects: 75% (420/559)
2019-06-27T16:14:01.1426800Z Receiving objects: 76% (425/559)
2019-06-27T16:14:01.1426874Z Receiving objects: 77% (431/559)
2019-06-27T16:14:01.1426909Z Receiving objects: 78% (437/559)
2019-06-27T16:14:01.1426943Z Receiving objects: 79% (442/559)
2019-06-27T16:14:01.1426984Z Receiving objects: 80% (448/559)
2019-06-27T16:14:01.1427059Z Receiving objects: 81% (453/559)
2019-06-27T16:14:01.1427093Z Receiving objects: 82% (459/559)
2019-06-27T16:14:01.1427127Z Receiving objects: 83% (464/559)
2019-06-27T16:14:01.1427200Z Receiving objects: 84% (470/559)
2019-06-27T16:14:01.1427233Z Receiving objects: 85% (476/559)
2019-06-27T16:14:01.1427267Z Receiving objects: 86% (481/559)
2019-06-27T16:14:01.1427339Z Receiving objects: 87% (487/559)
2019-06-27T16:14:01.1427374Z Receiving objects: 88% (492/559)
2019-06-27T16:14:01.1427617Z Receiving objects: 89% (498/559)
2019-06-27T16:14:01.1427690Z Receiving objects: 90% (504/559)
2019-06-27T16:14:01.1427725Z Receiving objects: 91% (509/559)
2019-06-27T16:14:01.1427758Z Receiving objects: 92% (515/559)
2019-06-27T16:14:01.1427791Z Receiving objects: 93% (520/559)
2019-06-27T16:14:01.1427865Z Receiving objects: 94% (526/559)
2019-06-27T16:14:01.1427899Z Receiving objects: 95% (532/559)
2019-06-27T16:14:01.1428142Z Receiving objects: 96% (537/559)
2019-06-27T16:14:01.1428225Z Receiving objects: 97% (543/559)
2019-06-27T16:14:01.1428260Z Receiving objects: 98% (548/559)
2019-06-27T16:14:01.1428295Z Receiving objects: 99% (554/559)
2019-06-27T16:14:01.1428367Z Receiving objects: 100% (559/559)
2019-06-27T16:14:01.1428406Z Receiving objects: 100% (559/559), 151.65 KiB | 8.92 MiB/s, done.
2019-06-27T16:14:01.1429131Z From https://dev.azure.com/orgName/projectName/_git/repoName
2019-06-27T16:14:01.1429402Z * [new branch] master -> origin/master
2019-06-27T16:14:01.2330680Z ##[command]git checkout --progress --force bxxxxxxxxxxxxxx3c
2019-06-27T16:14:01.2333010Z Note: checking out 'bxxxxxxxxxxxxxx3c'.
2019-06-27T16:14:01.2333061Z
2019-06-27T16:14:01.2333306Z You are in 'detached HEAD' state. You can look around, make experimental
2019-06-27T16:14:01.2333413Z changes and commit them, and you can discard any commits you make in this
2019-06-27T16:14:01.2333467Z state without impacting any branches by performing another checkout.
2019-06-27T16:14:01.2333507Z
2019-06-27T16:14:01.2333555Z If you want to create a new branch to retain commits you create, you may
2019-06-27T16:14:01.2333807Z do so (now or later) by using -b with the checkout command again. Example:
2019-06-27T16:14:01.2333842Z
2019-06-27T16:14:01.2334055Z git checkout -b
2019-06-27T16:14:01.2334086Z
2019-06-27T16:14:01.2334320Z HEAD is now at bxxxx3 Update azure-pipelines.yml for Azure Pipelines
2019-06-27T16:14:01.2403380Z ##[section]Finishing: Checkout
2019-06-27T16:14:01.2419753Z ##[section]Starting: PowerShell
2019-06-27T16:14:01.2423400Z ==============================================================================
2019-06-27T16:14:01.2423460Z Task : PowerShell
2019-06-27T16:14:01.2423516Z Description : Run a PowerShell script on Linux, macOS, or Windows
2019-06-27T16:14:01.2423563Z Version : 2.151.1
2019-06-27T16:14:01.2423607Z Author : Microsoft Corporation
2019-06-27T16:14:01.2423667Z Help : https://docs.microsoft.com/azure/devops/pipelines/tasks/utility/powershell
2019-06-27T16:14:01.2423718Z ==============================================================================
2019-06-27T16:14:03.5419716Z Generating script.
2019-06-27T16:14:03.5440440Z ========================== Starting Command Output ===========================
2019-06-27T16:14:03.5488937Z [command]/usr/bin/pwsh -NoLogo -NoProfile -NonInteractive -Command . '/home/vsts/work/_temp/fxxxxxxx3.ps1'
2019-06-27T16:14:21.1019791Z DEBUG: Command arguments: ['devops', 'project', 'create', '--name', 'test2', '--organization', 'https://dev.azure.com/orgName', '--debug']
2019-06-27T16:14:21.1020556Z DEBUG: Event: Cli.PreExecute []
2019-06-27T16:14:21.1020819Z DEBUG: Event: CommandParser.OnGlobalArgumentsCreate [, , ]
2019-06-27T16:14:21.1202368Z DEBUG: Event: CommandInvoker.OnPreCommandTableCreate []
2019-06-27T16:14:21.1229259Z DEBUG: Installed command modules ['acr', 'acs', 'advisor', 'ams', 'appservice', 'backup', 'batch', 'batchai', 'billing', 'botservice', 'cdn', 'cloud', 'cognitiveservices', 'configure', 'consumption', 'container', 'cosmosdb', 'deploymentmanager', 'dla', 'dls', 'dms', 'eventgrid', 'eventhubs', 'extension', 'feedback', 'find', 'hdinsight', 'interactive', 'iot', 'iotcentral', 'keyvault', 'kusto', 'lab', 'maps', 'monitor', 'natgateway', 'network', 'policyinsights', 'privatedns', 'profile', 'rdbms', 'redis', 'relay', 'reservations', 'resource', 'role', 'search', 'security', 'servicebus', 'servicefabric', 'signalr', 'sql', 'sqlvm', 'storage', 'vm']
2019-06-27T16:14:21.1278329Z DEBUG: Loaded module 'acr' in 0.005 seconds.
2019-06-27T16:14:21.1422313Z DEBUG: Loaded module 'acs' in 0.014 seconds.
2019-06-27T16:14:22.0548100Z DEBUG: Loaded module 'advisor' in 0.002 seconds.
2019-06-27T16:14:22.0548431Z DEBUG: Event: CommandLoader.OnLoadCommandTable []
2019-06-27T16:14:22.0553815Z DEBUG: Loaded module 'ams' in 0.005 seconds.
2019-06-27T16:14:22.0554515Z DEBUG: Loaded module 'appservice' in 0.007 seconds.
2019-06-27T16:14:22.0555203Z DEBUG: Loaded module 'backup' in 0.002 seconds.
2019-06-27T16:14:22.0556093Z DEBUG: Event: CommandLoader.OnLoadCommandTable []
2019-06-27T16:14:22.0557582Z DEBUG: Loaded module 'batch' in 0.008 seconds.
2019-06-27T16:14:22.0558069Z DEBUG: Loaded module 'batchai' in 0.002 seconds.
2019-06-27T16:14:22.0559317Z DEBUG: Loaded module 'billing' in 0.001 seconds.
2019-06-27T16:14:22.0560259Z DEBUG: Loaded module 'botservice' in 0.003 seconds.
2019-06-27T16:14:22.0560511Z DEBUG: Event: CommandLoader.OnLoadCommandTable []
2019-06-27T16:14:22.0560846Z DEBUG: Loaded module 'cdn' in 0.002 seconds.
2019-06-27T16:14:22.0561337Z DEBUG: Loaded module 'cloud' in 0.001 seconds.
2019-06-27T16:14:22.0562502Z DEBUG: Loaded module 'cognitiveservices' in 0.001 seconds.
2019-06-27T16:14:22.0563058Z DEBUG: Loaded module 'configure' in 0.001 seconds.
2019-06-27T16:14:22.0563561Z DEBUG: Loaded module 'consumption' in 0.002 seconds.
2019-06-27T16:14:22.0564008Z DEBUG: Loaded module 'container' in 0.001 seconds.
2019-06-27T16:14:22.056xxx6Z DEBUG: Loaded module 'cosmosdb' in 0.003 seconds.
2019-06-27T16:14:22.0564916Z DEBUG: Loaded module 'deploymentmanager' in 0.002 seconds.
2019-06-27T16:14:22.0565537Z DEBUG: Loaded module 'dla' in 0.004 seconds.
2019-06-27T16:14:22.0566461Z DEBUG: Loaded module 'dls' in 0.003 seconds.
2019-06-27T16:14:22.0567001Z DEBUG: Loaded module 'dms' in 0.002 seconds.
2019-06-27T16:14:22.0567603Z DEBUG: Loaded module 'eventgrid' in 0.002 seconds.
2019-06-27T16:14:22.0568002Z DEBUG: Loaded module 'eventhubs' in 0.003 seconds.
2019-06-27T16:14:22.0568355Z DEBUG: Loaded module 'extension' in 0.001 seconds.
2019-06-27T16:14:22.0568693Z DEBUG: Loaded module 'feedback' in 0.000 seconds.
2019-06-27T16:14:22.0569082Z DEBUG: Loaded module 'find' in 0.001 seconds.
2019-06-27T16:14:22.0569430Z DEBUG: Loaded module 'hdinsight' in 0.002 seconds.
2019-06-27T16:14:22.0569983Z DEBUG: Loaded module 'interactive' in 0.000 seconds.
2019-06-27T16:14:22.0570304Z DEBUG: Loaded module 'iot' in 0.003 seconds.
2019-06-27T16:14:22.0570874Z DEBUG: Loaded module 'iotcentral' in 0.001 seconds.
2019-06-27T16:14:22.0571215Z DEBUG: Loaded module 'keyvault' in 0.005 seconds.
2019-06-27T16:14:22.0572199Z DEBUG: Loaded module 'kusto' in 0.001 seconds.
2019-06-27T16:14:22.0572699Z DEBUG: Loaded module 'lab' in 0.004 seconds.
2019-06-27T16:14:22.0573234Z DEBUG: Loaded module 'maps' in 0.001 seconds.
2019-06-27T16:14:22.0573659Z DEBUG: Loaded module 'monitor' in 0.004 seconds.
2019-06-27T16:14:22.0574134Z DEBUG: Loaded module 'natgateway' in 0.001 seconds.
2019-06-27T16:14:22.0574572Z DEBUG: Loaded module 'network' in 0.026 seconds.
2019-06-27T16:14:22.0575055Z DEBUG: Loaded module 'policyinsights' in 0.001 seconds.
2019-06-27T16:14:22.0575580Z DEBUG: Loaded module 'privatedns' in 0.004 seconds.
2019-06-27T16:14:22.0575910Z DEBUG: Loaded module 'profile' in 0.001 seconds.
2019-06-27T16:14:22.0576296Z DEBUG: Loaded module 'rdbms' in 0.005 seconds.
2019-06-27T16:14:22.0576620Z DEBUG: Loaded module 'redis' in 0.002 seconds.
2019-06-27T16:14:22.0576995Z DEBUG: Loaded module 'relay' in 0.003 seconds.
2019-06-27T16:14:22.0577335Z DEBUG: Loaded module 'reservations' in 0.001 seconds.
2019-06-27T16:14:22.0577668Z DEBUG: Loaded module 'resource' in 0.006 seconds.
2019-06-27T16:14:22.0578043Z DEBUG: Loaded module 'role' in 0.004 seconds.
2019-06-27T16:14:22.0578775Z DEBUG: Loaded module 'search' in 0.001 seconds.
2019-06-27T16:14:22.0579154Z DEBUG: Loaded module 'security' in 0.002 seconds.
2019-06-27T16:14:22.0579486Z DEBUG: Loaded module 'servicebus' in 0.004 seconds.
2019-06-27T16:14:22.0579815Z DEBUG: Loaded module 'servicefabric' in 0.002 seconds.
2019-06-27T16:14:22.0580134Z DEBUG: Loaded module 'signalr' in 0.001 seconds.
2019-06-27T16:14:22.0580548Z DEBUG: Loaded module 'sql' in 0.005 seconds.
2019-06-27T16:14:22.0580876Z DEBUG: Loaded module 'sqlvm' in 0.002 seconds.
2019-06-27T16:14:22.0581034Z DEBUG: Event: CommandLoader.OnLoadCommandTable []
2019-06-27T16:14:22.0581321Z DEBUG: Loaded module 'storage' in 0.028 seconds.
2019-06-27T16:14:22.0582200Z DEBUG: Loaded module 'vm' in 0.012 seconds.
2019-06-27T16:14:22.0582795Z DEBUG: Loaded all modules in 0.211 seconds. (note: there's always an overhead with the first module loaded)
2019-06-27T16:14:22.0583255Z DEBUG: Extensions directory: '/home/vsts/.azure/cliextensions'
2019-06-27T16:14:22.0583688Z DEBUG: Found 1 extensions: ['azure-devops']
2019-06-27T16:14:22.0584127Z DEBUG: Extensions directory: '/home/vsts/.azure/cliextensions'
2019-06-27T16:14:22.0584342Z DEBUG: Extension compatibility result: is_compatible=True cli_core_version=2.0.66 min_required=2.0.49 max_required=None
2019-06-27T16:14:22.0584846Z DEBUG: Extensions directory: '/home/vsts/.azure/cliextensions'
2019-06-27T16:14:22.0585729Z DEBUG: Loaded extension 'azure-devops' in 0.077 seconds.
2019-06-27T16:14:22.0585894Z DEBUG: Event: CommandInvoker.OnPreCommandTableTruncate []
2019-06-27T16:14:22.0586262Z INFO: az_command_data_logger : command args: devops project create --name {} --organization {} --debug
2019-06-27T16:14:22.0586645Z DEBUG: metadata file logging enabled - writing logs to '/home/vsts/.azure/commands'.
2019-06-27T16:14:22.0586987Z DEBUG: Event: CommandInvoker.OnPostCommandTableCreate [.add_subscription_parameter at 0x7xxxxx0>, .add_ids_arguments at 0x7xxxxx8>, .add_cache_arguments at 0x7xxxxxxx0>]
2019-06-27T16:14:22.0587213Z DEBUG: Event: CommandInvoker.OnCommandTableLoaded []
2019-06-27T16:14:22.0587342Z DEBUG: Event: CommandInvoker.OnPreParseArgs []
2019-06-27T16:14:22.0587687Z DEBUG: Event: CommandInvoker.OnPostParseArgs [, , .parse_ids_arguments at 0x7xxxxx0>, , ]
2019-06-27T16:14:22.0588124Z DEBUG: Extensions directory: '/home/vsts/.azure/cliextensions'
2019-06-27T16:14:22.0588481Z DEBUG: Extensions directory: '/home/vsts/.azure/cliextensions'
2019-06-27T16:14:22.0588871Z INFO: az_command_data_logger : extension name: azure-devops
2019-06-27T16:14:22.0589080Z INFO: az_command_data_logger : extension version: 0.11.0
2019-06-27T16:14:22.0589247Z DEBUG: PAT is present which can be used against this instance
2019-06-27T16:14:22.0589360Z DEBUG: Current cloud config:
2019-06-27T16:14:22.0589466Z AzureCloud
2019-06-27T16:14:22.0589570Z DEBUG: az login is not present
2019-06-27T16:14:22.0589723Z DEBUG: There are no active accounts.
2019-06-27T16:14:22.0589878Z Traceback (most recent call last):
2019-06-27T16:14:22.0590235Z File "/opt/az/lib/python3.6/site-packages/azure/cli/core/_profile.py", line 475, in get_current_account_user
2019-06-27T16:14:22.0590401Z active_account = self.get_subscription()
2019-06-27T16:14:22.0590946Z File "/opt/az/lib/python3.6/site-packages/azure/cli/core/_profile.py", line 484, in get_subscription
2019-06-27T16:14:22.0591272Z raise CLIError(_AZ_LOGIN_MESSAGE)
2019-06-27T16:14:22.0592189Z knack.util.CLIError: Please run 'az login' to setup account.
2019-06-27T16:14:22.0592560Z
2019-06-27T16:14:22.0592733Z During handling of the above exception, another exception occurred:
2019-06-27T16:14:22.0592928Z
2019-06-27T16:14:22.0593068Z Traceback (most recent call last):
2019-06-27T16:14:22.0593543Z File "/home/vsts/.azure/cliextensions/azure-devops/azext_devops/dev/common/services.py", line 61, in _get_credentials
2019-06-27T16:14:22.0593811Z token_from_az_login = get_token_from_az_logins(organization, pat_token_present)
2019-06-27T16:14:22.0594330Z File "/home/vsts/.azure/cliextensions/azure-devops/azext_devops/dev/common/services.py", line 118, in get_token_from_az_logins
2019-06-27T16:14:22.0594544Z dummy_user = profile.get_current_account_user() # noqa: F841
2019-06-27T16:14:22.0594990Z File "/opt/az/lib/python3.6/site-packages/azure/cli/core/_profile.py", line 477, in get_current_account_user
2019-06-27T16:14:22.0595535Z raise CLIError('There are no active accounts.')
2019-06-27T16:14:22.0595734Z knack.util.CLIError: There are no active accounts.
2019-06-27T16:14:22.0595872Z INFO: received PAT from environment variable
2019-06-27T16:14:22.0595982Z INFO: Creating connection with personal access token.
2019-06-27T16:14:22.0596141Z DEBUG: msrest.universal_http.requests : Configuring retry: max_retries=3, backoff_factor=0.8, max_backoff=90
2019-06-27T16:14:22.0596297Z DEBUG: Current cloud config:
2019-06-27T16:14:22.0596403Z AzureCloud
2019-06-27T16:14:22.0596513Z DEBUG: Azure devops telemetry enabled.
2019-06-27T16:14:22.0596624Z DEBUG: Logging telemetry to azure devops server.
2019-06-27T16:14:22.0596773Z DEBUG: msrest.universal_http.requests : Configuring retry: max_retries=3, backoff_factor=0.8, max_backoff=90
2019-06-27T16:14:22.0597175Z DEBUG: azext_devops.devops_sdk._file_cache : Cache file does not exist: /home/vsts/.azure-devops/python-sdk/cache/resources.json
2019-06-27T16:14:22.0597553Z DEBUG: azext_devops.devops_sdk.connection : File cache miss for resources on: https://dev.azure.com/orgName
2019-06-27T16:14:22.0598027Z DEBUG: azext_devops.devops_sdk._file_cache : Cache file does not exist: /home/vsts/.azure-devops/python-sdk/cache/options.json
2019-06-27T16:14:22.0598433Z DEBUG: azext_devops.devops_sdk.client : File cache miss for options on: https://dev.azure.com/orgName
2019-06-27T16:14:22.0598730Z DEBUG: msrest.universal_http.requests : Configuring retry: max_retries=3, backoff_factor=0.8, max_backoff=90
2019-06-27T16:14:22.0599053Z DEBUG: azext_devops.devops_sdk.client : OPTIONS https://dev.azure.com/orgName/_apis
2019-06-27T16:14:22.0599405Z DEBUG: azext_devops.devops_sdk.client : File cache miss for options on: https://dev.azure.com/orgName
2019-06-27T16:14:22.0599569Z DEBUG: msrest.universal_http : Configuring redirects: allow=True, max=30
2019-06-27T16:14:22.0599737Z DEBUG: msrest.universal_http : Configuring request: timeout=100, verify=True, cert=None
2019-06-27T16:14:22.0600047Z DEBUG: azext_devops.devops_sdk.client : OPTIONS https://dev.azure.com/orgName/_apis
2019-06-27T16:14:22.0600425Z DEBUG: msrest.universal_http : Configuring proxies: ''
2019-06-27T16:14:22.0600602Z DEBUG: msrest.universal_http : Configuring redirects: allow=True, max=30
2019-06-27T16:14:22.0600768Z DEBUG: msrest.universal_http : Configuring request: timeout=100, verify=True, cert=None
2019-06-27T16:14:22.0600893Z DEBUG: msrest.universal_http : Evaluate proxies against ENV settings: True
2019-06-27T16:14:22.0601951Z DEBUG: msrest.universal_http : Configuring proxies: ''
2019-06-27T16:14:22.0602224Z DEBUG: msrest.universal_http : Evaluate proxies against ENV settings: True
2019-06-27T16:14:22.0602386Z DEBUG: urllib3.connectionpool : Starting new HTTPS connection (1): dev.azure.com:xxx
2019-06-27T16:14:22.0602596Z DEBUG: urllib3.connectionpool : Starting new HTTPS connection (1): dev.azure.com:xxx
2019-06-27T16:14:22.0603068Z DEBUG: urllib3.connectionpool : https://dev.azure.com:xxx "OPTIONS /orgName/_apis HTTP/1.1" 200 36827
2019-06-27T16:14:22.1023755Z DEBUG: azext_devops.devops_sdk.client : Response content:
2019-06-27T16:14:22.0789493Z DEBUG: azext_devops.devops_sdk.client : Response content:
2019-06-27T16:14:22.0607201Z DEBUG: urllib3.connectionpool : https://dev.azure.com:xxx "OPTIONS /orgName/_apis HTTP/1.1" 200 36792
2019-06-27T16:14:22.1070809Z DEBUG: azext_devops.devops_sdk.client : Route template: _apis/{resource}/{areaId}
2019-06-27T16:14:22.1072009Z DEBUG: azext_devops.devops_sdk.client : Api version '5.0-preview.1'
2019-06-27T16:14:22.1072417Z DEBUG: azext_devops.devops_sdk.client : GET https://dev.azure.com/orgName/_apis/ResourceAreas
2019-06-27T16:14:22.1072483Z DEBUG: azext_devops.devops_sdk.client : Request content: None
2019-06-27T16:14:22.1072542Z DEBUG: msrest.universal_http : Configuring redirects: allow=True, max=30
2019-06-27T16:14:22.1072643Z DEBUG: msrest.universal_http : Configuring request: timeout=100, verify=True, cert=None
2019-06-27T16:14:22.1073064Z DEBUG: msrest.universal_http : Configuring proxies: ''
2019-06-27T16:14:22.1073137Z DEBUG: msrest.universal_http : Evaluate proxies against ENV settings: True
2019-06-27T16:14:22.1073242Z DEBUG: azext_devops.devops_sdk.client : Route template: _apis/{area}/{resource}
2019-06-27T16:14:22.1073539Z DEBUG: azext_devops.devops_sdk.client : Api version '5.0-preview.1'
2019-06-27T16:14:22.1073881Z DEBUG: azext_devops.devops_sdk.client : POST https://dev.azure.com/orgName/_apis/CustomerIntelligence/Events
2019-06-27T16:14:22.1074423Z DEBUG: azext_devops.devops_sdk.client : Request content: [{'area': 'AzureDevopsCli', 'feature': 'devops', 'properties': {'Command': 'project create', 'Args': 'name organization source_control visibility', 'ShellType': None, 'IsInteractive': 'False', 'OutputType': 'json', 'OrgPresentInCommand': True, 'ProjectPresentInCommand': False, 'RepoPresentInCommand': False}}]
2019-06-27T16:14:22.1074551Z DEBUG: msrest.universal_http : Configuring redirects: allow=True, max=30
2019-06-27T16:14:22.1074629Z DEBUG: msrest.universal_http : Configuring request: timeout=100, verify=True, cert=None
2019-06-27T16:14:22.1074880Z DEBUG: msrest.universal_http : Configuring proxies: ''
2019-06-27T16:14:22.1075160Z DEBUG: msrest.universal_http : Evaluate proxies against ENV settings: True
2019-06-27T16:14:22.1075745Z DEBUG: urllib3.connectionpool : https://dev.azure.com:xxx "POST /orgName/_apis/CustomerIntelligence/Events HTTP/1.1" 401 0
2019-06-27T16:14:22.1076029Z DEBUG: msrest.exceptions : The requested resource requires user authentication: https://dev.azure.com/orgName/_apis/CustomerIntelligence/Events
2019-06-27T16:14:22.1076257Z DEBUG: The requested resource requires user authentication: https://dev.azure.com/orgName/_apis/CustomerIntelligence/Events
2019-06-27T16:14:22.1076337Z Traceback (most recent call last):
2019-06-27T16:14:22.1076559Z File "/home/vsts/.azure/cliextensions/azure-devops/azext_devops/dev/common/telemetry.py", line 92, in _send_tracking_ci_event
2019-06-27T16:14:22.1076685Z ci_client.publish_events([vsts_tracking_data])
2019-06-27T16:14:22.1077006Z File "/home/vsts/.azure/cliextensions/azure-devops/azext_devops/devops_sdk/v5_0/customer_intelligence/customer_intelligence_client.py", line 23, in publish_events
2019-06-27T16:14:22.1077054Z content=content)
2019-06-27T16:14:22.1077273Z File "/home/vsts/.azure/cliextensions/azure-devops/azext_devops/devops_sdk/client.py", line 90, in _send
2019-06-27T16:14:22.1077366Z response = self._send_request(request=request, headers=headers, content=content, media_type=media_type)
2019-06-27T16:14:22.1077596Z File "/home/vsts/.azure/cliextensions/azure-devops/azext_devops/devops_sdk/client.py", line 54, in _send_request
2019-06-27T16:14:22.1077677Z self._handle_error(request, response)
2019-06-27T16:14:22.1077896Z File "/home/vsts/.azure/cliextensions/azure-devops/azext_devops/devops_sdk/client.py", line 254, in _handle_error
2019-06-27T16:14:22.1077972Z url=request.url))
2019-06-27T16:14:22.1078290Z azext_devops.devops_sdk.exceptions.AzureDevOpsAuthenticationError: The requested resource requires user authentication: https://dev.azure.com/orgName/_apis/CustomerIntelligence/Events
2019-06-27T16:14:22.1078515Z DEBUG: urllib3.connectionpool : https://dev.azure.com:xxx "GET /orgName/_apis/ResourceAreas HTTP/1.1" 200 8484
2019-06-27T16:14:22.1109950Z DEBUG: azext_devops.devops_sdk.client : Response content:
2019-06-27T16:14:22.1118380Z DEBUG: msrest.universal_http.requests : Configuring retry: max_retries=3, backoff_factor=0.8, max_backoff=90
2019-06-27T16:14:22.1119144Z DEBUG: azext_devops.devops_sdk.client : File cache hit for options on: https://dev.azure.com/orgName
2019-06-27T16:14:22.1119202Z DEBUG: azext_devops.devops_sdk.client : Route template: _apis/process/{resource}/{processId}
2019-06-27T16:14:22.1119401Z DEBUG: azext_devops.devops_sdk.client : Api version '5.0'
2019-06-27T16:14:22.1119656Z DEBUG: azext_devops.devops_sdk.client : GET https://dev.azure.com/orgName/_apis/process/processes
2019-06-27T16:14:22.1119702Z DEBUG: azext_devops.devops_sdk.client : Request content: None
2019-06-27T16:14:22.1119744Z DEBUG: msrest.universal_http : Configuring redirects: allow=True, max=30
2019-06-27T16:14:22.1119828Z DEBUG: msrest.universal_http : Configuring request: timeout=100, verify=True, cert=None
2019-06-27T16:14:22.1120032Z DEBUG: msrest.universal_http : Configuring proxies: ''
2019-06-27T16:14:22.1120076Z DEBUG: msrest.universal_http : Evaluate proxies against ENV settings: True
2019-06-27T16:14:22.1120160Z DEBUG: urllib3.connectionpool : Starting new HTTPS connection (1): dev.azure.com:xxx
2019-06-27T16:14:22.1120397Z DEBUG: urllib3.connectionpool : https://dev.azure.com:xxx "GET /orgName/_apis/process/processes HTTP/1.1" 200 675
2019-06-27T16:14:22.1123187Z DEBUG: azext_devops.devops_sdk.client : Response content:
2019-06-27T16:14:22.1123646Z DEBUG: azext_devops.devops_sdk.client : Route template: _apis/{resource}/{projectId}
2019-06-27T16:14:22.1124031Z DEBUG: azext_devops.devops_sdk.client : Api version '5.0'
2019-06-27T16:14:22.1124325Z DEBUG: azext_devops.devops_sdk.client : POST https://dev.azure.com/orgName/_apis/projects
2019-06-27T16:14:22.1125098Z DEBUG: azext_devops.devops_sdk.client : Request content: {'name': 'txxx2', 'visibility': 'private', 'capabilities': {'versioncontrol': {'sourceControlType': 'git'}, 'processTemplate': {'templateTypeId': 'axxxxxxxxxc'}}}
2019-06-27T16:14:22.1125326Z DEBUG: msrest.universal_http : Configuring redirects: allow=True, max=30
2019-06-27T16:14:22.1125410Z DEBUG: msrest.universal_http : Configuring request: timeout=100, verify=True, cert=None
2019-06-27T16:14:22.1125607Z DEBUG: msrest.universal_http : Configuring proxies: ''
2019-06-27T16:14:22.1125649Z DEBUG: msrest.universal_http : Evaluate proxies against ENV settings: True
2019-06-27T16:14:22.1125900Z DEBUG: urllib3.connectionpool : https://dev.azure.com:xxx "POST /orgName/_apis/projects HTTP/1.1" 401 0
2019-06-27T16:14:22.1126122Z DEBUG: msrest.exceptions : The requested resource requires user authentication: https://dev.azure.com/orgName/_apis/projects
2019-06-27T16:14:22.1126255Z DEBUG: handling generic error
2019-06-27T16:14:22.1126347Z ERROR: cli.azure.cli.core.util : The command failed with an unexpected error. Here is the traceback:
2019-06-27T16:14:22.1126376Z
2019-06-27T16:14:22.1126413Z ERROR: The command failed with an unexpected error. Here is the traceback:
2019-06-27T16:14:22.1126473Z
2019-06-27T16:14:22.1126906Z ERROR: cli.azure.cli.core.util : The requested resource requires user authentication: https://dev.azure.com/orgName/_apis/projects
2019-06-27T16:14:22.1126954Z Traceback (most recent call last):
2019-06-27T16:14:22.1127204Z File "/opt/az/lib/python3.6/site-packages/knack/cli.py", line 206, in invoke
2019-06-27T16:14:22.1127248Z cmd_result = self.invocation.execute(args)
2019-06-27T16:14:22.1127466Z File "/opt/az/lib/python3.6/site-packages/azure/cli/core/commands/__init__.py", line 560, in execute
2019-06-27T16:14:22.1127546Z raise ex
2019-06-27T16:14:22.1127786Z File "/opt/az/lib/python3.6/site-packages/azure/cli/core/commands/__init__.py", line 618, in _run_jobs_serially
2019-06-27T16:14:22.1127832Z results.append(self._run_job(expanded_arg, cmd_copy))
2019-06-27T16:14:22.1128096Z File "/opt/az/lib/python3.6/site-packages/azure/cli/core/commands/__init__.py", line 609, in _run_job
2019-06-27T16:14:22.1128138Z cmd_copy.exception_handler(ex)
2019-06-27T16:14:22.1128379Z File "/home/vsts/.azure/cliextensions/azure-devops/azext_devops/dev/common/exception_handler.py", line 26, in azure_devops_exception_handler
2019-06-27T16:14:22.1128463Z reraise(sys.exc_info())
2019-06-27T16:14:22.1128661Z File "/opt/az/lib/python3.6/site-packages/six.py", line 693, in reraise
2019-06-27T16:14:22.1128739Z raise value
2019-06-27T16:14:22.1128956Z File "/opt/az/lib/python3.6/site-packages/azure/cli/core/commands/__init__.py", line 588, in _run_job
2019-06-27T16:14:22.1128997Z result = cmd_copy(params)
2019-06-27T16:14:22.1129247Z File "/opt/az/lib/python3.6/site-packages/azure/cli/core/commands/__init__.py", line 297, in __call__
2019-06-27T16:14:22.1129385Z return self.handler(args, *kwargs)
2019-06-27T16:14:22.1129638Z File "/opt/az/lib/python3.6/site-packages/azure/cli/core/__init__.py", line 461, in default_command_handler
2019-06-27T16:14:22.1129724Z return op(command_args)
2019-06-27T16:14:22.1129951Z File "/home/vsts/.azure/cliextensions/azure-devops/azext_devops/dev/team/project.py", line 74, in create_project
2019-06-27T16:14:22.1129999Z operation_reference = core_client.queue_create_project(project_to_create=team_project)
2019-06-27T16:14:22.1130286Z File "/home/vsts/.azure/cliextensions/azure-devops/azext_devops/devops_sdk/v5_0/core/core_client.py", line 151, in queue_create_project
2019-06-27T16:14:22.1130331Z content=content)
2019-06-27T16:14:22.1130591Z File "/home/vsts/.azure/cliextensions/azure-devops/azext_devops/devops_sdk/client.py", line 90, in _send
2019-06-27T16:14:22.1130642Z response = self._send_request(request=request, headers=headers, content=content, media_type=media_type)
2019-06-27T16:14:22.1130884Z File "/home/vsts/.azure/cliextensions/azure-devops/azext_devops/devops_sdk/client.py", line 54, in _send_request
2019-06-27T16:14:22.1130968Z self._handle_error(request, response)
2019-06-27T16:14:22.1131764Z File "/home/vsts/.azure/cliextensions/azure-devops/azext_devops/devops_sdk/client.py", line 254, in _handle_error
2019-06-27T16:14:22.1131830Z url=request.url))
2019-06-27T16:14:22.1132226Z azext_devops.devops_sdk.exceptions.AzureDevOpsAuthenticationError: The requested resource requires user authentication: https://dev.azure.com/orgName/_apis/projects
2019-06-27T16:14:22.1132514Z ERROR: The requested resource requires user authentication: https://dev.azure.com/orgName/_apis/projects
2019-06-27T16:14:22.1132615Z Traceback (most recent call last):
2019-06-27T16:14:22.1132875Z File "/opt/az/lib/python3.6/site-packages/knack/cli.py", line 206, in invoke
2019-06-27T16:14:22.1132931Z cmd_result = self.invocation.execute(args)
2019-06-27T16:14:22.1133365Z File "/opt/az/lib/python3.6/site-packages/azure/cli/core/commands/__init__.py", line 560, in execute
2019-06-27T16:14:22.1133430Z raise ex
2019-06-27T16:14:22.1133753Z File "/opt/az/lib/python3.6/site-packages/azure/cli/core/commands/__init__.py", line 618, in _run_jobs_serially
2019-06-27T16:14:22.1133861Z results.append(self._run_job(expanded_arg, cmd_copy))
2019-06-27T16:14:22.1134144Z File "/opt/az/lib/python3.6/site-packages/azure/cli/core/commands/__init__.py", line 609, in _run_job
2019-06-27T16:14:22.1134198Z cmd_copy.exception_handler(ex)
2019-06-27T16:14:22.1134559Z File "/home/vsts/.azure/cliextensions/azure-devops/azext_devops/dev/common/exception_handler.py", line 26, in azure_devops_exception_handler
2019-06-27T16:14:22.1134615Z reraise(sys.exc_info())
2019-06-27T16:14:22.1135047Z File "/opt/az/lib/python3.6/site-packages/six.py", line 693, in reraise
2019-06-27T16:14:22.1135084Z raise value
2019-06-27T16:14:22.1135306Z File "/opt/az/lib/python3.6/site-packages/azure/cli/core/commands/__init__.py", line 588, in _run_job
2019-06-27T16:14:22.1135384Z result = cmd_copy(params)
2019-06-27T16:14:22.1135593Z File "/opt/az/lib/python3.6/site-packages/azure/cli/core/commands/__init__.py", line 297, in __call__
2019-06-27T16:14:22.1135635Z return self.handler(args, kwargs)
2019-06-27T16:14:22.1135886Z File "/opt/az/lib/python3.6/site-packages/azure/cli/core/__init__.py", line 461, in default_command_handler
2019-06-27T16:14:22.1135926Z return op(command_args)
2019-06-27T16:14:22.1136134Z File "/home/vsts/.azure/cliextensions/azure-devops/azext_devops/dev/team/project.py", line 74, in create_project
2019-06-27T16:14:22.1136221Z operation_reference = core_client.queue_create_project(project_to_create=team_project)
2019-06-27T16:14:22.1136454Z File "/home/vsts/.azure/cliextensions/azure-devops/azext_devops/devops_sdk/v5_0/core/core_client.py", line 151, in queue_create_project
2019-06-27T16:14:22.1136606Z content=content)
2019-06-27T16:14:22.1136844Z File "/home/vsts/.azure/cliextensions/azure-devops/azext_devops/devops_sdk/client.py", line 90, in _send
2019-06-27T16:14:22.1136892Z response = self._send_request(request=request, headers=headers, content=content, media_type=media_type)
2019-06-27T16:14:22.1137158Z File "/home/vsts/.azure/cliextensions/azure-devops/azext_devops/devops_sdk/client.py", line 54, in _send_request
2019-06-27T16:14:22.1137202Z self._handle_error(request, response)
2019-06-27T16:14:22.1137414Z File "/home/vsts/.azure/cliextensions/azure-devops/azext_devops/devops_sdk/client.py", line 254, in _handle_error
2019-06-27T16:14:22.1137494Z url=request.url))
2019-06-27T16:14:22.1137741Z azext_devops.devops_sdk.exceptions.AzureDevOpsAuthenticationError: The requested resource requires user authentication: https://dev.azure.com/orgName/_apis/projects
2019-06-27T16:14:22.1137824Z WARNING: cli.azure.cli.core.util :
2019-06-27T16:14:22.1137989Z To open an issue, please run: 'az feedback'
2019-06-27T16:14:22.1138031Z WARNING:
2019-06-27T16:14:22.1138235Z To open an issue, please run: 'az feedback'
2019-06-27T16:14:22.1138276Z INFO: az_command_data_logger : exit code: 1
2019-06-27T16:14:22.1138313Z INFO: Suppress exception There are no active accounts.
2019-06-27T16:14:22.1138536Z INFO: Suppress exception Please run 'az login' to setup account.
2019-06-27T16:14:22.1138582Z INFO: telemetry.save : Save telemetry record of length 2371 in cache
2019-06-27T16:14:22.1138829Z WARNING: telemetry.check : Negative: The /home/vsts/.azure/telemetry.txt was modified at 2019-06-27 16:14:20.924539, which in less than 600.000000 s
2019-06-27T16:14:22.1138967Z INFO: command ran in 0.980 seconds.
2019-06-27T16:14:22.8259235Z ##[error]PowerShell exited with code '1'.
2019-06-27T16:14:22.8340963Z ##[section]Finishing: PowerShell
2019-06-27T16:14:22.8349451Z ##[section]Starting: Checkout
2019-06-27T16:14:22.8351011Z ==============================================================================
2019-06-27T16:14:22.8351069Z Task : Get sources
2019-06-27T16:14:22.8351107Z Description : Get sources from a repository. Supports Git, TfsVC, and SVN repositories.
2019-06-27T16:14:22.8351182Z Version : 1.0.0
2019-06-27T16:14:22.8351215Z Author : Microsoft
2019-06-27T16:14:22.8351252Z Help : More Information
2019-06-27T16:14:22.8351329Z ==============================================================================
2019-06-27T16:14:23.2366770Z Cleaning any cached credential from repository: repoName (Git)
2019-06-27T16:14:23.2409125Z ##[section]Finishing: Checkout
2019-06-27T16:14:23.2474661Z ##[section]Starting: Finalize Job
2019-06-27T16:14:23.2516898Z Start cleaning up orphan processes.
2019-06-27T16:14:23.2899592Z ##[section]Finishing: Finalize Job
2019-06-27T16:14:23.2953255Z ##[section]Finishing: Job

elderrollins picture elderrollins on 27 Jun 2019

Thanks for sharing the logs.. I was looking for "2019-06-27T16:14:22.0595872Z INFO: received PAT from environment variable" in logs which is present so your PAT Env was definitely picked up.
It is either the permission issue or your PAT string is not correct.

Just to confirm -

  1. Make sure you are NOT giving PAT with quotes when setting the variable?
    image
  2. Confirm that you replaced your organization name to OrgName when sharing the debug logs and that the command ran with the correct organization name for which you generated the PAT?
atbagga picture atbagga on 28 Jun 2019

I am not sure what the difference was, but I copied and pasted your .yml file, changed the org to my org name, and it worked. So I think it was a synthax error, or magic. I'm banking on magic, because clearly it wasn't my fault. Anyways thanks for the help with this.

Here is the .yml file that finally worked for me.

trigger:

  • master

pool:
vmImage: 'ubuntu-latest'

steps:

  • task: PowerShell@2
    inputs:
    targetType: 'inline'
    script:
    az extension add --name azure-devops
  • task: PowerShell@2
    inputs:
    targetType: 'inline'
    script:
    az devops project create --name "test1223" --organization https://dev.azure.com/
    env:
    AZURE_DEVOPS_EXT_PAT: $(PAT)
elderrollins picture elderrollins on 28 Jun 2019
😄2

Glad that you are unblocked!

atbagga picture atbagga on 28 Jun 2019
Was this page helpful?
0 / 5 - 0 ratings

Related issues

fidou picture fidou  Â·  5Comments
willsmythe picture willsmythe  Â·  5Comments
geverghe picture geverghe  Â·  3Comments
mydiemho picture mydiemho  Â·  3Comments
f00-beerd picture f00-beerd  Â·  3Comments