New-AzureRMVM fails when using a packer image from Azure Marketplace ISO

[srjennings]

Description

Followed the guide here for the packer image;
https://docs.microsoft.com/en-us/azure/virtual-machines/windows/build-image-with-packer

Running the below script results in timeout for extension writing. Some cursory research indicates that custom images may not have the extension installed or a firewall rule enabled - however we are using the build from the Azure marketplace. Am I misunderstanding what is included on the image built from Microsoft? I would imagine the Azure Agent is installed.

Workarounds currently in place
Use the Azure CLI to deploy vm from image results in no errors.

Script/Steps for Reproduction

Packer Image JSON template

{
  "builders": [{
    "type": "azure-arm",

    "client_id": "xxxx-xxxx-xxxx-xxxx",
    "client_secret": "secret!",
    "tenant_id": "xxxx-xxxx-xxxx-xxxx",
    "subscription_id": "xxxx-xxxx-xxxx-xxxx",
    "object_id": "d6e2f73a-b237-4e60-960f-b2dc3cf782c6",

    "managed_image_resource_group_name": "resourcegroupname",
    "managed_image_name": "packer-gui",
    "managed_image_storage_account_type": "Premium_LRS",

    "os_type": "Windows",
    "image_publisher": "MicrosoftWindowsServer",
    "image_offer": "WindowsServer",
    "image_sku": "2016-Datacenter",

    "communicator": "winrm",
    "winrm_use_ssl": "true",
    "winrm_insecure": "true",
    "winrm_timeout": "3m",
    "winrm_username": "admin",

    "azure_tags": {
        "dept": "deptname",
        "task": "Image deployment"   
    },

    "location": "East US",
    "vm_size": "Standard_F2s"
  }],
  "provisioners": [{
    "type": "powershell",
    "inline": [
      "(Invoke-WebRequest -Uri 'https://raw.githubusercontent.com/ansible/ansible/devel/examples/scripts/ConfigureRemotingForAnsible.ps1' -UseBasicParsing).content | Out-File $env:SystemDrive\\ConfigureRemotingForAnsible.ps1",
      "powershell.exe -ExecutionPolicy ByPass -File $env:SystemDrive\\ConfigureRemotingForAnsible.ps1",
      "Add-WindowsFeature Web-Server,Web-Asp-Net45,Web-AppInit",
      "& $env:SystemRoot\\System32\\Sysprep\\Sysprep.exe /oobe /generalize /quiet /quit",
      "while($true) { $imageState = Get-ItemProperty HKLM:\\SOFTWARE\\Microsoft\\Windows\\CurrentVersion\\Setup\\State | Select ImageState; if($imageState.ImageState -ne 'IMAGE_STATE_GENERALIZE_RESEAL_TO_OOBE') { Write-Output $imageState.ImageState; Start-Sleep -s 10  } else { break } }"
    ]
  }]
}

        Write-Output "Provide details for Azure"
        $azurecreds = Get-Credential
        Connect-AzureRmAccount -Credential $azurecreds
        
        # Create a subnet configuration
        $subnetConfig = New-AzureRmVirtualNetworkSubnetConfig `
            -Name subNet `
            -AddressPrefix 192.168.1.0/24
        
        # Create a virtual network
        $vnet = New-AzureRmVirtualNetwork `
            -ResourceGroupName $rgName `
            -Location $location `
            -Name automateVnet `
            -AddressPrefix 192.168.0.0/16 `
            -Subnet $subnetConfig
        
        # Create a public IP address and specify a DNS name
        $publicIP = New-AzureRmPublicIpAddress `
            -ResourceGroupName $rgName `
            -Location $location `
            -AllocationMethod "Static" `
            -IdleTimeoutInMinutes 4 `
            -Name "publicip1"
        
        # Create an inbound network security group rule for port 80
        $nsgRuleWeb = New-AzureRmNetworkSecurityRuleConfig `
            -Name allowHTTP  `
            -Protocol Tcp `
            -Direction Inbound `
            -Priority 1001 `
            -SourceAddressPrefix * `
            -SourcePortRange * `
            -DestinationAddressPrefix * `
            -DestinationPortRange 80 `
            -Access Allow

        $nsgRuleRDP = New-AzureRmNetworkSecurityRuleConfig `
            -Name allowRDP  `
            -Protocol Tcp `
            -Direction Inbound `
            -Priority 1002 `
            -SourceAddressPrefix * `
            -SourcePortRange * `
            -DestinationAddressPrefix * `
            -DestinationPortRange 3389 `
            -Access Allow
        
        # Create a network security group
        $nsg = New-AzureRmNetworkSecurityGroup `
            -ResourceGroupName $rgName `
            -Location $location `
            -Name webNSG `
            -SecurityRules $nsgRuleWeb,$nsgRuleRDP
        
        # Create a virtual network card and associate with public IP address and NSG
        $nic = New-AzureRmNetworkInterface `
            -Name nicname `
            -ResourceGroupName $rgName `
            -Location $location `
            -SubnetId $vnet.Subnets[0].Id `
            -PublicIpAddressId $publicIP.Id `
            -NetworkSecurityGroupId $nsg.Id
        
        # Define the image created by Packer
        $image = Get-AzureRMImage -ImageName packer-image -ResourceGroupName $rgName
        
        # Create a virtual machine configuration
        $vmConfig = New-AzureRmVMConfig -VMName iisvm-VMSize Standard_F2s | `
        Set-AzureRmVMOperatingSystem -Windows -ComputerName iisvm-Credential $cred | `
        Set-AzureRmVMSourceImage -Id $image.Id | `
        Add-AzureRmVMNetworkInterface -Id $nic.Id
        
        New-AzureRmStorageAccount -ResourceGroupName $rgName -Name vmdiag -Location $location -SkuName Standard_LRS -Verbose
        Set-AzureRmVMBootDiagnostics -VM $vmConfig -Enable -ResourceGroupName $rgName -StorageAccountName vmdiag
        New-AzureRmVM -ResourceGroupName $rgName -Location $location -VM $vmConfig -LicenseType "Windows_Server"

Module Version

ModuleType Version    Name                                ExportedCommands
---------- -------    ----                                ----------------
Script     5.6.0      AzureRM

Environment Data

Name                           Value
----                           -----
PSVersion                      5.1.16299.251
PSEdition                      Desktop
PSCompatibleVersions           {1.0, 2.0, 3.0, 4.0...}
BuildVersion                   10.0.16299.251
CLRVersion                     4.0.30319.42000
WSManStackVersion              3.0
PSRemotingProtocolVersion      2.3
SerializationVersion           1.1.0.1

Debug Output

Unfortunately, missing a small portion of the debug in the beginning but I don't think it matters much? E.g, Creation of the subnet, virtual network, ip address and security rule configuration.

{
  "startTime": "2018-03-29T13:29:08.9038615-04:00",
  "status": "InProgress",
  "name": "0fd58f15-b58a-4e9a-8aff-ee4a240a66e1"
}


DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 :
DEBUG: 03/29/2018 17:48:19: bfb57f52-8609-40bf-84b6-e9bb9eacd128 - AcquireTokenHandlerBase: === Token Acquisition started:
        Authority: https://login.microsoftonline.com/xxxx-xxxx-xxxx-xxxx/
        Resource: https://management.core.windows.net/
        ClientId: 1950a258-227b-4e31-a9cf-717495945fc2
        CacheType: Microsoft.Azure.Commands.Common.Authentication.AuthenticationStoreTokenCache (1 items)
        Authentication Target: User


DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Verbose: 1 :
DEBUG: 03/29/2018 17:48:19: bfb57f52-8609-40bf-84b6-e9bb9eacd128 - TokenCache: Looking up cache for a token...

DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 :
DEBUG: 03/29/2018 17:48:19: bfb57f52-8609-40bf-84b6-e9bb9eacd128 - TokenCache: An item matching the requested resource was found in the cache

DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Verbose: 1 :
DEBUG: 03/29/2018 17:48:19: bfb57f52-8609-40bf-84b6-e9bb9eacd128 - TokenCache: 34.5350486716667 minutes left until token in cache expires

DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 :
DEBUG: 03/29/2018 17:48:19: bfb57f52-8609-40bf-84b6-e9bb9eacd128 - TokenCache: A matching item (access token or refresh token or both) was found in the cache

DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 :
DEBUG: 03/29/2018 17:48:19: bfb57f52-8609-40bf-84b6-e9bb9eacd128 - AcquireTokenHandlerBase: === Token Acquisition finished successfully. An access token was retuned:
        Access Token Hash: MTAqUNOwWJurZvlNmjRcIoh4hVlxJvQQwVLM5MW+/f0=
        Refresh Token Hash: PnyUuk6CR2GWbURE7uGPbn/QrCiPYHOA2kT9UWYnyQA=
        Expiration Time: 03/29/2018 18:22:51 +00:00
        User Hash: N/Gz3yO+2RExr+AHDgk5dZYnAIkIRTkZe5tlZHwcjTA=


DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 :
DEBUG: 03/29/2018 17:48:19:  - TokenCache: Serializing token cache with 1 items.

DEBUG: ============================ HTTP REQUEST ============================

HTTP Method:
GET

Absolute Uri:
https://management.azure.com/subscriptions/xxxx-xxxx-xxxx-xxxx/providers/Microsoft.Compute/locations/eastus/operations/0fd58f15-b58a-4e9a-8aff-ee4a240a66e1?api-version=2017-12-01

Headers:

Body:



DEBUG: ============================ HTTP RESPONSE ============================

Status Code:
OK

Headers:
Pragma                        : no-cache
x-ms-ratelimit-remaining-resource: Microsoft.Compute/GetOperation3Min;11983,Microsoft.Compute/GetOperation30Min;23868
Strict-Transport-Security     : max-age=31536000; includeSubDomains
x-ms-served-by                : 70d7e5f6-1c51-403a-aafc-0d55928deb53_131650662970037999
x-ms-request-id               : aba73adb-db63-48fd-9923-0adcf2ef62c8
Cache-Control                 : no-cache
Server                        : Microsoft-HTTPAPI/2.0,Microsoft-HTTPAPI/2.0
x-ms-ratelimit-remaining-subscription-reads: 14948
x-ms-correlation-request-id   : c28c5f2f-61a4-4e8d-9659-faad23711e0e
x-ms-routing-request-id       : EASTUS:20180329T174819Z:c28c5f2f-61a4-4e8d-9659-faad23711e0e
X-Content-Type-Options        : nosniff
Date                          : Thu, 29 Mar 2018 17:48:19 GMT

Body:
{
  "startTime": "2018-03-29T13:29:08.9038615-04:00",
  "status": "InProgress",
  "name": "0fd58f15-b58a-4e9a-8aff-ee4a240a66e1"
}


DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 :
DEBUG: 03/29/2018 17:48:49: 7918408b-0a1b-4ffd-986e-f976efd90b80 - AcquireTokenHandlerBase: === Token Acquisition started:
        Authority: https://login.microsoftonline.com/xxxx-xxxx-xxxx-xxxx/
        Resource: https://management.core.windows.net/
        ClientId: 1950a258-227b-4e31-a9cf-717495945fc2
        CacheType: Microsoft.Azure.Commands.Common.Authentication.AuthenticationStoreTokenCache (1 items)
        Authentication Target: User


DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Verbose: 1 :
DEBUG: 03/29/2018 17:48:49: 7918408b-0a1b-4ffd-986e-f976efd90b80 - TokenCache: Looking up cache for a token...

DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 :
DEBUG: 03/29/2018 17:48:49: 7918408b-0a1b-4ffd-986e-f976efd90b80 - TokenCache: An item matching the requested resource was found in the cache

DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Verbose: 1 :
DEBUG: 03/29/2018 17:48:49: 7918408b-0a1b-4ffd-986e-f976efd90b80 - TokenCache: 34.02596099 minutes left until token in cache expires

DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 :
DEBUG: 03/29/2018 17:48:49: 7918408b-0a1b-4ffd-986e-f976efd90b80 - TokenCache: A matching item (access token or refresh token or both) was found in the cache

DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 :
DEBUG: 03/29/2018 17:48:49: 7918408b-0a1b-4ffd-986e-f976efd90b80 - AcquireTokenHandlerBase: === Token Acquisition finished successfully. An access token was retuned:
        Access Token Hash: MTAqUNOwWJurZvlNmjRcIoh4hVlxJvQQwVLM5MW+/f0=
        Refresh Token Hash: PnyUuk6CR2GWbURE7uGPbn/QrCiPYHOA2kT9UWYnyQA=
        Expiration Time: 03/29/2018 18:22:51 +00:00
        User Hash: N/Gz3yO+2RExr+AHDgk5dZYnAIkIRTkZe5tlZHwcjTA=


DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 :
DEBUG: 03/29/2018 17:48:49:  - TokenCache: Serializing token cache with 1 items.

DEBUG: ============================ HTTP REQUEST ============================

HTTP Method:
GET

Absolute Uri:
https://management.azure.com/subscriptions/xxxx-xxxx-xxxx-xxxx/providers/Microsoft.Compute/locations/eastus/operations/0fd58f15-b58a-4e9a-8aff-ee4a240a66e1?api-version=2017-12-01

Headers:

Body:



DEBUG: ============================ HTTP RESPONSE ============================

Status Code:
OK

Headers:
Pragma                        : no-cache
x-ms-ratelimit-remaining-resource: Microsoft.Compute/GetOperation3Min;11983,Microsoft.Compute/GetOperation30Min;23865
Strict-Transport-Security     : max-age=31536000; includeSubDomains
x-ms-served-by                : 70d7e5f6-1c51-403a-aafc-0d55928deb53_131650662970037999
x-ms-request-id               : 9d39308e-d93c-4cd0-8dfc-6da9b90c2e50
Cache-Control                 : no-cache
Server                        : Microsoft-HTTPAPI/2.0,Microsoft-HTTPAPI/2.0
x-ms-ratelimit-remaining-subscription-reads: 14946
x-ms-correlation-request-id   : b3ef07a0-2df5-4344-8f40-b2ac30609f4e
x-ms-routing-request-id       : EASTUS:20180329T174850Z:b3ef07a0-2df5-4344-8f40-b2ac30609f4e
X-Content-Type-Options        : nosniff
Date                          : Thu, 29 Mar 2018 17:48:49 GMT

Body:
{
  "startTime": "2018-03-29T13:29:08.9038615-04:00",
  "status": "InProgress",
  "name": "0fd58f15-b58a-4e9a-8aff-ee4a240a66e1"
}


DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 :
DEBUG: 03/29/2018 17:49:20: e6345cf7-5f26-48b9-a83c-574c0621e1e2 - AcquireTokenHandlerBase: === Token Acquisition started:
        Authority: https://login.microsoftonline.com/xxxx-xxxx-xxxx-xxxx/
        Resource: https://management.core.windows.net/
        ClientId: 1950a258-227b-4e31-a9cf-717495945fc2
        CacheType: Microsoft.Azure.Commands.Common.Authentication.AuthenticationStoreTokenCache (1 items)
        Authentication Target: User


DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Verbose: 1 :
DEBUG: 03/29/2018 17:49:20: e6345cf7-5f26-48b9-a83c-574c0621e1e2 - TokenCache: Looking up cache for a token...

DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 :
DEBUG: 03/29/2018 17:49:20: e6345cf7-5f26-48b9-a83c-574c0621e1e2 - TokenCache: An item matching the requested resource was found in the cache

DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Verbose: 1 :
DEBUG: 03/29/2018 17:49:20: e6345cf7-5f26-48b9-a83c-574c0621e1e2 - TokenCache: 33.5186135633333 minutes left until token in cache expires

DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 :
DEBUG: 03/29/2018 17:49:20: e6345cf7-5f26-48b9-a83c-574c0621e1e2 - TokenCache: A matching item (access token or refresh token or both) was found in the cache

DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 :
DEBUG: 03/29/2018 17:49:20: e6345cf7-5f26-48b9-a83c-574c0621e1e2 - AcquireTokenHandlerBase: === Token Acquisition finished successfully. An access token was retuned:
        Access Token Hash: MTAqUNOwWJurZvlNmjRcIoh4hVlxJvQQwVLM5MW+/f0=
        Refresh Token Hash: PnyUuk6CR2GWbURE7uGPbn/QrCiPYHOA2kT9UWYnyQA=
        Expiration Time: 03/29/2018 18:22:51 +00:00
        User Hash: N/Gz3yO+2RExr+AHDgk5dZYnAIkIRTkZe5tlZHwcjTA=


DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 :
DEBUG: 03/29/2018 17:49:20:  - TokenCache: Serializing token cache with 1 items.

DEBUG: ============================ HTTP REQUEST ============================

HTTP Method:
GET

Absolute Uri:
https://management.azure.com/subscriptions/xxxx-xxxx-xxxx-xxxx/providers/Microsoft.Compute/locations/eastus/operations/0fd58f15-b58a-4e9a-8aff-ee4a240a66e1?api-version=2017-12-01

Headers:

Body:



DEBUG: ============================ HTTP RESPONSE ============================

Status Code:
OK

Headers:
Pragma                        : no-cache
x-ms-ratelimit-remaining-resource: Microsoft.Compute/GetOperation3Min;11983,Microsoft.Compute/GetOperation30Min;23862
Strict-Transport-Security     : max-age=31536000; includeSubDomains
x-ms-served-by                : 70d7e5f6-1c51-403a-aafc-0d55928deb53_131650662970037999
x-ms-request-id               : 0f53c1cb-26fd-473a-9863-8c98c5fdc1dd
Cache-Control                 : no-cache
Server                        : Microsoft-HTTPAPI/2.0,Microsoft-HTTPAPI/2.0
x-ms-ratelimit-remaining-subscription-reads: 14945
x-ms-correlation-request-id   : 6a7fb167-2043-4147-8672-0407ea6e9b43
x-ms-routing-request-id       : EASTUS:20180329T174921Z:6a7fb167-2043-4147-8672-0407ea6e9b43
X-Content-Type-Options        : nosniff
Date                          : Thu, 29 Mar 2018 17:49:21 GMT

Body:
{
  "startTime": "2018-03-29T13:29:08.9038615-04:00",
  "status": "InProgress",
  "name": "0fd58f15-b58a-4e9a-8aff-ee4a240a66e1"
}


DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 :
DEBUG: 03/29/2018 17:49:51: 03fbab13-8f64-4e68-a041-c1a8c0a98cd8 - AcquireTokenHandlerBase: === Token Acquisition started:
        Authority: https://login.microsoftonline.com/xxxx-xxxx-xxxx-xxxx/
        Resource: https://management.core.windows.net/
        ClientId: 1950a258-227b-4e31-a9cf-717495945fc2
        CacheType: Microsoft.Azure.Commands.Common.Authentication.AuthenticationStoreTokenCache (1 items)
        Authentication Target: User


DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Verbose: 1 :
DEBUG: 03/29/2018 17:49:51: 03fbab13-8f64-4e68-a041-c1a8c0a98cd8 - TokenCache: Looking up cache for a token...

DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 :
DEBUG: 03/29/2018 17:49:51: 03fbab13-8f64-4e68-a041-c1a8c0a98cd8 - TokenCache: An item matching the requested resource was found in the cache

DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Verbose: 1 :
DEBUG: 03/29/2018 17:49:51: 03fbab13-8f64-4e68-a041-c1a8c0a98cd8 - TokenCache: 33.0007306316667 minutes left until token in cache expires

DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 :
DEBUG: 03/29/2018 17:49:51: 03fbab13-8f64-4e68-a041-c1a8c0a98cd8 - TokenCache: A matching item (access token or refresh token or both) was found in the cache

DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 :
DEBUG: 03/29/2018 17:49:51: 03fbab13-8f64-4e68-a041-c1a8c0a98cd8 - AcquireTokenHandlerBase: === Token Acquisition finished successfully. An access token was retuned:
        Access Token Hash: MTAqUNOwWJurZvlNmjRcIoh4hVlxJvQQwVLM5MW+/f0=
        Refresh Token Hash: PnyUuk6CR2GWbURE7uGPbn/QrCiPYHOA2kT9UWYnyQA=
        Expiration Time: 03/29/2018 18:22:51 +00:00
        User Hash: N/Gz3yO+2RExr+AHDgk5dZYnAIkIRTkZe5tlZHwcjTA=


DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 :
DEBUG: 03/29/2018 17:49:51:  - TokenCache: Serializing token cache with 1 items.

DEBUG: ============================ HTTP REQUEST ============================

HTTP Method:
GET

Absolute Uri:
https://management.azure.com/subscriptions/xxxx-xxxx-xxxx-xxxx/providers/Microsoft.Compute/locations/eastus/operations/0fd58f15-b58a-4e9a-8aff-ee4a240a66e1?api-version=2017-12-01

Headers:

Body:



DEBUG: ============================ HTTP RESPONSE ============================

Status Code:
OK

Headers:
Pragma                        : no-cache
x-ms-ratelimit-remaining-resource: Microsoft.Compute/GetOperation3Min;11983,Microsoft.Compute/GetOperation30Min;23859
Strict-Transport-Security     : max-age=31536000; includeSubDomains
x-ms-served-by                : 70d7e5f6-1c51-403a-aafc-0d55928deb53_131650662970037999
x-ms-request-id               : adcd3c59-3e54-4a5b-94ea-5fcf24ace6ab
Cache-Control                 : no-cache
Server                        : Microsoft-HTTPAPI/2.0,Microsoft-HTTPAPI/2.0
x-ms-ratelimit-remaining-subscription-reads: 14944
x-ms-correlation-request-id   : a8b6f258-5a79-437f-94cf-ac285a4fe420
x-ms-routing-request-id       : EASTUS:20180329T174953Z:a8b6f258-5a79-437f-94cf-ac285a4fe420
X-Content-Type-Options        : nosniff
Date                          : Thu, 29 Mar 2018 17:49:53 GMT

Body:
{
  "startTime": "2018-03-29T13:29:08.9038615-04:00",
  "status": "InProgress",
  "name": "0fd58f15-b58a-4e9a-8aff-ee4a240a66e1"
}


DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 :
DEBUG: 03/29/2018 17:50:23: 7dab612e-00b3-410f-a65f-67f043e7043b - AcquireTokenHandlerBase: === Token Acquisition started:
        Authority: https://login.microsoftonline.com/xxxx-xxxx-xxxx-xxxx/
        Resource: https://management.core.windows.net/
        ClientId: 1950a258-227b-4e31-a9cf-717495945fc2
        CacheType: Microsoft.Azure.Commands.Common.Authentication.AuthenticationStoreTokenCache (1 items)
        Authentication Target: User


DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Verbose: 1 :
DEBUG: 03/29/2018 17:50:23: 7dab612e-00b3-410f-a65f-67f043e7043b - TokenCache: Looking up cache for a token...

DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 :
DEBUG: 03/29/2018 17:50:23: 7dab612e-00b3-410f-a65f-67f043e7043b - TokenCache: An item matching the requested resource was found in the cache

DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Verbose: 1 :
DEBUG: 03/29/2018 17:50:23: 7dab612e-00b3-410f-a65f-67f043e7043b - TokenCache: 32.4589392816667 minutes left until token in cache expires

DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 :
DEBUG: 03/29/2018 17:50:23: 7dab612e-00b3-410f-a65f-67f043e7043b - TokenCache: A matching item (access token or refresh token or both) was found in the cache

DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 :
DEBUG: 03/29/2018 17:50:23: 7dab612e-00b3-410f-a65f-67f043e7043b - AcquireTokenHandlerBase: === Token Acquisition finished successfully. An access token was retuned:
        Access Token Hash: MTAqUNOwWJurZvlNmjRcIoh4hVlxJvQQwVLM5MW+/f0=
        Refresh Token Hash: PnyUuk6CR2GWbURE7uGPbn/QrCiPYHOA2kT9UWYnyQA=
        Expiration Time: 03/29/2018 18:22:51 +00:00
        User Hash: N/Gz3yO+2RExr+AHDgk5dZYnAIkIRTkZe5tlZHwcjTA=


DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 :
DEBUG: 03/29/2018 17:50:23:  - TokenCache: Serializing token cache with 1 items.

DEBUG: ============================ HTTP REQUEST ============================

HTTP Method:
GET

Absolute Uri:
https://management.azure.com/subscriptions/xxxx-xxxx-xxxx-xxxx/providers/Microsoft.Compute/locations/eastus/operations/0fd58f15-b58a-4e9a-8aff-ee4a240a66e1?api-version=2017-12-01

Headers:

Body:



DEBUG: ============================ HTTP RESPONSE ============================

Status Code:
OK

Headers:
Pragma                        : no-cache
x-ms-ratelimit-remaining-resource: Microsoft.Compute/GetOperation3Min;11983,Microsoft.Compute/GetOperation30Min;23860
Strict-Transport-Security     : max-age=31536000; includeSubDomains
x-ms-served-by                : 70d7e5f6-1c51-403a-aafc-0d55928deb53_131650662970037999
x-ms-request-id               : 15aace17-7964-4d82-934d-909c9cf47ae8
Cache-Control                 : no-cache
Server                        : Microsoft-HTTPAPI/2.0,Microsoft-HTTPAPI/2.0
x-ms-ratelimit-remaining-subscription-reads: 14943
x-ms-correlation-request-id   : 005915d4-5a62-446d-a1d6-e0db7adce376
x-ms-routing-request-id       : EASTUS:20180329T175025Z:005915d4-5a62-446d-a1d6-e0db7adce376
X-Content-Type-Options        : nosniff
Date                          : Thu, 29 Mar 2018 17:50:25 GMT

Body:
{
  "startTime": "2018-03-29T13:29:08.9038615-04:00",
  "status": "InProgress",
  "name": "0fd58f15-b58a-4e9a-8aff-ee4a240a66e1"
}


DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 :
DEBUG: 03/29/2018 17:50:55: cabb8904-2292-443f-b90c-34ef6948a6df - AcquireTokenHandlerBase: === Token Acquisition started:
        Authority: https://login.microsoftonline.com/xxxx-xxxx-xxxx-xxxx/
        Resource: https://management.core.windows.net/
        ClientId: 1950a258-227b-4e31-a9cf-717495945fc2
        CacheType: Microsoft.Azure.Commands.Common.Authentication.AuthenticationStoreTokenCache (1 items)
        Authentication Target: User


DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Verbose: 1 :
DEBUG: 03/29/2018 17:50:55: cabb8904-2292-443f-b90c-34ef6948a6df - TokenCache: Looking up cache for a token...

DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 :
DEBUG: 03/29/2018 17:50:55: cabb8904-2292-443f-b90c-34ef6948a6df - TokenCache: An item matching the requested resource was found in the cache

DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Verbose: 1 :
DEBUG: 03/29/2018 17:50:55: cabb8904-2292-443f-b90c-34ef6948a6df - TokenCache: 31.931159295 minutes left until token in cache expires

DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 :
DEBUG: 03/29/2018 17:50:55: cabb8904-2292-443f-b90c-34ef6948a6df - TokenCache: A matching item (access token or refresh token or both) was found in the cache

DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 :
DEBUG: 03/29/2018 17:50:55: cabb8904-2292-443f-b90c-34ef6948a6df - AcquireTokenHandlerBase: === Token Acquisition finished successfully. An access token was retuned:
        Access Token Hash: MTAqUNOwWJurZvlNmjRcIoh4hVlxJvQQwVLM5MW+/f0=
        Refresh Token Hash: PnyUuk6CR2GWbURE7uGPbn/QrCiPYHOA2kT9UWYnyQA=
        Expiration Time: 03/29/2018 18:22:51 +00:00
        User Hash: N/Gz3yO+2RExr+AHDgk5dZYnAIkIRTkZe5tlZHwcjTA=


DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 :
DEBUG: 03/29/2018 17:50:55:  - TokenCache: Serializing token cache with 1 items.

DEBUG: ============================ HTTP REQUEST ============================

HTTP Method:
GET

Absolute Uri:
https://management.azure.com/subscriptions/xxxx-xxxx-xxxx-xxxx/providers/Microsoft.Compute/locations/eastus/operations/0fd58f15-b58a-4e9a-8aff-ee4a240a66e1?api-version=2017-12-01

Headers:

Body:



DEBUG: ============================ HTTP RESPONSE ============================

Status Code:
OK

Headers:
Pragma                        : no-cache
x-ms-ratelimit-remaining-resource: Microsoft.Compute/GetOperation3Min;11983,Microsoft.Compute/GetOperation30Min;23857
Strict-Transport-Security     : max-age=31536000; includeSubDomains
x-ms-served-by                : 70d7e5f6-1c51-403a-aafc-0d55928deb53_131650662970037999
x-ms-request-id               : c806cb48-501c-40e8-8f07-84f713b8daf8
Cache-Control                 : no-cache
Server                        : Microsoft-HTTPAPI/2.0,Microsoft-HTTPAPI/2.0
x-ms-ratelimit-remaining-subscription-reads: 14942
x-ms-correlation-request-id   : 29b6d969-e7ac-40ac-830c-5b73fc406392
x-ms-routing-request-id       : EASTUS:20180329T175056Z:29b6d969-e7ac-40ac-830c-5b73fc406392
X-Content-Type-Options        : nosniff
Date                          : Thu, 29 Mar 2018 17:50:56 GMT

Body:
{
  "startTime": "2018-03-29T13:29:08.9038615-04:00",
  "status": "InProgress",
  "name": "0fd58f15-b58a-4e9a-8aff-ee4a240a66e1"
}


DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 :
DEBUG: 03/29/2018 17:51:26: 2136d739-b4bd-4a2d-b874-c9f5770db99b - AcquireTokenHandlerBase: === Token Acquisition started:
        Authority: https://login.microsoftonline.com/xxxx-xxxx-xxxx-xxxx/
        Resource: https://management.core.windows.net/
        ClientId: 1950a258-227b-4e31-a9cf-717495945fc2
        CacheType: Microsoft.Azure.Commands.Common.Authentication.AuthenticationStoreTokenCache (1 items)
        Authentication Target: User


DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Verbose: 1 :
DEBUG: 03/29/2018 17:51:26: 2136d739-b4bd-4a2d-b874-c9f5770db99b - TokenCache: Looking up cache for a token...

DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 :
DEBUG: 03/29/2018 17:51:26: 2136d739-b4bd-4a2d-b874-c9f5770db99b - TokenCache: An item matching the requested resource was found in the cache

DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Verbose: 1 :
DEBUG: 03/29/2018 17:51:26: 2136d739-b4bd-4a2d-b874-c9f5770db99b - TokenCache: 31.4095061716667 minutes left until token in cache expires

DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 :
DEBUG: 03/29/2018 17:51:26: 2136d739-b4bd-4a2d-b874-c9f5770db99b - TokenCache: A matching item (access token or refresh token or both) was found in the cache

DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 :
DEBUG: 03/29/2018 17:51:26: 2136d739-b4bd-4a2d-b874-c9f5770db99b - AcquireTokenHandlerBase: === Token Acquisition finished successfully. An access token was retuned:
        Access Token Hash: MTAqUNOwWJurZvlNmjRcIoh4hVlxJvQQwVLM5MW+/f0=
        Refresh Token Hash: PnyUuk6CR2GWbURE7uGPbn/QrCiPYHOA2kT9UWYnyQA=
        Expiration Time: 03/29/2018 18:22:51 +00:00
        User Hash: N/Gz3yO+2RExr+AHDgk5dZYnAIkIRTkZe5tlZHwcjTA=


DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 :
DEBUG: 03/29/2018 17:51:26:  - TokenCache: Serializing token cache with 1 items.

DEBUG: ============================ HTTP REQUEST ============================

HTTP Method:
GET

Absolute Uri:
https://management.azure.com/subscriptions/xxxx-xxxx-xxxx-xxxx/providers/Microsoft.Compute/locations/eastus/operations/0fd58f15-b58a-4e9a-8aff-ee4a240a66e1?api-version=2017-12-01

Headers:

Body:



DEBUG: ============================ HTTP RESPONSE ============================

Status Code:
OK

Headers:
Pragma                        : no-cache
x-ms-ratelimit-remaining-resource: Microsoft.Compute/GetOperation3Min;11983,Microsoft.Compute/GetOperation30Min;23854
Strict-Transport-Security     : max-age=31536000; includeSubDomains
x-ms-served-by                : 70d7e5f6-1c51-403a-aafc-0d55928deb53_131650662970037999
x-ms-request-id               : 4dfce8b6-bfdb-4c02-8917-f3157bdb2bb1
Cache-Control                 : no-cache
Server                        : Microsoft-HTTPAPI/2.0,Microsoft-HTTPAPI/2.0
x-ms-ratelimit-remaining-subscription-reads: 14941
x-ms-correlation-request-id   : 26e0ef11-eaca-43e9-bdb2-27808672c153
x-ms-routing-request-id       : EASTUS:20180329T175127Z:26e0ef11-eaca-43e9-bdb2-27808672c153
X-Content-Type-Options        : nosniff
Date                          : Thu, 29 Mar 2018 17:51:26 GMT

Body:
{
  "startTime": "2018-03-29T13:29:08.9038615-04:00",
  "status": "InProgress",
  "name": "0fd58f15-b58a-4e9a-8aff-ee4a240a66e1"
}


DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 :
DEBUG: 03/29/2018 17:51:57: cf94d1a3-4d3c-4ae4-8f24-c168b71ecb25 - AcquireTokenHandlerBase: === Token Acquisition started:
        Authority: https://login.microsoftonline.com/xxxx-xxxx-xxxx-xxxx/
        Resource: https://management.core.windows.net/
        ClientId: 1950a258-227b-4e31-a9cf-717495945fc2
        CacheType: Microsoft.Azure.Commands.Common.Authentication.AuthenticationStoreTokenCache (1 items)
        Authentication Target: User


DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Verbose: 1 :
DEBUG: 03/29/2018 17:51:57: cf94d1a3-4d3c-4ae4-8f24-c168b71ecb25 - TokenCache: Looking up cache for a token...

DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 :
DEBUG: 03/29/2018 17:51:57: cf94d1a3-4d3c-4ae4-8f24-c168b71ecb25 - TokenCache: An item matching the requested resource was found in the cache

DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Verbose: 1 :
DEBUG: 03/29/2018 17:51:57: cf94d1a3-4d3c-4ae4-8f24-c168b71ecb25 - TokenCache: 30.9020009766667 minutes left until token in cache expires

DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 :
DEBUG: 03/29/2018 17:51:57: cf94d1a3-4d3c-4ae4-8f24-c168b71ecb25 - TokenCache: A matching item (access token or refresh token or both) was found in the cache

DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 :
DEBUG: 03/29/2018 17:51:57: cf94d1a3-4d3c-4ae4-8f24-c168b71ecb25 - AcquireTokenHandlerBase: === Token Acquisition finished successfully. An access token was retuned:
        Access Token Hash: MTAqUNOwWJurZvlNmjRcIoh4hVlxJvQQwVLM5MW+/f0=
        Refresh Token Hash: PnyUuk6CR2GWbURE7uGPbn/QrCiPYHOA2kT9UWYnyQA=
        Expiration Time: 03/29/2018 18:22:51 +00:00
        User Hash: N/Gz3yO+2RExr+AHDgk5dZYnAIkIRTkZe5tlZHwcjTA=


DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 :
DEBUG: 03/29/2018 17:51:57:  - TokenCache: Serializing token cache with 1 items.

DEBUG: ============================ HTTP REQUEST ============================

HTTP Method:
GET

Absolute Uri:
https://management.azure.com/subscriptions/xxxx-xxxx-xxxx-xxxx/providers/Microsoft.Compute/locations/eastus/operations/0fd58f15-b58a-4e9a-8aff-ee4a240a66e1?api-version=2017-12-01

Headers:

Body:



DEBUG: ============================ HTTP RESPONSE ============================

Status Code:
OK

Headers:
Pragma                        : no-cache
x-ms-ratelimit-remaining-resource: Microsoft.Compute/GetOperation3Min;11983,Microsoft.Compute/GetOperation30Min;23851
Strict-Transport-Security     : max-age=31536000; includeSubDomains
x-ms-served-by                : 70d7e5f6-1c51-403a-aafc-0d55928deb53_131650662970037999
x-ms-request-id               : 2d08a6f5-16d2-4872-a4e1-541f88647851
Cache-Control                 : no-cache
Server                        : Microsoft-HTTPAPI/2.0,Microsoft-HTTPAPI/2.0
x-ms-ratelimit-remaining-subscription-reads: 14939
x-ms-correlation-request-id   : 83f98ed5-9d4c-4e66-b30a-e865b53e28fd
x-ms-routing-request-id       : EASTUS:20180329T175157Z:83f98ed5-9d4c-4e66-b30a-e865b53e28fd
X-Content-Type-Options        : nosniff
Date                          : Thu, 29 Mar 2018 17:51:57 GMT

Body:
{
  "startTime": "2018-03-29T13:29:08.9038615-04:00",
  "status": "InProgress",
  "name": "0fd58f15-b58a-4e9a-8aff-ee4a240a66e1"
}


DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 :
DEBUG: 03/29/2018 17:52:27: ff42a7c4-9d49-4f37-b855-1850b4b71883 - AcquireTokenHandlerBase: === Token Acquisition started:
        Authority: https://login.microsoftonline.com/xxxx-xxxx-xxxx-xxxx/
        Resource: https://management.core.windows.net/
        ClientId: 1950a258-227b-4e31-a9cf-717495945fc2
        CacheType: Microsoft.Azure.Commands.Common.Authentication.AuthenticationStoreTokenCache (1 items)
        Authentication Target: User


DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Verbose: 1 :
DEBUG: 03/29/2018 17:52:27: ff42a7c4-9d49-4f37-b855-1850b4b71883 - TokenCache: Looking up cache for a token...

DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 :
DEBUG: 03/29/2018 17:52:27: ff42a7c4-9d49-4f37-b855-1850b4b71883 - TokenCache: An item matching the requested resource was found in the cache

DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Verbose: 1 :
DEBUG: 03/29/2018 17:52:27: ff42a7c4-9d49-4f37-b855-1850b4b71883 - TokenCache: 30.39360228 minutes left until token in cache expires

DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 :
DEBUG: 03/29/2018 17:52:27: ff42a7c4-9d49-4f37-b855-1850b4b71883 - TokenCache: A matching item (access token or refresh token or both) was found in the cache

DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 :
DEBUG: 03/29/2018 17:52:27: ff42a7c4-9d49-4f37-b855-1850b4b71883 - AcquireTokenHandlerBase: === Token Acquisition finished successfully. An access token was retuned:
        Access Token Hash: MTAqUNOwWJurZvlNmjRcIoh4hVlxJvQQwVLM5MW+/f0=
        Refresh Token Hash: PnyUuk6CR2GWbURE7uGPbn/QrCiPYHOA2kT9UWYnyQA=
        Expiration Time: 03/29/2018 18:22:51 +00:00
        User Hash: N/Gz3yO+2RExr+AHDgk5dZYnAIkIRTkZe5tlZHwcjTA=


DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 :
DEBUG: 03/29/2018 17:52:27:  - TokenCache: Serializing token cache with 1 items.

DEBUG: ============================ HTTP REQUEST ============================

HTTP Method:
GET

Absolute Uri:
https://management.azure.com/subscriptions/xxxx-xxxx-xxxx-xxxx/providers/Microsoft.Compute/locations/eastus/operations/0fd58f15-b58a-4e9a-8aff-ee4a240a66e1?api-version=2017-12-01

Headers:

Body:



DEBUG: ============================ HTTP RESPONSE ============================

Status Code:
OK

Headers:
Pragma                        : no-cache
x-ms-ratelimit-remaining-resource: Microsoft.Compute/GetOperation3Min;11982,Microsoft.Compute/GetOperation30Min;23848
Strict-Transport-Security     : max-age=31536000; includeSubDomains
x-ms-served-by                : 70d7e5f6-1c51-403a-aafc-0d55928deb53_131650662970037999
x-ms-request-id               : 93f9dc08-ff0a-4aa0-8ea5-6cda59a60df9
Cache-Control                 : no-cache
Server                        : Microsoft-HTTPAPI/2.0,Microsoft-HTTPAPI/2.0
x-ms-ratelimit-remaining-subscription-reads: 14938
x-ms-correlation-request-id   : cfb706c0-e3b9-45b7-8d51-83d811e679fe
x-ms-routing-request-id       : EASTUS:20180329T175228Z:cfb706c0-e3b9-45b7-8d51-83d811e679fe
X-Content-Type-Options        : nosniff
Date                          : Thu, 29 Mar 2018 17:52:28 GMT

Body:
{
  "startTime": "2018-03-29T13:29:08.9038615-04:00",
  "status": "InProgress",
  "name": "0fd58f15-b58a-4e9a-8aff-ee4a240a66e1"
}


DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 :
DEBUG: 03/29/2018 17:52:58: 9c4c34d8-6d96-40a7-8571-714f3df88593 - AcquireTokenHandlerBase: === Token Acquisition started:
        Authority: https://login.microsoftonline.com/xxxx-xxxx-xxxx-xxxx/
        Resource: https://management.core.windows.net/
        ClientId: 1950a258-227b-4e31-a9cf-717495945fc2
        CacheType: Microsoft.Azure.Commands.Common.Authentication.AuthenticationStoreTokenCache (1 items)
        Authentication Target: User


DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Verbose: 1 :
DEBUG: 03/29/2018 17:52:58: 9c4c34d8-6d96-40a7-8571-714f3df88593 - TokenCache: Looking up cache for a token...

DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 :
DEBUG: 03/29/2018 17:52:58: 9c4c34d8-6d96-40a7-8571-714f3df88593 - TokenCache: An item matching the requested resource was found in the cache

DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Verbose: 1 :
DEBUG: 03/29/2018 17:52:58: 9c4c34d8-6d96-40a7-8571-714f3df88593 - TokenCache: 29.8858039833333 minutes left until token in cache expires

DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 :
DEBUG: 03/29/2018 17:52:58: 9c4c34d8-6d96-40a7-8571-714f3df88593 - TokenCache: A matching item (access token or refresh token or both) was found in the cache

DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 :
DEBUG: 03/29/2018 17:52:58: 9c4c34d8-6d96-40a7-8571-714f3df88593 - AcquireTokenHandlerBase: === Token Acquisition finished successfully. An access token was retuned:
        Access Token Hash: MTAqUNOwWJurZvlNmjRcIoh4hVlxJvQQwVLM5MW+/f0=
        Refresh Token Hash: PnyUuk6CR2GWbURE7uGPbn/QrCiPYHOA2kT9UWYnyQA=
        Expiration Time: 03/29/2018 18:22:51 +00:00
        User Hash: N/Gz3yO+2RExr+AHDgk5dZYnAIkIRTkZe5tlZHwcjTA=


DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 :
DEBUG: 03/29/2018 17:52:58:  - TokenCache: Serializing token cache with 1 items.

DEBUG: ============================ HTTP REQUEST ============================

HTTP Method:
GET

Absolute Uri:
https://management.azure.com/subscriptions/xxxx-xxxx-xxxx-xxxx/providers/Microsoft.Compute/locations/eastus/operations/0fd58f15-b58a-4e9a-8aff-ee4a240a66e1?api-version=2017-12-01

Headers:

Body:



DEBUG: ============================ HTTP RESPONSE ============================

Status Code:
OK

Headers:
Pragma                        : no-cache
x-ms-ratelimit-remaining-resource: Microsoft.Compute/GetOperation3Min;11982,Microsoft.Compute/GetOperation30Min;23845
Strict-Transport-Security     : max-age=31536000; includeSubDomains
x-ms-served-by                : 70d7e5f6-1c51-403a-aafc-0d55928deb53_131650662970037999
x-ms-request-id               : 3d564720-58a4-4afb-a1f0-0442b195ec09
Cache-Control                 : no-cache
Server                        : Microsoft-HTTPAPI/2.0,Microsoft-HTTPAPI/2.0
x-ms-ratelimit-remaining-subscription-reads: 14937
x-ms-correlation-request-id   : 4eea1892-6b99-4b2c-a9d9-071a4a20388d
x-ms-routing-request-id       : EASTUS:20180329T175259Z:4eea1892-6b99-4b2c-a9d9-071a4a20388d
X-Content-Type-Options        : nosniff
Date                          : Thu, 29 Mar 2018 17:52:59 GMT

Body:
{
  "startTime": "2018-03-29T13:29:08.9038615-04:00",
  "status": "InProgress",
  "name": "0fd58f15-b58a-4e9a-8aff-ee4a240a66e1"
}


DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 :
DEBUG: 03/29/2018 17:53:29: 0a65ccc2-0f13-4bc9-a3ee-0234b9dad09f - AcquireTokenHandlerBase: === Token Acquisition started:
        Authority: https://login.microsoftonline.com/xxxx-xxxx-xxxx-xxxx/
        Resource: https://management.core.windows.net/
        ClientId: 1950a258-227b-4e31-a9cf-717495945fc2
        CacheType: Microsoft.Azure.Commands.Common.Authentication.AuthenticationStoreTokenCache (1 items)
        Authentication Target: User


DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Verbose: 1 :
DEBUG: 03/29/2018 17:53:29: 0a65ccc2-0f13-4bc9-a3ee-0234b9dad09f - TokenCache: Looking up cache for a token...

DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 :
DEBUG: 03/29/2018 17:53:29: 0a65ccc2-0f13-4bc9-a3ee-0234b9dad09f - TokenCache: An item matching the requested resource was found in the cache

DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Verbose: 1 :
DEBUG: 03/29/2018 17:53:29: 0a65ccc2-0f13-4bc9-a3ee-0234b9dad09f - TokenCache: 29.3670655116667 minutes left until token in cache expires

DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 :
DEBUG: 03/29/2018 17:53:29: 0a65ccc2-0f13-4bc9-a3ee-0234b9dad09f - TokenCache: A matching item (access token or refresh token or both) was found in the cache

DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 :
DEBUG: 03/29/2018 17:53:29: 0a65ccc2-0f13-4bc9-a3ee-0234b9dad09f - AcquireTokenHandlerBase: === Token Acquisition finished successfully. An access token was retuned:
        Access Token Hash: MTAqUNOwWJurZvlNmjRcIoh4hVlxJvQQwVLM5MW+/f0=
        Refresh Token Hash: PnyUuk6CR2GWbURE7uGPbn/QrCiPYHOA2kT9UWYnyQA=
        Expiration Time: 03/29/2018 18:22:51 +00:00
        User Hash: N/Gz3yO+2RExr+AHDgk5dZYnAIkIRTkZe5tlZHwcjTA=


DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 :
DEBUG: 03/29/2018 17:53:29:  - TokenCache: Serializing token cache with 1 items.

DEBUG: ============================ HTTP REQUEST ============================

HTTP Method:
GET

Absolute Uri:
https://management.azure.com/subscriptions/xxxx-xxxx-xxxx-xxxx/providers/Microsoft.Compute/locations/eastus/operations/0fd58f15-b58a-4e9a-8aff-ee4a240a66e1?api-version=2017-12-01

Headers:

Body:



DEBUG: ============================ HTTP RESPONSE ============================

Status Code:
OK

Headers:
Pragma                        : no-cache
x-ms-ratelimit-remaining-resource: Microsoft.Compute/GetOperation3Min;11982,Microsoft.Compute/GetOperation30Min;23842
Strict-Transport-Security     : max-age=31536000; includeSubDomains
x-ms-served-by                : 70d7e5f6-1c51-403a-aafc-0d55928deb53_131650662970037999
x-ms-request-id               : 8a6b2321-30ce-455f-bbc9-dbbcfd36d753
Cache-Control                 : no-cache
Server                        : Microsoft-HTTPAPI/2.0,Microsoft-HTTPAPI/2.0
x-ms-ratelimit-remaining-subscription-reads: 14936
x-ms-correlation-request-id   : 3d78b566-13b9-4e57-904a-18f62189ac3a
x-ms-routing-request-id       : EASTUS:20180329T175330Z:3d78b566-13b9-4e57-904a-18f62189ac3a
X-Content-Type-Options        : nosniff
Date                          : Thu, 29 Mar 2018 17:53:30 GMT

Body:
{
  "startTime": "2018-03-29T13:29:08.9038615-04:00",
  "status": "InProgress",
  "name": "0fd58f15-b58a-4e9a-8aff-ee4a240a66e1"
}


DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 :
DEBUG: 03/29/2018 17:54:00: 8115085f-9e40-49cd-8a44-639c25955045 - AcquireTokenHandlerBase: === Token Acquisition started:
        Authority: https://login.microsoftonline.com/xxxx-xxxx-xxxx-xxxx/
        Resource: https://management.core.windows.net/
        ClientId: 1950a258-227b-4e31-a9cf-717495945fc2
        CacheType: Microsoft.Azure.Commands.Common.Authentication.AuthenticationStoreTokenCache (1 items)
        Authentication Target: User


DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Verbose: 1 :
DEBUG: 03/29/2018 17:54:00: 8115085f-9e40-49cd-8a44-639c25955045 - TokenCache: Looking up cache for a token...

DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 :
DEBUG: 03/29/2018 17:54:00: 8115085f-9e40-49cd-8a44-639c25955045 - TokenCache: An item matching the requested resource was found in the cache

DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Verbose: 1 :
DEBUG: 03/29/2018 17:54:00: 8115085f-9e40-49cd-8a44-639c25955045 - TokenCache: 28.8421884983333 minutes left until token in cache expires

DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 :
DEBUG: 03/29/2018 17:54:00: 8115085f-9e40-49cd-8a44-639c25955045 - TokenCache: A matching item (access token or refresh token or both) was found in the cache

DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 :
DEBUG: 03/29/2018 17:54:00: 8115085f-9e40-49cd-8a44-639c25955045 - AcquireTokenHandlerBase: === Token Acquisition finished successfully. An access token was retuned:
        Access Token Hash: MTAqUNOwWJurZvlNmjRcIoh4hVlxJvQQwVLM5MW+/f0=
        Refresh Token Hash: PnyUuk6CR2GWbURE7uGPbn/QrCiPYHOA2kT9UWYnyQA=
        Expiration Time: 03/29/2018 18:22:51 +00:00
        User Hash: N/Gz3yO+2RExr+AHDgk5dZYnAIkIRTkZe5tlZHwcjTA=


DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 :
DEBUG: 03/29/2018 17:54:00:  - TokenCache: Serializing token cache with 1 items.

DEBUG: ============================ HTTP REQUEST ============================

HTTP Method:
GET

Absolute Uri:
https://management.azure.com/subscriptions/xxxx-xxxx-xxxx-xxxx/providers/Microsoft.Compute/locations/eastus/operations/0fd58f15-b58a-4e9a-8aff-ee4a240a66e1?api-version=2017-12-01

Headers:

Body:



DEBUG: ============================ HTTP RESPONSE ============================

Status Code:
OK

Headers:
Pragma                        : no-cache
x-ms-ratelimit-remaining-resource: Microsoft.Compute/GetOperation3Min;11985,Microsoft.Compute/GetOperation30Min;23839
Strict-Transport-Security     : max-age=31536000; includeSubDomains
x-ms-served-by                : 70d7e5f6-1c51-403a-aafc-0d55928deb53_131650662970037999
x-ms-request-id               : f19a42a8-cf5e-4778-b4c8-a47adcace6d3
Cache-Control                 : no-cache
Server                        : Microsoft-HTTPAPI/2.0,Microsoft-HTTPAPI/2.0
x-ms-ratelimit-remaining-subscription-reads: 14935
x-ms-correlation-request-id   : ea83480c-6b04-4a7c-8dc0-723e39b2e976
x-ms-routing-request-id       : EASTUS:20180329T175401Z:ea83480c-6b04-4a7c-8dc0-723e39b2e976
X-Content-Type-Options        : nosniff
Date                          : Thu, 29 Mar 2018 17:54:00 GMT

Body:
{
  "startTime": "2018-03-29T13:29:08.9038615-04:00",
  "status": "InProgress",
  "name": "0fd58f15-b58a-4e9a-8aff-ee4a240a66e1"
}


DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 :
DEBUG: 03/29/2018 17:54:31: 4b7e7891-78e9-4a0d-aab0-c0ed60537651 - AcquireTokenHandlerBase: === Token Acquisition started:
        Authority: https://login.microsoftonline.com/xxxx-xxxx-xxxx-xxxx/
        Resource: https://management.core.windows.net/
        ClientId: 1950a258-227b-4e31-a9cf-717495945fc2
        CacheType: Microsoft.Azure.Commands.Common.Authentication.AuthenticationStoreTokenCache (1 items)
        Authentication Target: User


DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Verbose: 1 :
DEBUG: 03/29/2018 17:54:31: 4b7e7891-78e9-4a0d-aab0-c0ed60537651 - TokenCache: Looking up cache for a token...

DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 :
DEBUG: 03/29/2018 17:54:31: 4b7e7891-78e9-4a0d-aab0-c0ed60537651 - TokenCache: An item matching the requested resource was found in the cache

DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Verbose: 1 :
DEBUG: 03/29/2018 17:54:31: 4b7e7891-78e9-4a0d-aab0-c0ed60537651 - TokenCache: 28.3290537666667 minutes left until token in cache expires

DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 :
DEBUG: 03/29/2018 17:54:31: 4b7e7891-78e9-4a0d-aab0-c0ed60537651 - TokenCache: A matching item (access token or refresh token or both) was found in the cache

DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 :
DEBUG: 03/29/2018 17:54:31: 4b7e7891-78e9-4a0d-aab0-c0ed60537651 - AcquireTokenHandlerBase: === Token Acquisition finished successfully. An access token was retuned:
        Access Token Hash: MTAqUNOwWJurZvlNmjRcIoh4hVlxJvQQwVLM5MW+/f0=
        Refresh Token Hash: PnyUuk6CR2GWbURE7uGPbn/QrCiPYHOA2kT9UWYnyQA=
        Expiration Time: 03/29/2018 18:22:51 +00:00
        User Hash: N/Gz3yO+2RExr+AHDgk5dZYnAIkIRTkZe5tlZHwcjTA=


DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 :
DEBUG: 03/29/2018 17:54:31:  - TokenCache: Serializing token cache with 1 items.

DEBUG: ============================ HTTP REQUEST ============================

HTTP Method:
GET

Absolute Uri:
https://management.azure.com/subscriptions/xxxx-xxxx-xxxx-xxxx/providers/Microsoft.Compute/locations/eastus/operations/0fd58f15-b58a-4e9a-8aff-ee4a240a66e1?api-version=2017-12-01

Headers:

Body:



DEBUG: ============================ HTTP RESPONSE ============================

Status Code:
OK

Headers:
Pragma                        : no-cache
x-ms-ratelimit-remaining-resource: Microsoft.Compute/GetOperation3Min;11985,Microsoft.Compute/GetOperation30Min;23836
Strict-Transport-Security     : max-age=31536000; includeSubDomains
x-ms-served-by                : 70d7e5f6-1c51-403a-aafc-0d55928deb53_131650662970037999
x-ms-request-id               : 1dca41d9-a12d-4f63-83ed-99cd427fa751
Cache-Control                 : no-cache
Server                        : Microsoft-HTTPAPI/2.0,Microsoft-HTTPAPI/2.0
x-ms-ratelimit-remaining-subscription-reads: 14933
x-ms-correlation-request-id   : 933ab2f5-5738-4391-890b-916f9e4bf39b
x-ms-routing-request-id       : EASTUS:20180329T175432Z:933ab2f5-5738-4391-890b-916f9e4bf39b
X-Content-Type-Options        : nosniff
Date                          : Thu, 29 Mar 2018 17:54:31 GMT

Body:
{
  "startTime": "2018-03-29T13:29:08.9038615-04:00",
  "endTime": "2018-03-29T13:54:30.1933236-04:00",
  "status": "Failed",
  "error": {
    "code": "VMAgentStatusCommunicationError",
    "message": "VM 'iisvm' has not reported status for VM agent or extensions. Please verify the VM has a running VM agent, and can establish outbound connections to Azure storage."
  },
  "name": "0fd58f15-b58a-4e9a-8aff-ee4a240a66e1"
}


DEBUG: AzureQoSEvent: CommandName - New-AzureRmVM; IsSuccess - True; Duration - 00:30:21.1587333; Exception - ;
DEBUG: Finish sending metric.
DEBUG: 1:54:32 PM - NewAzureVMCommand end processing.
DEBUG: 1:54:32 PM - NewAzureVMCommand end processing.
New-AzureRmVM : Long running operation failed with status 'Failed'. Additional Info:'VM 'iisvm' has not reported status for VM agent or extensions. Please verify the VM has a running VM agent, and can establish
outbound connections to Azure storage.'
ErrorCode: VMAgentStatusCommunicationError
ErrorMessage: VM 'iisvm' has not reported status for VM agent or extensions. Please verify the VM has a running VM agent, and can establish outbound connections to Azure storage.
StartTime: 3/29/2018 1:29:08 PM
EndTime: 3/29/2018 1:54:30 PM
OperationID: 0fd58f15-b58a-4e9a-8aff-ee4a240a66e1
Status: Failed
At C:\development\packer\deploy-packer.ps1:94 char:9
+         New-AzureRmVM -ResourceGroupName $rgName -Location $location  ...
+         ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
    + CategoryInfo          : CloseError: (:) [New-AzureRmVM], ComputeCloudException
    + FullyQualifiedErrorId : Microsoft.Azure.Commands.Compute.NewAzureVMCommand

DEBUG: AzureQoSEvent: CommandName - New-AzureRmVM; IsSuccess - False; Duration - 00:30:21.1587333; Exception - Microsoft.Azure.Commands.Compute.Common.ComputeCloudException: Long running operation failed with status 'Failed'. Additional Info:'VM 'iisvm' has not reported status for VM agent or extensions. Please verify the VM has a running VM agent, and can establish outbound connections to Azure storage.'
ErrorCode: VMAgentStatusCommunicationError
ErrorMessage: VM 'iisvm' has not reported status for VM agent or extensions. Please verify the VM has a running VM agent, and can establish outbound connections to Azure storage.
StartTime: 3/29/2018 1:29:08 PM
EndTime: 3/29/2018 1:54:30 PM
OperationID: 0fd58f15-b58a-4e9a-8aff-ee4a240a66e1
Status: Failed ---> Microsoft.Rest.Azure.CloudException: Long running operation failed with status 'Failed'. Additional Info:'VM 'iisvm' has not reported status for VM agent or extensions. Please verify the VM has a running VM agent, and can establish outbound connections to Azure storage.'
   at Microsoft.Rest.Azure.AzureClientExtensions.<GetLongRunningOperationResultAsync>d__1`2.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Microsoft.Rest.Azure.AzureClientExtensions.<GetLongRunningOperationResultAsync>d__0`1.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Microsoft.Rest.Azure.AzureClientExtensions.<GetPutOrPatchOperationResultAsync>d__4`1.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Microsoft.Azure.Management.Compute.VirtualMachineExtensionsOperations.<CreateOrUpdateWithHttpMessagesAsync>d__5.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Microsoft.Azure.Commands.Compute.NewAzureVMCommand.<DefaultExecuteCmdlet>b__106_0()
   at Microsoft.Azure.Commands.Compute.ComputeClientBaseCmdlet.ExecuteClientAction(Action action)
   --- End of inner exception stack trace ---
   at Microsoft.Azure.Commands.Compute.ComputeClientBaseCmdlet.ExecuteClientAction(Action action)
   at Microsoft.Azure.Commands.Compute.NewAzureVMCommand.DefaultExecuteCmdlet()
   at Microsoft.WindowsAzure.Commands.Utilities.Common.AzurePSCmdlet.ProcessRecord();
DEBUG: Finish sending metric.
DEBUG: 1:54:33 PM - NewAzureVMCommand end processing.
DEBUG: 1:54:33 PM - NewAzureVMCommand end processing.

[vladimir-shcherbakov]

@praries880 Could you take a look?

[sergey-shandar]

@praries880 it's not a simple parameter set. I would recommend to assign it to Compute team.

[maddieclayton]

@hyonholee @nibhat Can you take a look at this issue?

[huangpf]

Can someone from the CLI side to help instruct what did you do differently there? It may be because of different designs.

[huangpf]

We would like to defer the feature parity triage to CLI team first, because I think that feature was implemented after PS' cmdlet counterpart. @maddieclayton