Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

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

Closed
afengli opened this issue Jul 12, 2017 · 5 comments
Closed

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

afengli opened this issue Jul 12, 2017 · 5 comments
Assignees
@markcowl
Labels
Azure PS Team
Milestone
August 2017

Comments

@afengli
Copy link

afengli commented Jul 12, 2017 •
edited by azuresdkci
Loading

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 '[email protected]'...
DEBUG: 12:25:11 AM - RemoveAzureAccountCommand begin processing with ParameterSet '__AllParameterSets'.
DEBUG: 12:25:11 AM - using account id '[email protected]'...
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 - d__0: Sending user realm discovery request to
'https://login.microsoftonline.com/common/UserRealm/[email protected]?api-version=1.0'
DEBUG: Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 :
DEBUG: 07/12/2017 00:25:11: 39256786-a90e-462d-91dc-7b7c12c039bf - d__4: 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
[email protected]
[email protected]
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
[email protected]
[email protected]
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 "[email protected]" 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 '[email protected]'...
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 '[email protected]'...
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: '[email protected]', 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

[email protected] 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 = "[email protected]"
$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
Copy link
Author

afengli commented Jul 12, 2017

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

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

@markcowl markcowl modified the milestone: August 2017 Jul 12, 2017
@afengli
Copy link
Author

afengli commented Jul 12, 2017

@markcowl , can we mark this Sprint Candidate?

@markcowl
Copy link
Member

@afengli It is actually in the current milestone

@markcowl markcowl mentioned this issue Jul 14, 2017
Merged
13 tasks
@markcowl
Copy link
Member

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

@akinsriv
Copy link

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()
[Microsoft.IdentityModel.Clients.ActiveDirectory.TokenCache]::DefaultShared.Deserialize($cdata)

@vicp-iq vicp-iq mentioned this issue Oct 25, 2017
Closed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@markcowl markcowl

Labels
Azure PS Team
Projects
None yet
Milestone
August 2017
Development

No branches or pull requests
4 participants
@markcowl @cormacpayne @afengli @akinsriv