search

Azure / azure-powershell

Microsoft Azure PowerShell
Other
4.22k stars 3.83k forks source link

Add-AzureAccount non-interactive flow fail to setup token cache #4299

Closed afengli closed 7 years ago

afengli commented 7 years ago

Cmdlet(s)

Add-AzureAccount

PowerShell Version

Instructions: to get PowerShell version, type $PSVersionTable and look for the value associated with PSVersion

5.1.14393.1198

Module Version

4.2.0

OS Version

Instructions: to get OS version, type $PSversionTable and look for value associated with BuildVersion 5.1.14393.1198

Description

Add-AzureAccount does not setup token cache properly in non-interactive flow

An scenario not covered by https://github.com/Azure/azure-powershell/issues/4080

Debug Output

Instructions: to get Debug Output, set $DebugPreference="Continue" and then execute the cmdlet or script causing the issue

PS C:\test> .\asm.ps1 Executing Remove-AzureAccount and Clear-AzureProfile (Classic)... DEBUG: 12:25:11 AM - GetAzureAccount begin processing with ParameterSet 'AllParameterSets'. DEBUG: 12:25:11 AM - using account id 'admin@fenglihotmailsubad.onmicrosoft.com'... DEBUG: 12:25:11 AM - RemoveAzureAccountCommand begin processing with ParameterSet 'AllParameterSets'. DEBUG: 12:25:11 AM - using account id 'admin@fenglihotmailsubad.onmicrosoft.com'... WARNING: The default subscription is being removed. Use Select-AzureSubscription -Default to select a new default subscription. DEBUG: 12:25:11 AM - RemoveAzureAccountCommand end processing. DEBUG: 12:25:11 AM - RemoveAzureAccountCommand end processing. DEBUG: 12:25:11 AM - GetAzureAccount end processing. DEBUG: 12:25:11 AM - GetAzureAccount end processing. DEBUG: 12:25:11 AM - ClearAzureProfileCommand begin processing with ParameterSet '__AllParameterSets'. DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 : DEBUG: 07/12/2017 00:25:11: - TokenCache: Deserialized 1 items to token cache. DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 : DEBUG: 07/12/2017 00:25:11: - TokenCache: Clearing Cache :- 1 items to be removed DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 : DEBUG: 07/12/2017 00:25:11: - TokenCache: Successfully Cleared Cache DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 : DEBUG: 07/12/2017 00:25:11: - TokenCache: Serializing token cache with 0 items. DEBUG: 12:25:11 AM - ClearAzureProfileCommand end processing. DEBUG: 12:25:11 AM - ClearAzureProfileCommand end processing. DEBUG: 12:25:11 AM - AddAzureAccount begin processing with ParameterSet 'User'. DEBUG: [Common.Authentication]: Authenticating using configuration values: Domain: 'Common', Endpoint: 'https://login.microsoftonline.com/', ClientId: '1950a258-227b-4e31-a9cf-717495945fc2', ClientRedirect: 'urn:ietf:wg:oauth:2.0:oob', ResourceClientUri: 'https://management.core.windows.net/', ValidateAuthrity: 'True' DEBUG: [Common.Authentication]: Acquiring token using context with Authority 'https://login.microsoftonline.com/Common/', CorrelationId: '00000000-0000-0000-0000-000000000000', ValidateAuthority: 'True' DEBUG: [Common.Authentication]: Acquiring token using AdalConfiguration with Domain: 'Common', AdEndpoint: 'https://login.microsoftonline.com/', ClientId: '1950a258-227b-4e31-a9cf-717495945fc2', ClientRedirectUri: urn:ietf:wg:oauth:2.0:oob DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 : DEBUG: 07/12/2017 00:25:11: 39256786-a90e-462d-91dc-7b7c12c039bf - AcquireTokenHandlerBase: === Token Acquisition started: Authority: https://login.microsoftonline.com/Common/ Resource: https://management.core.windows.net/ ClientId: 1950a258-227b-4e31-a9cf-717495945fc2 CacheType: Microsoft.Azure.Commands.Common.Authentication.ProtectedFileTokenCache (0 items) Authentication Target: User

DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Verbose: 1 : DEBUG: 07/12/2017 00:25:11: 39256786-a90e-462d-91dc-7b7c12c039bf - TokenCache: Looking up cache for a token... DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 : DEBUG: 07/12/2017 00:25:11: 39256786-a90e-462d-91dc-7b7c12c039bf - TokenCache: No matching token was found in the cache DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 : DEBUG: 07/12/2017 00:25:11: 39256786-a90e-462d-91dc-7b7c12c039bf - d0: Sending user realm discovery request to 'https://login.microsoftonline.com/common/UserRealm/admin@fenglihotmailsubad.onmicrosoft.com?api-version=1.0' DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 : DEBUG: 07/12/2017 00:25:11: 39256786-a90e-462d-91dc-7b7c12c039bf - d4: User with hash 'aaf8AUYAYjnQ/ncvvmA82umJyACdMhWn3QAziJDXBgI=' detected as 'Managed' DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Verbose: 1 : DEBUG: 07/12/2017 00:25:12: 39256786-a90e-462d-91dc-7b7c12c039bf - TokenCache: Storing token in the cache... DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Verbose: 1 : DEBUG: 07/12/2017 00:25:12: 39256786-a90e-462d-91dc-7b7c12c039bf - TokenCache: An item was stored in the cache DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 : DEBUG: 07/12/2017 00:25:12: 39256786-a90e-462d-91dc-7b7c12c039bf - AcquireTokenHandlerBase: === Token Acquisition finished successfully. An access token was retuned: Access Token Hash: avu7ccvhoS2DeYJST4CU3nlxEtnZ6KQpEEsd1T7LsQ0= Refresh Token Hash: CT1E2WqAjI+F/NEHwFeuCR7QfHPURJ4fcriIkT1rjf4= Expiration Time: 07/12/2017 00:35:11 +00:00 User Hash: GgNaeXVT4zdXb7PZcZpIx9xxn+NDiENLhlXPhPgff9o=

DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 : DEBUG: 07/12/2017 00:25:12: - TokenCache: Serializing token cache with 1 items. DEBUG: ============================ HTTP REQUEST ============================

HTTP Method: GET

Absolute Uri: https://management.core.windows.net/subscriptions

Headers: x-ms-version : 2013-08-01

Body:

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

Status Code: OK

Headers: x-ms-servedbyregion : ussouth3 x-ms-request-id : cfad064ac5b9a0cd8bf8505507dbe9e7 Cache-Control : no-cache Date : Wed, 12 Jul 2017 00:25:12 GMT Server : 1.0.6198.509,(rd_rdfe_stable.170705-1940),Microsoft-HTTPAPI/2.0

Body:

be8b8d49-5fe4-4abb-bac1-b283469b1da9 Windows Azure MSDN - Visual Studio Ultimate Active afengli@hotmail.com afengli@hotmail.com 20 100 20 0 3 5 50 6 20 2 20 Azure_Platform_All;Azure_Paid;Azure_Consumption;Azure_MSDN;Azure_Credit;Azure_MS-AZR-0063P;Individual 32b608e7-c186-4746-b3ac-1f1614ec7574 2012-05-14T02:18:42Z DEBUG: [Common.Authentication]: Authenticating using configuration values: Domain: '32b608e7-c186-4746-b3ac-1f1614ec7574', Endpoint: 'https://login.microsoftonline.com/', ClientId: '1950a258-227b-4e31-a9cf-717495945fc2', ClientRedirect: 'urn:ietf:wg:oauth:2.0:oob', ResourceClientUri: 'https://management.core.windows.net/', ValidateAuthrity: 'True' DEBUG: [Common.Authentication]: Acquiring token using context with Authority 'https://login.microsoftonline.com/32b608e7-c186-4746-b3ac-1f1614ec7574/', CorrelationId: '00000000-0000-0000-0000-000000000000', ValidateAuthority: 'True' DEBUG: [Common.Authentication]: Acquiring token using AdalConfiguration with Domain: '32b608e7-c186-4746-b3ac-1f1614ec7574', AdEndpoint: 'https://login.microsoftonline.com/', ClientId: '1950a258-227b-4e31-a9cf-717495945fc2', ClientRedirectUri: urn:ietf:wg:oauth:2.0:oob DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 : DEBUG: 07/12/2017 00:25:12: cedb6a7f-0472-48dc-8736-efbdbaef4316 - AcquireTokenHandlerBase: === Token Acquisition started: Authority: https://login.microsoftonline.com/32b608e7-c186-4746-b3ac-1f1614ec7574/ Resource: https://management.core.windows.net/ ClientId: 1950a258-227b-4e31-a9cf-717495945fc2 CacheType: Microsoft.Azure.Commands.Common.Authentication.ProtectedFileTokenCache (1 items) Authentication Target: User DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 : DEBUG: 07/12/2017 00:25:12: - TokenCache: Deserialized 1 items to token cache. DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Verbose: 1 : DEBUG: 07/12/2017 00:25:12: cedb6a7f-0472-48dc-8736-efbdbaef4316 - TokenCache: Looking up cache for a token... DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 : DEBUG: 07/12/2017 00:25:12: cedb6a7f-0472-48dc-8736-efbdbaef4316 - TokenCache: An item matching the requested resource was found in the cache DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Verbose: 1 : DEBUG: 07/12/2017 00:25:12: cedb6a7f-0472-48dc-8736-efbdbaef4316 - TokenCache: 9.97628596333333 minutes left until token in cache expires DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 : DEBUG: 07/12/2017 00:25:12: cedb6a7f-0472-48dc-8736-efbdbaef4316 - TokenCache: A matching item (access token or refresh token or both) was found in the cache DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 : DEBUG: 07/12/2017 00:25:12: cedb6a7f-0472-48dc-8736-efbdbaef4316 - AcquireTokenHandlerBase: === Token Acquisition finished successfully. An access token was retuned: Access Token Hash: avu7ccvhoS2DeYJST4CU3nlxEtnZ6KQpEEsd1T7LsQ0= Refresh Token Hash: CT1E2WqAjI+F/NEHwFeuCR7QfHPURJ4fcriIkT1rjf4= Expiration Time: 07/12/2017 00:35:11 +00:00 User Hash: GgNaeXVT4zdXb7PZcZpIx9xxn+NDiENLhlXPhPgff9o= DEBUG: ============================ HTTP REQUEST ============================ HTTP Method: GET Absolute Uri: https://management.core.windows.net/subscriptions Headers: x-ms-version : 2013-08-01 Body: DEBUG: ============================ HTTP RESPONSE ============================ Status Code: OK Headers: x-ms-servedbyregion : ussouth3 x-ms-request-id : 864914610e39a55c88a4cd5caebe6e64 Cache-Control : no-cache Date : Wed, 12 Jul 2017 00:25:13 GMT Server : 1.0.6198.509,(rd_rdfe_stable.170705-1940),Microsoft-HTTPAPI/2.0 Body: be8b8d49-5fe4-4abb-bac1-b283469b1da9 Windows Azure MSDN - Visual Studio Ultimate Active afengli@hotmail.com afengli@hotmail.com 20 100 20 0 3 5 50 6 20 2 20 Azure_Platform_All;Azure_Paid;Azure_Consumption;Azure_MSDN;Azure_Credit;Azure_MS-AZR-0063P;Individual 32b608e7-c186-4746-b3ac-1f1614ec7574 2012-05-14T02:18:42Z VERBOSE: Account "admin@fenglihotmailsubad.onmicrosoft.com" has been added. VERBOSE: Subscription "Windows Azure MSDN - Visual Studio Ultimate" is selected as the default subscription. VERBOSE: To view all the subscriptions, please use Get-AzureSubscription. VERBOSE: To switch to a different subscription, please use Select-AzureSubscription. DEBUG: 12:25:13 AM - AddAzureAccount end processing. DEBUG: 12:25:13 AM - AddAzureAccount end processing. DEBUG: 12:25:13 AM - SelectAzureSubscriptionCommand begin processing with ParameterSet 'SelectSubscriptionByIdParameterSet'. DEBUG: 12:25:13 AM - using account id 'admin@fenglihotmailsubad.onmicrosoft.com'... DEBUG: 12:25:13 AM - SelectAzureSubscriptionCommand end processing. DEBUG: 12:25:13 AM - SelectAzureSubscriptionCommand end processing. DEBUG: 12:25:13 AM - GetAzureServiceCommand begin processing with ParameterSet '__AllParameterSets'. Confirm Continue with this operation? [Y] Yes [A] Yes to All [H] Halt Command [S] Suspend [?] Help (default is "Y"): a DEBUG: 12:25:16 AM - using account id 'admin@fenglihotmailsubad.onmicrosoft.com'... VERBOSE: 12:25:16 AM - Begin Operation: Get-AzureService Confirm Continue with this operation? [Y] Yes [A] Yes to All [H] Halt Command [S] Suspend [?] Help (default is "Y"): a DEBUG: [Common.Authentication]: Authenticating using Account: 'admin@fenglihotmailsubad.onmicrosoft.com', environment: 'AzureCloud', tenant: '32b608e7-c186-4746-b3ac-1f1614ec7574' DEBUG: [Common.Authentication]: Authenticating using configuration values: Domain: '32b608e7-c186-4746-b3ac-1f1614ec7574', Endpoint: 'https://login.microsoftonline.com/', ClientId: '1950a258-227b-4e31-a9cf-717495945fc2', ClientRedirect: 'urn:ietf:wg:oauth:2.0:oob', ResourceClientUri: 'https://management.core.windows.net/', ValidateAuthrity: 'True' DEBUG: [Common.Authentication]: Acquiring token using context with Authority 'https://login.microsoftonline.com/32b608e7-c186-4746-b3ac-1f1614ec7574/', CorrelationId: '00000000-0000-0000-0000-000000000000', ValidateAuthority: 'True' DEBUG: [Common.Authentication]: Acquiring token using AdalConfiguration with Domain: '32b608e7-c186-4746-b3ac-1f1614ec7574', AdEndpoint: 'https://login.microsoftonline.com/', ClientId: '1950a258-227b-4e31-a9cf-717495945fc2', ClientRedirectUri: urn:ietf:wg:oauth:2.0:oob DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 : DEBUG: 07/12/2017 00:25:17: ed99c4ff-ddec-4441-8fbf-b213d5ba6f5d - AcquireTokenHandlerBase: === Token Acquisition started: Authority: https://login.microsoftonline.com/32b608e7-c186-4746-b3ac-1f1614ec7574/ Resource: https://management.core.windows.net/ ClientId: 1950a258-227b-4e31-a9cf-717495945fc2 CacheType: Microsoft.IdentityModel.Clients.ActiveDirectory.TokenCache (0 items) Authentication Target: User DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Verbose: 1 : DEBUG: 07/12/2017 00:25:17: ed99c4ff-ddec-4441-8fbf-b213d5ba6f5d - TokenCache: Looking up cache for a token... DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 : DEBUG: 07/12/2017 00:25:17: ed99c4ff-ddec-4441-8fbf-b213d5ba6f5d - TokenCache: No matching token was found in the cache DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Verbose: 1 : DEBUG: 07/12/2017 00:25:17: - WindowsFormsWebAuthenticationDialogBase: Navigating to 'https://login.microsoftonline.com/32b608e7-c186-4746-b3ac-1f1614ec7574/oauth2/authorize?resource=https://management.core.windows.net/&client_ id=1950a258-227b-4e31-a9cf-717495945fc2&response_type=code&haschrome=1&redirect_uri=urn:ietf:wg:oauth:2.0:oob&login_hint=admin@fenglihotmailsu bad.onmicrosoft.com&client-request-id=ed99c4ff-ddec-4441-8fbf-b213d5ba6f5d&prompt=attempt_none&x-client-SKU=.NET&x-client-Ver=2.28.3.860&x-cli ent-CPU=x64&x-client-OS=Microsoft Windows NT 10.0.14393.0&site_id=501358&display=popup'. DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Error: 4 : DEBUG: 07/12/2017 00:25:17: ed99c4ff-ddec-4441-8fbf-b213d5ba6f5d - d__0: Microsoft.IdentityModel.Clients.ActiveDirectory.AdalException: user_interaction_required: One of two conditions was encountered: 1. The PromptBehavior.Never flag was passed, but the constraint could not be honored, because user interaction was required. 2. An error occurred during a silent web authentication that prevented the http authentication flow from completing in a short enough time frame at Microsoft.IdentityModel.Clients.ActiveDirectory.AcquireTokenInteractiveHandler.VerifyAuthorizationResult() at Microsoft.IdentityModel.Clients.ActiveDirectory.AcquireTokenInteractiveHandler.PreTokenRequest() at Microsoft.IdentityModel.Clients.ActiveDirectory.AcquireTokenHandlerBase.d__0.MoveNext() ErrorCode: user_interaction_required DEBUG: [Common.Authentication]: Received exception User Interaction is required to authenticate this user. Please authenticate using the log in dialog. In PowerShell, execute Login-AzureRMAccount for Azure Resource Manager cmdlets or Add-AzureAccount for service management cmdlets., while authenticating. Confirm Your Azure credentials have not been set up or have expired, please run Add-AzureAccount to set up your Azure credentials. [Y] Yes [A] Yes to All [H] Halt Command [S] Suspend [?] Help (default is "Y"): a Id Type Subscriptions Tenants -- ---- ------------- ------- admin@fenglihotmailsubad.onmicrosoft.com User be8b8d49-5fe4-4abb-bac1-b283469b1da9 {32b608e7-c186-4746-b3ac-1f1614ec7574} Get-AzureService : Your Azure credentials have not been set up or have expired, please run Add-AzureAccount to set up your Azure credentials. At C:\test\asm.ps1:13 char:5 + Get-AzureService -Debug + ~~~~~~~~~~~~~~~~~~~~~~~ + CategoryInfo : CloseError: (:) [Get-AzureService], ArgumentException + FullyQualifiedErrorId : Microsoft.WindowsAzure.Commands.ServiceManagement.HostedServices.GetAzureServiceCommand VERBOSE: 12:25:18 AM - Completed Operation: Get-AzureService DEBUG: 12:25:18 AM - GetAzureServiceCommand end processing. DEBUG: 12:25:18 AM - GetAzureServiceCommand end processing. ### Script/Steps for Reproduction $UserName = "admin@fenglihotmailsubad.onmicrosoft.com" $Password = ConvertTo-SecureString 'Password' -AsPlainText -Force $AzureRMCredential = New-Object -TypeName System.Management.Automation.PSCredential($UserName, $Password) $DebugPreference="Continue" Write-Host "Executing Remove-AzureAccount and Clear-AzureProfile (Classic)..." Get-AzureAccount | ForEach-Object { Remove-AzureAccount $_.Id -Force } Clear-AzureProfile -Force Add-AzureAccount -Credential $AzureRMCredential -Verbose Select-AzureSubscription -SubscriptionId 'be8b8d49-5fe4-4abb-bac1-b283469b1da9' Get-AzureService -Debug get-azurevm -servicename fengli-DCenter1 -name dcenter1dc -Verbose
afengli commented 7 years ago

Following are commands that can verify the problem after non-interactive flow logon.

Get-AzureService Get-AzureVM Set-AzureSubscription -SubscriptionId xxx - CurrentStorageAccountName yyy

afengli commented 7 years ago

@markcowl , can we mark this Sprint Candidate?

markcowl commented 7 years ago

@afengli It is actually in the current milestone

markcowl commented 7 years ago

Fix released in release 4.2.1: https://www.powershellgallery.com/packages/AzureRM/4.2.1. Closing

akinsriv commented 7 years ago

Please use below line of codes in case still using 4.1.0, You can work around this be doing the following after log in $cdata =[Microsoft.Azure.Commands.Common.Authentication.AzureSession]::Instance.TokenCache.Serialize()