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

ExecuteReaderAsync hangs when Column Encryption is enabled and the worker usage of Azure DB is 100% #1762

Open
TungKJ opened this issue Sep 15, 2022 · 4 comments

Comments

@TungKJ
Copy link

TungKJ commented Sep 15, 2022

Describe the bug

SqlCommand ExecuteReaderAsync hangs when Column Encryption is enabled and the worker usage of Azure DB is 100%
In the EventSource trace, there is an SqlError, but the app doesn't doesn't receive the exception.
The error message in the trace is "SqlError.ctor | ERR | Info Number 10928, Error State 1, Error Class 20, Error Message 'Resource ID : 1. The request limit for the database is 60 and has been reached. See 'https://docs.microsoft.com/azure/azure-sql/database/resource-limits-logical-server' for assistance.', Procedure '', Line Number 1"

If using ExecuteReader instead of ExecuteReaderAsync, Column Encryption disabled, or the stored procedure without any parameters, the app works fine.

To reproduce

  1. Create a Azure DB S0
  2. Execute below sql to create a store procedure with a parameter in which WAITFOR is executed
  3. Run ConsoleAppCore in the attached file to call the store procedure constantly
  4. Run ConsoleAppCore2 to occupy all the workers of Azure DB
  5. ConsoleAppCore hangs in 2 minutes

stored procedure

ALTER PROC [dbo].[GetBlogs] (@__para_0 datetime2(7))  
AS  
BEGIN  
WAITFOR DELAY '00:00:02'
END  

test code: TestProject.zip

EventSource trace

ThreadID="8,808" ProcessorNumber="0" message="<prov.DbConnectionHelper.ConnectionString_Set|API> 36, 'Server=tcp:jsqasg.database.windows.net,1433;Database=TestModel;Encrypt=True;TrustServerCertificate=False;Connection Timeout=120;MultipleActiveResultSets=True;User ID=JSQALottery;Max Pool Size=100;Column Encryption Setting=enabled'" 
ThreadID="8,808" ProcessorNumber="0" message="<sc.SqlConfigurableRetryLogicManager.ConnectionProvider|INFO> Requested the ConnectionProvider value." 
ThreadID="8,808" ProcessorNumber="0" message="SqlCommand.Set_CommandText | API | Object Id 36, String Value = 'GetBlogs', Client Connection Id null" 
ThreadID="8,808" ProcessorNumber="0" message="SqlCommand.Set_Connection | API | ObjectId 36, Client Connection Id ec0b9261-8ea2-4324-ab16-ff356f224421" 
ThreadID="8,808" ProcessorNumber="0" message="SqlCommand.Set_CommandType | API | ObjectId 36, Command type value 4, Client Connection Id ec0b9261-8ea2-4324-ab16-ff356f224421" 
ThreadID="8,808" ProcessorNumber="0" message="<sc.SqlConfigurableRetryLogicManager.CommandProvider|INFO> Requested the CommandProvider value." 
ThreadID="8,808" ProcessorNumber="0" message="SqlCommand.InternalExecuteReaderAsync | API> 36, Client Connection Id ec0b9261-8ea2-4324-ab16-ff356f224421, Command Text = 'GetBlogs'" 
ThreadID="8,808" ProcessorNumber="0" message="SqlCommand.RunExecuteReaderTds | Info | Object Id 36, Activity Id 9829f214-a1e0-4e4f-9d0e-b48af043eb2f:1, Client Connection Id ec0b9261-8ea2-4324-ab16-ff356f224421, Command executed as RPC, RPC Name 'GetBlogs' " 
ThreadID="8,808" ProcessorNumber="5" message="SqlCommand.SetActiveConnectionAndResult | API | ObjectId 36, Client Connection Id ec0b9261-8ea2-4324-ab16-ff356f224421, MARS=True" 
ThreadID="16,448" ProcessorNumber="6" message="TdsParserStateObject.ReadAsyncCallback | Info | State Object Id 3, received error 0 on idle connection" 
ThreadID="8,808" ProcessorNumber="3" message="SqlCommand.InternalEndExecuteReader | INFO | ObjectId 36, Client Connection Id ec0b9261-8ea2-4324-ab16-ff356f224421, MARS=True, AsyncCommandInProgress=True" 
ThreadID="8,808" ProcessorNumber="3" message="SqlCommand.VerifyEndExecuteState | API | ObjectId 36, Client Connection Id ec0b9261-8ea2-4324-ab16-ff356f224421, MARS=True, AsyncCommandInProgress=True" 
ThreadID="8,808" ProcessorNumber="3" message="SqlCommand.VerifyEndExecuteState | API | ObjectId 36, Client Connection Id ec0b9261-8ea2-4324-ab16-ff356f224421, MARS=True, AsyncCommandInProgress=True" 
ThreadID="8,808" ProcessorNumber="4" message="SqlError.ctor | ERR | Info Number 10928, Error State 1, Error Class 20, Error Message 'Resource ID : 1. The request limit for the database is 60 and has been reached. See 'https://docs.microsoft.com/azure/azure-sql/database/resource-limits-logical-server' for assistance.', Procedure '', Line Number 1" 
ThreadID="8,808" ProcessorNumber="4" message="TdsParserStateObject.DecrementOpenResultCount | INFO | State Object Id 3, Processing Attention." 
ThreadID="8,808" ProcessorNumber="4" message="SqlConnection.OnError | Info | Object Id 36, Connection broken." 
ThreadID="8,808" ProcessorNumber="1" message="CachedAsyncState.ResetAsyncState | API | ObjectId 36, Client Connection Id ec0b9261-8ea2-4324-ab16-ff356f224421, AsyncCommandInProgress=True" 
ThreadID="8,808" ProcessorNumber="6" message="<comm.ADP.TraceException|ERR|THROW> 'System.InvalidOperationException: Invalid operation. The connection is closed.'" 

Expected behavior

Sql Command should receive an exception and should not hang

Further technical details

Microsoft.Data.SqlClient version: 5.0.0
.NET target: Core 6.0
SQL Server version: Azure DB
Operating system: Windows

Additional context

@JRahnama
Copy link
Member

@TungKJ we will look into this and will get back to you soon.

@lcheunglci
Copy link
Contributor

There was a PR opened yesterday #1766 that may address this issue. The build from that PR can be found here . Could you try it out and see if this fixes the issue?

@TungKJ
Copy link
Author

TungKJ commented Sep 21, 2022

using the attached package, the app still hangs

@lcheunglci
Copy link
Contributor

Thanks for checking @TungKJ. We'll have to further investigate the deadlock issue.

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

No branches or pull requests

3 participants