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.

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

"Login failed for user ***. Token is expired." when using Azure Active Directory password authentication #617

Closed
sk-pub opened this issue Jun 19, 2020 · 22 comments · Fixed by #635

Comments

@sk-pub
Copy link

sk-pub commented Jun 19, 2020

Describe the bug

We use Azure Active Directory password authentication and get the following exception 2-4 times per day:

Exception message:
Login failed for user '***@***.com'. Token is expired.
A severe error occurred on the current command.  The results, if any, should be discarded.

Stack trace may different. Here are two examples:
Stack trace #1
{"assembly":"Microsoft.Data.SqlClient, Version=2.0.20168.4, Culture=neutral, PublicKeyToken=23ec7fc2d6eaa4a5","method":"Microsoft.Data.SqlClient.SqlConnection.OnError","level":0,"line":0}
{"assembly":"Microsoft.Data.SqlClient, Version=2.0.20168.4, Culture=neutral, PublicKeyToken=23ec7fc2d6eaa4a5","method":"Microsoft.Data.SqlClient.TdsParser.ThrowExceptionAndWarning","level":1,"line":0}
{"assembly":"Microsoft.Data.SqlClient, Version=2.0.20168.4, Culture=neutral, PublicKeyToken=23ec7fc2d6eaa4a5","method":"Microsoft.Data.SqlClient.TdsParser.TryRun","level":2,"line":0}
{"assembly":"Microsoft.Data.SqlClient, Version=2.0.20168.4, Culture=neutral, PublicKeyToken=23ec7fc2d6eaa4a5","method":"Microsoft.Data.SqlClient.SqlDataReader.TryConsumeMetaData","level":3,"line":0}
{"assembly":"Microsoft.Data.SqlClient, Version=2.0.20168.4, Culture=neutral, PublicKeyToken=23ec7fc2d6eaa4a5","method":"Microsoft.Data.SqlClient.SqlDataReader.get_MetaData","level":4,"line":0}
{"assembly":"Microsoft.Data.SqlClient, Version=2.0.20168.4, Culture=neutral, PublicKeyToken=23ec7fc2d6eaa4a5","method":"Microsoft.Data.SqlClient.SqlCommand.FinishExecuteReader","level":5,"line":0}
{"assembly":"Microsoft.Data.SqlClient, Version=2.0.20168.4, Culture=neutral, PublicKeyToken=23ec7fc2d6eaa4a5","method":"Microsoft.Data.SqlClient.SqlCommand.RunExecuteReaderTds","level":6,"line":0}
{"assembly":"Microsoft.Data.SqlClient, Version=2.0.20168.4, Culture=neutral, PublicKeyToken=23ec7fc2d6eaa4a5","method":"Microsoft.Data.SqlClient.SqlCommand.RunExecuteReader","level":7,"line":0}
{"assembly":"Microsoft.Data.SqlClient, Version=2.0.20168.4, Culture=neutral, PublicKeyToken=23ec7fc2d6eaa4a5","method":"Microsoft.Data.SqlClient.SqlCommand.ExecuteReader","level":8,"line":0}
{"assembly":"Microsoft.EntityFrameworkCore.Relational, Version=3.1.5.0, Culture=neutral, PublicKeyToken=adb9793829ddae60","method":"Microsoft.EntityFrameworkCore.Storage.RelationalCommand.ExecuteReader","level":9,"line":0}
{"assembly":"Microsoft.EntityFrameworkCore.Relational, Version=3.1.5.0, Culture=neutral, PublicKeyToken=adb9793829ddae60","method":"Microsoft.EntityFrameworkCore.Query.Internal.QueryingEnumerable`1+Enumerator.InitializeReader","level":10,"line":0}
{"assembly":"Microsoft.EntityFrameworkCore.SqlServer, Version=3.1.5.0, Culture=neutral, PublicKeyToken=adb9793829ddae60","method":"Microsoft.EntityFrameworkCore.SqlServer.Storage.Internal.SqlServerExecutionStrategy.Execute","level":11,"line":0}
{"assembly":"Microsoft.EntityFrameworkCore.Relational, Version=3.1.5.0, Culture=neutral, PublicKeyToken=adb9793829ddae60","method":"Microsoft.EntityFrameworkCore.Query.Internal.QueryingEnumerable`1+Enumerator.MoveNext","level":12,"line":0}
{"assembly":"System.Linq, Version=4.2.2.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a","method":"System.Linq.Enumerable.Single","level":13,"line":0}
...

Stack trace #2 
{"assembly":"Microsoft.Data.SqlClient, Version=1.10.19324.4, Culture=neutral, PublicKeyToken=23ec7fc2d6eaa4a5","method":"Microsoft.Data.SqlClient.SqlCommand+<>c.<ExecuteDbDataReaderAsync>b__164_0","level":0,"line":0}
{"assembly":"System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e","method":"System.Threading.Tasks.ContinuationResultTaskFromResultTask`2.InnerInvoke","level":1,"line":0}
{"assembly":"System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e","method":"System.Threading.ExecutionContext.RunInternal","level":2,"line":0}
{"assembly":"System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e","method":"System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw","level":3,"line":0}
{"assembly":"System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e","method":"System.Threading.Tasks.Task.ExecuteWithThreadLocal","level":4,"line":0}
{"assembly":"System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e","method":"System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw","level":5,"line":0}
{"assembly":"System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e","method":"System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification","level":6,"line":0}
{"assembly":"Microsoft.EntityFrameworkCore.Relational, Version=3.1.3.0, Culture=neutral, PublicKeyToken=adb9793829ddae60","method":"Microsoft.EntityFrameworkCore.Storage.RelationalCommand+<ExecuteReaderAsync>d__17.MoveNext","level":7,"line":0}
{"assembly":"System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e","method":"System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw","level":8,"line":0}
{"assembly":"Microsoft.EntityFrameworkCore.Relational, Version=3.1.3.0, Culture=neutral, PublicKeyToken=adb9793829ddae60","method":"Microsoft.EntityFrameworkCore.Storage.RelationalCommand+<ExecuteReaderAsync>d__17.MoveNext","level":9,"line":0}
{"assembly":"System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e","method":"System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw","level":10,"line":0}
{"assembly":"Microsoft.EntityFrameworkCore.Relational, Version=3.1.3.0, Culture=neutral, PublicKeyToken=adb9793829ddae60","method":"Microsoft.EntityFrameworkCore.Storage.RelationalCommand+<ExecuteReaderAsync>d__17.MoveNext","level":11,"line":0}
{"assembly":"System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e","method":"System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw","level":12,"line":0}
{"assembly":"System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e","method":"System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification","level":13,"line":0}
{"assembly":"Microsoft.EntityFrameworkCore.Relational, Version=3.1.3.0, Culture=neutral, PublicKeyToken=adb9793829ddae60","method":"Microsoft.EntityFrameworkCore.Query.Internal.QueryingEnumerable`1+AsyncEnumerator+<InitializeReaderAsync>d__18.MoveNext","level":14,"line":0}
{"assembly":"System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e","method":"System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw","level":15,"line":0}
{"assembly":"System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e","method":"System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification","level":16,"line":0}
{"assembly":"Microsoft.EntityFrameworkCore.SqlServer, Version=3.1.3.0, Culture=neutral, PublicKeyToken=adb9793829ddae60","method":"Microsoft.EntityFrameworkCore.SqlServer.Storage.Internal.SqlServerExecutionStrategy+<ExecuteAsync>d__7`2.MoveNext","level":17,"line":0}
{"assembly":"System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e","method":"System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw","level":18,"line":0}
{"assembly":"System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e","method":"System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification","level":19,"line":0}
{"assembly":"Microsoft.EntityFrameworkCore.Relational, Version=3.1.3.0, Culture=neutral, PublicKeyToken=adb9793829ddae60","method":"Microsoft.EntityFrameworkCore.Query.Internal.QueryingEnumerable`1+AsyncEnumerator+<MoveNextAsync>d__17.MoveNext","level":20,"line":0}
{"assembly":"System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e","method":"System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw","level":21,"line":0}
{"assembly":"System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e","method":"System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification","level":22,"line":0}
{"assembly":"Microsoft.EntityFrameworkCore, Version=3.1.3.0, Culture=neutral, PublicKeyToken=adb9793829ddae60","method":"Microsoft.EntityFrameworkCore.Query.ShapedQueryCompilingExpressionVisitor+<SingleOrDefaultAsync>d__22`1.MoveNext","level":23,"line":0}
{"assembly":"System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e","method":"System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw","level":24,"line":0}
{"assembly":"Microsoft.EntityFrameworkCore, Version=3.1.3.0, Culture=neutral, PublicKeyToken=adb9793829ddae60","method":"Microsoft.EntityFrameworkCore.Query.ShapedQueryCompilingExpressionVisitor+<SingleOrDefaultAsync>d__22`1.MoveNext","level":25,"line":0}
{"assembly":"System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e","method":"System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw","level":26,"line":0}
{"assembly":"System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e","method":"System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification","level":27,"line":0}
...

To reproduce

Unfortunately, I cannot reproduce the issue. I just see the exception in our logs.
I will update the ticket if I manage to reproduce the bug.

Expected behavior

I don't know, how auth token expiration is handled inside Microsoft.Data.SqlClient. But I would expect that the token is refreshed prior to expiration. Or that the expiration exception is properly handled inside the library without throwing it outside.

Further technical details

Microsoft.Data.SqlClient version: 2.0.20168.4. The exception also happened when we used the version 1.10.19324.4.

.NET target: Core 3.1.5

SQL Server version: SQL Server 2014 (12.0.2000.8) on Azure.

Operating system: Docker container based on the image mcr.microsoft.com/dotnet/core/aspnet:3.1

@JRahnama
Copy link
Contributor

@unicrus can you please provide a brief sample of your code that we can setup your environment at our side please? We also have recently released version 2.0.0 of Microsoft.Data.SqlClient. Is it possible to upgrade to that version to see if any errors happen?

@sk-pub
Copy link
Author

sk-pub commented Jun 19, 2020

@JRahnama, we already use the version 2.0.0 of Microsoft.Data.SqlClient. The problem is still there.
I suspect, that the token may not be updated if the application stays idle for a while (no SQL queries are made). Currently, I'm trying a workaround — periodically sending SQL queries.

We use JsonApiDotNetCore on top of EF Core, so our environment is not the easiest to replicate. I will try to create a simple app to reproduce the issue.

@cheenamalhotra
Copy link
Member

Hi @unicrus

Could you explain more on how you connect to your server? Do you pass "AccessToken" connection property to SqlConnection class or use "Active Directory Password" authentication keyword in Connection String when connecting with SqlConnection?

@sk-pub
Copy link
Author

sk-pub commented Jun 19, 2020

Hi @cheenamalhotra,

As I mentioned above, we use Azure Active Directory password authentication. The connection string looks like this:
Data Source=<srv>.database.windows.net;Authentication=Active Directory Password;Initial Catalog=<db>;UID=<user>;PWD=<pass>

@sk-pub
Copy link
Author

sk-pub commented Jun 24, 2020

@JRahnama, @cheenamalhotra
I reproduced the issue with the following code:

using System;
using System.Threading;
using Microsoft.Data.SqlClient;

namespace ConnectionTest
{
    class Program
    {
        static void Main(string[] args)
        {
            SqlConnection connection = null;
            try
            {
                while (true)
                {
                    connection = new SqlConnection(@"Data Source=<srv>.database.windows.net;Authentication=Active Directory Password;Initial Catalog=<db>;UID=<user>;PWD=<pass>");
                    connection.Open();

                    using (var command = new SqlCommand(@"select count(*) from Organizations", connection))
                    {
                        using (var reader = command.ExecuteReader())
                        {
                            while (reader.Read())
                            {
                                var c = reader.GetInt32(0);
                                Console.WriteLine($"{DateTime.Now}  {c}");
                            }
                        }
                    }

                    connection.Close();
                    connection.Dispose();

                    Thread.Sleep(60 * 1000);
                }
            } catch (Exception e)
            {
                Console.WriteLine(e.ToString());
                Console.ReadKey();
            }
            finally
            {
                if (connection != null)
                {
                    connection.Dispose();
                }
            }
        }
    }
}

The exception occurred after exactly 10 hours of the app running.

Microsoft.Data.SqlClient version: the latest code from this git repo
.NET target: Core 3.1.5
SQL Server version: SQL Server 2014 (12.0.2000.8) on Azure.
Operating system: Windows 10

Stack trace:

   at Microsoft.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection, Action`1 wrapCloseInAction) in ...\SqlClient\src\Microsoft.Data.SqlClient\netcore\src\Microsoft\Data\SqlClient\SqlConnection.cs:line 1780
   at Microsoft.Data.SqlClient.SqlInternalConnection.OnError(SqlException exception, Boolean breakConnection, Action`1 wrapCloseInAction) in ...\SqlClient\src\Microsoft.Data.SqlClient\netcore\src\Microsoft\Data\SqlClient\SqlInternalConnection.cs:line 606
   at Microsoft.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(TdsParserStateObject stateObj, Boolean callerHasConnectionLock, Boolean asyncClose) in ...\SqlClient\src\Microsoft.Data.SqlClient\netcore\src\Microsoft\Data\SqlClient\TdsParser.cs:line 1302
   at Microsoft.Data.SqlClient.TdsParser.TryRun(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj, Boolean& dataReady) in ...\SqlClient\src\Microsoft.Data.SqlClient\netcore\src\Microsoft\Data\SqlClient\TdsParser.cs:line 2523
   at Microsoft.Data.SqlClient.SqlDataReader.TryConsumeMetaData() in ...\SqlClient\src\Microsoft.Data.SqlClient\netcore\src\Microsoft\Data\SqlClient\SqlDataReader.cs:line 1139
   at Microsoft.Data.SqlClient.SqlDataReader.get_MetaData() in ...\SqlClient\src\Microsoft.Data.SqlClient\netcore\src\Microsoft\Data\SqlClient\SqlDataReader.cs:line 265
   at Microsoft.Data.SqlClient.SqlCommand.FinishExecuteReader(SqlDataReader ds, RunBehavior runBehavior, String resetOptionsString, Boolean isInternal, Boolean forDescribeParameterEncryption, Boolean shouldCacheForAlwaysEncrypted) in ...\SqlClient\src\Microsoft.Data.SqlClient\netcore\src\Microsoft\Data\SqlClient\SqlCommand.cs:line 4681
   at Microsoft.Data.SqlClient.SqlCommand.RunExecuteReaderTds(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, Boolean isAsync, Int32 timeout, Task& task, Boolean asyncWrite, Boolean inRetry, SqlDataReader ds, Boolean describeParameterEncryptionRequest) in ...\SqlClient\src\Microsoft.Data.SqlClient\netcore\src\Microsoft\Data\SqlClient\SqlCommand.cs:line 4497
   at Microsoft.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, TaskCompletionSource`1 completion, Int32 timeout, Task& task, Boolean& usedCache, Boolean asyncWrite, Boolean inRetry, String method) in ...\SqlClient\src\Microsoft.Data.SqlClient\netcore\src\Microsoft\Data\SqlClient\SqlCommand.cs:line 4180
   at Microsoft.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method) in ...\SqlClient\src\Microsoft.Data.SqlClient\netcore\src\Microsoft\Data\SqlClient\SqlCommand.cs:line 4052
   at Microsoft.Data.SqlClient.SqlCommand.ExecuteReader(CommandBehavior behavior) in ...\SqlClient\src\Microsoft.Data.SqlClient\netcore\src\Microsoft\Data\SqlClient\SqlCommand.cs:line 1856
   at Microsoft.Data.SqlClient.SqlCommand.ExecuteReader() in ...\SqlClient\src\Microsoft.Data.SqlClient\netcore\src\Microsoft\Data\SqlClient\SqlCommand.cs:line 1831
   at ConnectionTest.Program.Main(String[] args) in ...\SqlClient\ConnectionTest\Program.cs:line 21

@cheenamalhotra
Copy link
Member

Thank you for reproducing this @unicrus

10 hours is a little unexpected duration.. Since these AD federated auth tokens expire in 1 hour and driver requests a new one when applicable.

I'll investigate and let you know!

@cheenamalhotra
Copy link
Member

cheenamalhotra commented Jun 25, 2020

Hi @unicrus

I'm able to reproduce this issue and to mention this happens from Server side, as no token is generated from client/re-used as there's no login being done when this error occurs. The state of the connection is "Active" and processing results where the server exactly after 10 hours fails with exception:

Login failed for user '_____@______'. Token is expired.
A severe error occurred on the current command.  The results, if any, should be discarded.
Error Number:18456,State:91,Class:14

This State 91 for Error 18456 is also not documented on Microsoft Documentation and seems like this behavior is newly introduced. We're following up with Azure teams for more details and will let you know soon.

@sk-pub
Copy link
Author

sk-pub commented Jul 1, 2020

Hi @cheenamalhotra,

Is there any update reg. the issue?

@cheenamalhotra
Copy link
Member

Hi @unicrus

We confirmed the issue occurs due to Azure SQL DB revalidating access token on an active physical connection after 10 hours. The driver's current behavior seems flawed and we'll have to ensure pooled connection is not re-used that contains an expired access token. PR #635 fixes this issue, feel free to give it a try!

@sk-pub
Copy link
Author

sk-pub commented Jul 9, 2020

HI @cheenamalhotra,

I've checked the pull request — it fixed the error. But after 1.5 days of running the test app, I got the following exception. I'm not sure if it's related to the change or not. Will run the app again to check.

Microsoft.Data.SqlClient.SqlException (0x80131904): A transport-level error has occurred when receiving results from the server. (provider: TCP Provider, error: 0 - The semaphore timeout period has expired.)
 ---> System.ComponentModel.Win32Exception (121): The semaphore timeout period has expired.
   at Microsoft.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection, Action`1 wrapCloseInAction) in ...\src\Microsoft.Data.SqlClient\netcore\src\Microsoft\Data\SqlClient\SqlConnection.cs:line 1780
   at Microsoft.Data.SqlClient.SqlInternalConnection.OnError(SqlException exception, Boolean breakConnection, Action`1 wrapCloseInAction) in ...\src\Microsoft.Data.SqlClient\netcore\src\Microsoft\Data\SqlClient\SqlInternalConnection.cs:line 606
   at Microsoft.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(TdsParserStateObject stateObj, Boolean callerHasConnectionLock, Boolean asyncClose) in ...\src\Microsoft.Data.SqlClient\netcore\src\Microsoft\Data\SqlClient\TdsParser.cs:line 1302
   at Microsoft.Data.SqlClient.TdsParserStateObject.ThrowExceptionAndWarning(Boolean callerHasConnectionLock, Boolean asyncClose) in ...\src\Microsoft.Data.SqlClient\netcore\src\Microsoft\Data\SqlClient\TdsParserStateObject.cs:line 959
   at Microsoft.Data.SqlClient.TdsParserStateObject.ReadSniError(TdsParserStateObject stateObj, UInt32 error) in ...\src\Microsoft.Data.SqlClient\netcore\src\Microsoft\Data\SqlClient\TdsParserStateObject.cs:line 2673
   at Microsoft.Data.SqlClient.TdsParserStateObject.ReadSniSyncOverAsync() in ...\src\Microsoft.Data.SqlClient\netcore\src\Microsoft\Data\SqlClient\TdsParserStateObject.cs:line 2219
   at Microsoft.Data.SqlClient.TdsParserStateObject.TryReadNetworkPacket() in ...\src\Microsoft.Data.SqlClient\netcore\src\Microsoft\Data\SqlClient\TdsParserStateObject.cs:line 2144
   at Microsoft.Data.SqlClient.TdsParserStateObject.TryPrepareBuffer() in ...\src\Microsoft.Data.SqlClient\netcore\src\Microsoft\Data\SqlClient\TdsParserStateObject.cs:line 1104
   at Microsoft.Data.SqlClient.TdsParserStateObject.TryReadByte(Byte& value) in ...\src\Microsoft.Data.SqlClient\netcore\src\Microsoft\Data\SqlClient\TdsParserStateObject.cs:line 1378
   at Microsoft.Data.SqlClient.TdsParser.TryRun(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj, Boolean& dataReady) in ...\src\Microsoft.Data.SqlClient\netcore\src\Microsoft\Data\SqlClient\TdsParser.cs:line 1920
   at Microsoft.Data.SqlClient.SqlDataReader.TryConsumeMetaData() in ...\src\Microsoft.Data.SqlClient\netcore\src\Microsoft\Data\SqlClient\SqlDataReader.cs:line 1139
   at Microsoft.Data.SqlClient.SqlDataReader.get_MetaData() in ...\src\Microsoft.Data.SqlClient\netcore\src\Microsoft\Data\SqlClient\SqlDataReader.cs:line 265
   at Microsoft.Data.SqlClient.SqlCommand.FinishExecuteReader(SqlDataReader ds, RunBehavior runBehavior, String resetOptionsString, Boolean isInternal, Boolean forDescribeParameterEncryption, Boolean shouldCacheForAlwaysEncrypted) in ...\src\Microsoft.Data.SqlClient\netcore\src\Microsoft\Data\SqlClient\SqlCommand.cs:line 4681
   at Microsoft.Data.SqlClient.SqlCommand.RunExecuteReaderTds(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, Boolean isAsync, Int32 timeout, Task& task, Boolean asyncWrite, Boolean inRetry, SqlDataReader ds, Boolean describeParameterEncryptionRequest) in ...\src\Microsoft.Data.SqlClient\netcore\src\Microsoft\Data\SqlClient\SqlCommand.cs:line 4497
   at Microsoft.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, TaskCompletionSource`1 completion, Int32 timeout, Task& task, Boolean& usedCache, Boolean asyncWrite, Boolean inRetry, String method) in ...\src\Microsoft.Data.SqlClient\netcore\src\Microsoft\Data\SqlClient\SqlCommand.cs:line 4180
   at Microsoft.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method) in ...\src\Microsoft.Data.SqlClient\netcore\src\Microsoft\Data\SqlClient\SqlCommand.cs:line 4052
   at Microsoft.Data.SqlClient.SqlCommand.ExecuteReader(CommandBehavior behavior) in ...\src\Microsoft.Data.SqlClient\netcore\src\Microsoft\Data\SqlClient\SqlCommand.cs:line 1856
   at Microsoft.Data.SqlClient.SqlCommand.ExecuteReader() in ...\src\Microsoft.Data.SqlClient\netcore\src\Microsoft\Data\SqlClient\SqlCommand.cs:line 1831
   at ConnectionTest.Program.Main(String[] args) in ...\ConnectionTest\Program.cs:line 22

@cheenamalhotra
Copy link
Member

I've let my test app run for ~5 days without error, so I don't think it's related to this issue.

@sk-pub
Copy link
Author

sk-pub commented Aug 17, 2020

Hi @cheenamalhotra, is there an estimated date for the v2.1.0 release with the fix?
From https://github.com/dotnet/SqlClient/projects/6 it seems, that it may take months. It would be sad if the fix stays unreleased for a long time.

@ErikEJ
Copy link
Contributor

ErikEJ commented Aug 17, 2020

@sk-pub
Copy link
Author

sk-pub commented Aug 17, 2020

@ErikEJ , it cannot be the current plan — it's release notes for 2.0 preview 4, while there is 2.0 release already.

@ErikEJ
Copy link
Contributor

ErikEJ commented Aug 17, 2020

Did you read the blog post? "Our plan is to provide GA releases twice a year with two preview releases in between. This cadence should provide time for feedback and allow us to deliver features and fixes in a timely manner."

@cheenamalhotra
Copy link
Member

Hi @unicrus

This fix has also been backported to v2.0 (#639) which means v2.0.1 (planned to release soon) will also contain this fix. Also v2.1.0-preview1 shall contain this fix, planned for this month.

@CodeSwimBikeRunner
Copy link

CodeSwimBikeRunner commented Oct 13, 2020

I am having the same issue. About a half day, I'm getting the same error. It is running on this docker container
mcr.microsoft.com/dotnet/core/runtime:3.1.2-alpine
I have upgraded to this version of SqlClient <PackageReference Include="System.Data.SqlClient" Version="4.8.2" />
@cheenamalhotra is there anything I can do to get the fix mentioned?

@sk-pub
Copy link
Author

sk-pub commented Oct 14, 2020

@CodeSwimBikeRunner, the fix is in Microsoft.Data.SqlClient. Not System.Data.SqlClient.

@andycoderapptio
Copy link

Any suggested fixes or work arounds for people on EF 6? aka using System.Data.SqlClient. vs Microsoft.Data.SqlClient?

@myopicmage
Copy link

@andycoderapptio we've had some preliminary success by extending the SqlAzureExecutionStrategy to retry when encountering this error

    public class CustomExecutionStrategy : SqlAzureExecutionStrategy
    {
        protected override bool ShouldRetryOn(Exception ex)
        {
            if (ex is SqlException sqlex)
            {
                foreach (SqlError err in sqlex.Errors)
                {
                    // Error number found here https://github.com/dotnet/SqlClient/issues/617#issuecomment-649686544
                    if (err.Number == 18456)
                    {
                        return true;
                    }
                }
            }

            return base.ShouldRetryOn(ex);
        }
    }

@cheenamalhotra
Copy link
Member

cheenamalhotra commented Jan 30, 2021

Hi @CodeSwimBikeRunner @andycoderapptio

For System.Data.SqlClient, the best recommendation we can provide for this issue is, to fetch and provide access token from your application and ensuring it's always fetched and is "Active" when connection is acquired.

You can do something as under as a quick solution. Azure.Identity is the recommended library to fetch tokens from, and it also provides caching capabilities if needed. Eventually you should consider moving to Microsoft.Data.SqlClient, and we are also moving to Azure.Identity soon from MSAL to acquire access tokens, also ensuring that they're always "Active" when reactivating pooled connections.

    var connString = new SqlConnectionStringBuilder()
    {
        DataSource = "{server}.database.windows.net",
        InitialCatalog = "{db}"
    }.ConnectionString;

    var scopes = new string[] { "https://database.windows.net/.default" };
    
    // Token Lifetime = 24 hours
    var accessToken = new Azure.Identity.ManagedIdentityCredential()
        .GetToken(new Azure.Core.TokenRequestContext(scopes)).Token;

    using (SqlConnection connection = new SqlConnection(connString))
    {
        connection.AccessToken = accessToken;
        connection.Open();
        Console.WriteLine("Connected!");
    }

Or alternatively, if you still use Credential based login:

    var connString = new SqlConnectionStringBuilder()
    {
        DataSource = "{server}.database.windows.net",
        InitialCatalog = "{db}"
    }.ConnectionString;

    var username = "{user}";
    var password = "{pass}";
    var tenantId = "{tenantId}";
    var clientId = "{clientId}";
    var scopes = new string[] { "https://database.windows.net/.default" };

    // Token Lifetime = 1 hour
    var accessToken = new Azure.Identity.UsernamePasswordCredential(username, password, tenantId, clientId)
        .GetToken(new Azure.Core.TokenRequestContext(scopes)).Token;

    using (SqlConnection connection = new SqlConnection(connString))
    {
        connection.AccessToken = accessToken;
        connection.Open();
        Console.WriteLine("Connected!");
    }

@sw-tt-pankajkathiriya
Copy link

at Microsoft.Data.SqlClient.TdsParser.SendFedAuthToken(SqlFedAuthToken fedAuthToken)
at Microsoft.Data.SqlClient.SqlInternalConnectionTds.OnFedAuthInfo(SqlFedAuthInfo fedAuthInfo)
at Microsoft.Data.SqlClient.TdsParser.TryRun(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj, Boolean& dataReady)
at Microsoft.Data.SqlClient.TdsParser.Run(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj)
at Microsoft.Data.SqlClient.SqlInternalConnectionTds.CompleteLogin(Boolean enlistOK)
at Microsoft.Data.SqlClient.SqlInternalConnectionTds.AttemptOneLogin(ServerInfo serverInfo, String newPassword, SecureString newSecurePassword, Boolean ignoreSniOpenTimeout, TimeoutTimer timeout, Boolean withFailover)
at Microsoft.Data.SqlClient.SqlInternalConnectionTds.LoginNoFailover(ServerInfo serverInfo, String newPassword, SecureString newSecurePassword, Boolean redirectedUserInstance, SqlConnectionString connectionOptions, SqlCredential credential, TimeoutTimer timeout)
at Microsoft.Data.SqlClient.SqlInternalConnectionTds.OpenLoginEnlist(TimeoutTimer timeout, SqlConnectionString connectionOptions, SqlCredential credential, String newPassword, SecureString newSecurePassword, Boolean redirectedUserInstance)
at Microsoft.Data.SqlClient.SqlInternalConnectionTds..ctor(DbConnectionPoolIdentity identity, SqlConnectionString connectionOptions, SqlCredential credential, Object providerInfo, String newPassword, SecureString newSecurePassword, Boolean redirectedUserInstance, SqlConnectionString userConnectionOptions, SessionData reconnectSessionData, Boolean applyTransientFaultHandling, String accessToken, DbConnectionPool pool)
at Microsoft.Data.SqlClient.SqlConnectionFactory.CreateConnection(DbConnectionOptions options, DbConnectionPoolKey poolKey, Object poolGroupProviderInfo, DbConnectionPool pool, DbConnection owningConnection, DbConnectionOptions userOptions)
at Microsoft.Data.ProviderBase.DbConnectionFactory.CreatePooledConnection(DbConnectionPool pool, DbConnection owningObject, DbConnectionOptions options, DbConnectionPoolKey poolKey, DbConnectionOptions userOptions)
at Microsoft.Data.ProviderBase.DbConnectionPool.CreateObject(DbConnection owningObject, DbConnectionOptions userOptions, DbConnectionInternal oldConnection)
at Microsoft.Data.ProviderBase.DbConnectionPool.UserCreateRequest(DbConnection owningObject, DbConnectionOptions userOptions, DbConnectionInternal oldConnection)
at Microsoft.Data.ProviderBase.DbConnectionPool.TryGetConnection(DbConnection owningObject, UInt32 waitForMultipleObjectsTimeout, Boolean allowCreate, Boolean onlyOneCheckConnection, DbConnectionOptions userOptions, DbConnectionInternal& connection)
at Microsoft.Data.ProviderBase.DbConnectionPool.TryGetConnection(DbConnection owningObject, TaskCompletionSource1 retry, DbConnectionOptions userOptions, DbConnectionInternal& connection) at Microsoft.Data.ProviderBase.DbConnectionFactory.TryGetConnection(DbConnection owningConnection, TaskCompletionSource1 retry, DbConnectionOptions userOptions, DbConnectionInternal oldConnection, DbConnectionInternal& connection)
at Microsoft.Data.ProviderBase.DbConnectionInternal.TryOpenConnectionInternal(DbConnection outerConnection, DbConnectionFactory connectionFactory, TaskCompletionSource1 retry, DbConnectionOptions userOptions) at Microsoft.Data.ProviderBase.DbConnectionClosed.TryOpenConnection(DbConnection outerConnection, DbConnectionFactory connectionFactory, TaskCompletionSource1 retry, DbConnectionOptions userOptions)
at Microsoft.Data.SqlClient.SqlConnection.TryOpen(TaskCompletionSource`1 retry, SqlConnectionOverrides overrides)
at Microsoft.Data.SqlClient.SqlConnection.Open(SqlConnectionOverrides overrides)
at Microsoft.Data.SqlClient.SqlConnection.Open()
at TestAzureapp.Handler.TestHandler.Handle(TestRequest request, CancellationToken cancellationToken) in D:\IOTConnect\7825_Test_App\TestAzureapp\TestAzureapp\Handler\TestHandler.cs:line 30

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging a pull request may close this issue.

8 participants