Azure-sdk-for-net: [BUG] AzureServiceTokenProvider.GetAccessTokenAsync no longer works with Visual Studio 16.3

[Liversage]

Describe the bug

I work on a project that uses Azure Managed Identities. AzureServiceTokenProvider.GetAccessTokenAsync() is used to get a token, and to debug locally a token provided by Visual Studio is used. After upgrading to Visual Studio 16.3 this no longer works. I have verified this to be the case on two different computers after upgrading to Visual Studio 16.3.

I don't know if this is a problem with Visual Studio or the NuGet package but the exception is thrown by the NuGet package so I'm reporting it here.

Exception or Stack Trace

Parameters: Connection String: RunAs=Developer; DeveloperTool=VisualStudio, Resource: https://management.azure.com, Authority: . Exception Message: Tried to get token using Visual Studio. Access token could not be acquired.
Exception for Visual Studio token provider Microsoft.Asal.TokenService.exe : Token response is not in the expected format. Exception Message: There was an error deserializing the object of type Microsoft.Azure.Services.AppAuthentication.TokenResponse. Encountered unexpected character 'D'.

   at Microsoft.Azure.Services.AppAuthentication.AzureServiceTokenProvider.d__14.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 System.Runtime.CompilerServices.ConfiguredTaskAwaitable`1.ConfiguredTaskAwaiter.GetResult()
   at Microsoft.Azure.Services.AppAuthentication.AzureServiceTokenProvider.d__18.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 System.Runtime.CompilerServices.ConfiguredTaskAwaitable`1.ConfiguredTaskAwaiter.GetResult()
   at Microsoft.Azure.Services.AppAuthentication.AzureServiceTokenProvider.d__16.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 System.Runtime.CompilerServices.TaskAwaiter`1.GetResult()
   at UserQuery.d__0.MoveNext()

To Reproduce

Use Visual Studio 16.3 and configure an Azure account in _Tools_ > _Options_ > _Azure Service Authentication_ > _Account Selection_.

Create a new instance of AzureServiceTokenProvider with connection string "RunAs=Developer; DeveloperTool=VisualStudio" and then call GetAccessTokenAsync("https://management.azure.com") to get a token.

Code Snippet

C# var connectionString = "RunAs=Developer; DeveloperTool=VisualStudio"; var azureServiceTokenProvider = new AzureServiceTokenProvider(connectionString); var token = await azureServiceTokenProvider.GetAccessTokenAsync("https://management.azure.com");

Expected behavior

GetAccessTokenAsync should return a token that can be used to authenticate with Azure based on the configured account in Visual Studio and not throw an exception.

Screenshots

Setup (please complete the following information):

• OS: Windows 10 Pro 1903 18362.356
• IDE: Visual Studio 16.3.0
• Version of the Library used: Microsoft.Azure.Services.AppAuthentication 1.3.1

Additional context

None.

Information Checklist

Kindly make sure that you have added all the following information above and checkoff the required fields otherwise we will treat the issuer as an incomplete report

• [x] Bug Description Added
• [X] Repro Steps Added
• [X] Setup information Added

[loarabia]

Hi @Liversage I've tried reproducing just now using a Functions app built with Visual Studio 2019 16.3.1. I was also using Microsoft.Azure.Services.AppAuthentication 1.3.1. I wasn't successful at recreating the issue. Given that the component that is raising the exception is ASAL, I have asked the visual studio team if there were any known issues or there are any logs that might help us dig deeper. I assume you're using 16.3.1?

[Liversage]

Hi @loarabia, thanks for looking into this issue.

I was using 16.3.0 when I reported the issue. That was the version that was offered to me when I used the Visual Studio Installer to upgrade Visual Studio (I was using 16.2 before the upgrade). I reported the issue shortly after upgrading my second computer because I became certain that this problem was not isolated to a single computer.

However, since 16.3.1 is the latest version I have upgraded to this version on one of my computers to further investigate:

| Test | Result |
| - | - |
| Snippet in LINQPad (AnyCPU edition using full framework) | Exception is thrown |
| My application (.NET Core App 2.2) | Exception is thrown |
| Switching configured account in Visual Studio | Exception is thrown |
| Having a single account configured in Visual Studio (I normally have two) | Exception is thrown |
| Snippet in .NET Core App 3.0 console app | Exception is not thrown |
| Snippet in .NET Core App 2.2 console app | Exception is not thrown |
| Snippet in full framework console app | Exception is not thrown |

Summing up:

• I'm unable to reproduce the issue except in my own project and in LINQPad.
• I can resolve the issue I'm having with my own project and LINQPad by downgrading from Visual Studio 16.3 to 16.2.
• I have the issue on two different computers.

So I'm pretty sure the issue is real but since I'm having problems reproducing it myself I can see that it's hard to investigate. Would you be able to test my snippet in LINQPad?

[MarcWils]

I had the same error. I opened up VS2017 and re-entered my credentials there. After that, it works.

[Liversage]

Thanks to open source I was able to troubleshoot this issue further.

The Visual Studio access token is acquired by executing Microsoft.Asal.TokenService.exe. This is the command line on my computer:

"c:\program files (x86)\microsoft visual studio\2019\enterprise\common7\ide\extensions\qglq5p5b.btx\TokenService\Microsoft.Asal.TokenService.exe" --resource https://management.azure.com --serviceHubConfig "C:\Program Files (x86)\Microsoft Visual Studio\2019\Enterprise\Common7\servicehub.config.json"

Executing this in the console prints the JSON containing the Azure token as expected. However, in some cases, when using the NuGet package, the `Microsoft.Asal.TokenService.exe` process writes the following to standard output:

Devhub Core CLR service module host. Copyright (c) Microsoft Corp
  Host id: desktopClr.x86$IdentityHost
  Controller pipe: net.pipe://C7EB239D4C5E775A2743A1938D70EA14
Running host until the hub controller sends 'exit' command...
{"access_token":"...",."expires_on":...}

The token is still in the output but for some reason there are four lines of text before. The first character of this text is D which explains the exception message:

There was an error deserializing the object of type Microsoft.Azure.Services.AppAuthentication.TokenResponse. Encountered unexpected character 'D'.

I don't know why the output of Microsoft.Asal.TokenService.exe sometimes contains extra text but it explains my issue.

[loarabia]

@Liversage awesome that actually makes this much easier to dive into. Let me see if I can get someone on the ASAL side of things to weigh in next week.

[crmann1]

@Liversage, I have been able to reproduce the error in linqPad using the snippet, I was also not able to reproduce the issue using .net core applications either launching the process directly or using the app.authentication nuget package.

However, I did find that older versions of the token service for example one from vs2017 work fine even in linqpad.

What I think is happening is that linqPad is doing some sort of redirection of the standard out handles in a way which is causing the tokenservice.exe and one of the child exe process it launches to now share the standard out steam. This is then read by the app.authentication library and it fails because it sees output in the standard out stream.

You mentioned that your application also fails, does that application to any redirection of standard our or standard error?

[MarcWils]

We use Service Fabric which uses output redirection.

[Liversage]

To follow up on the comments about console redirection and Service Fabric:

My system consists of multiple .NET Core App 2.2 console apps. When deployed they do execute in Service Fabric. However, this issue is about local testing and in that case my apps are configured to just execute as normal console apps without any redirection of standard out or error. I don't believe this execution path will ever call Service Fabric code but the DLLs are still present in the bin folder so this might be what triggers the problem. (I'm actually having a bit of a problem running my system in the local test cluster because it executes using a Windows service account which does not have access to my Azure credentials.)

It's my understanding that different versions of Visual Studio will each supply their own version of Microsoft.Asal.TokenService.exe linked to the Azure account selection option in that specific version of Visual Studio. The availability of a token service is recorded in %LOCALAPPDATA%\.IdentityService\AzureServiceAuth\tokenprovider.json where each version has a priority. The NuGet package will enumerate and try each version until it gets a token. My belief is that when using Visual Studio 2017 to set the Azure account it becomes the one with the highest priority which fixes the problem. Unfortunately, I don't think it's possible to install 16.2 together with 16.3. Otherwise using 16.2 for the Azure account selection would allow me to use 16.3 for daily work. (I'm not going to install 2017 to fix this issue.)

[crmann1]

We have been able to reproduce the issue in both LINQPad and on the commandline directly by redirecting std out to a file and seeing the extra text be printed to std out. We believe this issue is caused by how the identity modules are inheriting the handles during process launch. An internal bug has been created to address this issue. I do not know of any work arounds at the moment, other than the one you suggested about installing a different version of visual studio. We are currently looking at how to address this issue.

[Liversage]

I just installed Visual Studio 2019 16.4.0 and as far as I can tell this problem has been fixed.

[vlardn]

For me, the problem appeared after upgrading to Visual Studio 2019 16.4.0 from the previous version. I've found that this was caused by invalid TokenProvider path, so I was forced to change content of "%LOCALAPPDATA%.IdentityServiceAzureServiceAuthtokenprovider.json" file:

{ "TokenProviders": [ { "Path": "c:\\program files (x86)\\microsoft visual studio\\2019\\enterprise\\common7\\ide\\extensions\\1rzmhu0l.2xx\\TokenService\\Microsoft.Asal.TokenService.exe", "Arguments": [ "--serviceHubConfig", "\"C:\\Program Files (x86)\\Microsoft Visual Studio\\2019\\Enterprise\\Common7\\servicehub.config.json\"" ], "Preference": 0 }, { "Path": "c:\\program files (x86)\\microsoft visual studio\\2019\\enterprise\\common7\\ide\\extensions\\qglq5p5b.btx\\TokenService\\Microsoft.Asal.TokenService.exe", "Arguments": [ "--serviceHubConfig", "\"C:\\Program Files (x86)\\Microsoft Visual Studio\\2019\\Enterprise\\Common7\\servicehub.config.json\"" ], "Preference": 1 }, { "Path": "c:\\program files (x86)\\microsoft visual studio\\2019\\enterprise\\common7\\ide\\extensions\\4rin0bzc.yf5\\TokenService\\Microsoft.Asal.TokenService.exe", "Arguments": [ "--serviceHubConfig", "\"C:\\Program Files (x86)\\Microsoft Visual Studio\\2019\\Enterprise\\Common7\\servicehub.config.json\"" ], "Preference": 2 } ] }

to only one valid entry (note a new extensions folder - "...extensionsys2aolp3.2rs"):

{ "TokenProviders": [ { "Path": "c:\\program files (x86)\\microsoft visual studio\\2019\\enterprise\\common7\\ide\\extensions\\ys2aolp3.2rs\\TokenService\\Microsoft.Asal.TokenService.exe", "Arguments": [ "--serviceHubConfig", "\"C:\\Program Files (x86)\\Microsoft Visual Studio\\2019\\Enterprise\\Common7\\servicehub.config.json\"" ], "Preference": 0 } ] }

and then everything started to work again!

[Liversage]

@vlardn The "good" (version 16.4) extension is in folder ys2aolp3.2rs. The "bad" (version 16.3) was in folder qglq5p5b.btx. Apparently, your service hub configuration was incorrect after the upgrade and your information is useful in case others have the same problem (and really is a new issue in itself). However, I still believe that Visual Studio 16.4 fixes the token provider problem that was introduced with Visual Studio 16.3.

I think I will leave it to the maintainers of this repository to close this issue, though.

[aidapsibr]

I'm now seeing this with both Visual Studio 16.4.5 and az cli.

I've tried using both Microsoft.Azure.Services.AppAuthentication v1.0.3 (transitive from Microsoft.Extensions.Configuration.AzureKeyVault) and v1.2.1 explicitly.

Error message using both Visual Studio Services and az cli with same issue:

parameters: Connection String: [No connection string specified], Resource: https://vault.azure.net, Authority: https://login.windows.net/{tenantId}. Exception Message: Tried the following 4 methods to get an access token, but none of them worked.
Parameters: Connection String: [No connection string specified], Resource: https://vault.azure.net, Authority: https://login.windows.net/{tenantId}. Exception Message: Tried to get token using Managed Service Identity. Unable to connect to the Managed Service Identity (MSI) endpoint. Please check that you are running on an Azure resource that has MSI setup.
Parameters: Connection String: [No connection string specified], Resource: https://vault.azure.net, Authority: https://login.windows.net/{tenantId}. Exception Message: Tried to get token using Visual Studio. Access token could not be acquired. 
Exception for Visual Studio token provider Microsoft.Asal.TokenService.exe : Token response is not in the expected format. Exception Message: There was an error deserializing the object of type Microsoft.Azure.Services.AppAuthentication.TokenResponse. Encountered unexpected character 'â'. 
Parameters: Connection String: [No connection string specified], Resource: https://vault.azure.net, Authority: https://login.windows.net/{tenantId}. Exception Message: Tried to get token using Azure CLI. Access token could not be acquired. Token response is not in the expected format. Exception Message: There was an error deserializing the object of type Microsoft.Azure.Services.AppAuthentication.TokenResponse. Encountered unexpected character 'à'.
Parameters: Connection String: [No connection string specified], Resource: https://vault.azure.net, Authority: https://login.windows.net/{tenantId}. Exception Message: Tried to get token using Active Directory Integrated Authentication. Access token could not be acquired. password_required_for_managed_user: Password is required for managed user

I'm also getting this when I set my Visual Studio Services authentication to a different account:

[vlardn]

Again the same issue when upgrading from VS 2019 16.5.5 to 16.6.0 :(
And again I need to manually fix the new extension folder name in tokenprovider.json.
Microsoft guys! When you will fix this annoying issue occurring every second VS update??

[vlardn]

Again the same issue after updating to latest VS 2019 16.6.2 :-(

[jsquire]

@AlexGhiondea: Would you be so kind as to help route to the right individual?

[crmann1]

What is likely happening is that the tokenprovider.json file is not being correctly updated after an upgrade. The file is updated when you go to Tools->options->Azure Services Authentication and click OK. Or load a project which has a dependency on the App.Authentication nuget package. This is supposed to run a target which causes the json file to be uploaded.

This was done because we only wanted to update the file if the feature was being used. However, it seems that this target is not always running which leaves the file out of date and as for the tools options route that would normally be done once and it not obvious that you need to go back there and click it again (and you should not really have to either).

Because of this we are changing how we write this file such that it is always updated without having to go to the dialog and click ok or have a certain dependency in the project.

[markcowl]

@crmann1 Is there a bug / issue we can link to for the new behavior in updating tokenprovider.json?

[anaismiller]

@crmann1 Has this been fixed in recent VS updates?