RetryLogicProvider is called twice recursively when calling SqlCommand.ExecuteScalarAsync

[frederic-luce]

Describe the bug

I use SqlClient 3.0 RetryLogic to transparently log extensive information about failed request.

When a retry logic provider is used with SqlCommand.ExecuteScalarAsync, RetryLogicProvider.ExecuteAsync is called twice recursively : first time from SqlCommand.ExecuteScalarAsync, and second time from the inner SqlCommand.ExecuteReaderAsync.

Here is a stack trace from the second call :

• MultipleRetryCall.dll!MultipleRetryCall.ErrorInfoRetryLogicProvider.ExecuteAsync<Microsoft.Data.SqlClient.SqlDataReader>(object sender, System.Func<System.Threading.Tasks.Task<Microsoft.Data.SqlClient.SqlDataReader>> function, System.Threading.CancellationToken cancellationToken) Ligne 77
• Microsoft.Data.SqlClient.dll!Microsoft.Data.SqlClient.SqlCommand.InternalExecuteReaderWithRetryAsync(System.Data.CommandBehavior behavior, System.Threading.CancellationToken cancellationToken) Ligne 2548
• Microsoft.Data.SqlClient.dll!Microsoft.Data.SqlClient.SqlCommand.ExecuteReaderAsync(System.Data.CommandBehavior behavior, System.Threading.CancellationToken cancellationToken) Ligne 2543
• Microsoft.Data.SqlClient.dll!Microsoft.Data.SqlClient.SqlCommand.ExecuteReaderAsync(System.Threading.CancellationToken cancellationToken) Ligne 2538
• Microsoft.Data.SqlClient.dll!Microsoft.Data.SqlClient.SqlCommand.InternalExecuteScalarAsync(System.Threading.CancellationToken cancellationToken) Ligne 2635
• Microsoft.Data.SqlClient.dll!Microsoft.Data.SqlClient.SqlCommand.InternalExecuteScalarWithRetryAsync.AnonymousMethod__0() Ligne 2626
• MultipleRetryCall.dll!MultipleRetryCall.ErrorInfoRetryLogicProvider.LogCallsAsync(object sender, System.Func<System.Threading.Tasks.Task> function) Ligne 65
• MultipleRetryCall.dll!MultipleRetryCall.ErrorInfoRetryLogicProvider.ExecuteAsync.AnonymousMethod__0() Ligne 81
• Microsoft.Data.SqlClient.dll!Microsoft.Data.SqlClient.SqlRetryLogicProvider.ExecuteAsync(object sender, System.Func<System.Threading.Tasks.Task> function, System.Threading.CancellationToken cancellationToken) Ligne 106
• MultipleRetryCall.dll!MultipleRetryCall.ErrorInfoRetryLogicProvider.ExecuteAsync(object sender, System.Func<System.Threading.Tasks.Task> function, System.Threading.CancellationToken cancellationToken) Ligne 81
• Microsoft.Data.SqlClient.dll!Microsoft.Data.SqlClient.SqlCommand.InternalExecuteScalarWithRetryAsync(System.Threading.CancellationToken cancellationToken) Ligne 2626
• Microsoft.Data.SqlClient.dll!Microsoft.Data.SqlClient.SqlCommand.ExecuteScalarAsync(System.Threading.CancellationToken cancellationToken) Ligne 2621
• System.Data.Common.dll!System.Data.Common.DbCommand.ExecuteScalarAsync() Ligne 191
• MultipleRetryCall.dll!MultipleRetryCall.Program.Main(string[] args) Ligne 147

(bold : custom code)

To reproduce

Define a SqlRetryLogicBaseProvider that encapsulate a FixedRetryProvider.
Execute* methods add logs before and after each inner call.

First part call ExecuteScalarAsync that will fail :

 ExecuteAsync<T> Microsoft.Data.SqlClient.SqlCommand Starting counter=1 thread=4
 LogCallsAsync<T> Microsoft.Data.SqlClient.SqlCommand    Starting inner 1
  ExecuteAsync<T> Microsoft.Data.SqlClient.SqlCommand Starting counter=2 thread=4
  LogCallsAsync<T> Microsoft.Data.SqlClient.SqlCommand    Starting inner 2
  LogCallsAsync<T> Microsoft.Data.SqlClient.SqlCommand    Stopping inner 2
  LogCallsAsync<T> Microsoft.Data.SqlClient.SqlCommand    Starting inner 3
  LogCallsAsync<T> Microsoft.Data.SqlClient.SqlCommand    Stopping inner 3
  LogCallsAsync<T> Microsoft.Data.SqlClient.SqlCommand    Starting inner 4
  LogCallsAsync<T> Microsoft.Data.SqlClient.SqlCommand    Stopping inner 4
  ExecuteAsync<T> Microsoft.Data.SqlClient.SqlCommand Stopping counter=2 thread=5
 LogCallsAsync<T> Microsoft.Data.SqlClient.SqlCommand    Stopping inner 4
 ExecuteAsync<T> Microsoft.Data.SqlClient.SqlCommand Stopping counter=1 thread=7
  Error The number of retries has exceeded the maximum of 3 attempt(s). (Error) (Error) (Error) total tries = 4

Same call with ExecuteReaderAsync :

ExecuteReaderAsync failure with retry
 ExecuteAsync<T> Microsoft.Data.SqlClient.SqlCommand Starting counter=1 thread=7
 LogCallsAsync<T> Microsoft.Data.SqlClient.SqlCommand    Starting inner 1
 LogCallsAsync<T> Microsoft.Data.SqlClient.SqlCommand    Stopping inner 1
 LogCallsAsync<T> Microsoft.Data.SqlClient.SqlCommand    Starting inner 2
 LogCallsAsync<T> Microsoft.Data.SqlClient.SqlCommand    Stopping inner 2
 LogCallsAsync<T> Microsoft.Data.SqlClient.SqlCommand    Starting inner 3
 LogCallsAsync<T> Microsoft.Data.SqlClient.SqlCommand    Stopping inner 3
 ExecuteAsync<T> Microsoft.Data.SqlClient.SqlCommand Stopping counter=1 thread=5
Error The number of retries has exceeded the maximum of 3 attempt(s). (Error) (Error) (Error) total tries = 3

Same call with ExecuteScalar (Sync) :

ExecuteScalar failure with retry
 Execute<T> Microsoft.Data.SqlClient.SqlCommand Starting counter=1 thread=5
 LogCalls<T> Microsoft.Data.SqlClient.SqlCommand    Starting inner 1
 LogCalls<T> Microsoft.Data.SqlClient.SqlCommand    Stopping inner 1
 LogCalls<T> Microsoft.Data.SqlClient.SqlCommand    Starting inner 2
 LogCalls<T> Microsoft.Data.SqlClient.SqlCommand    Stopping inner 2
 LogCalls<T> Microsoft.Data.SqlClient.SqlCommand    Starting inner 3
 LogCalls<T> Microsoft.Data.SqlClient.SqlCommand    Stopping inner 3
 Execute<T> Microsoft.Data.SqlClient.SqlCommand Stopping counter=1 thread=5
Error The number of retries has exceeded the maximum of 3 attempt(s). (Error) (Error) (Error) total tries = 3

GIST
MultipleRetryCall.zip

Expected behavior

RetryLogicProvider should be called only once when used with ExecuteScalarAsync to be consistent with ExecuteScalar and ExecuteReaderAsync.

Further technical details

Microsoft.Data.SqlClient version: 3.0
.NET target: netcore3.1
SQL Server version: 14
Operating system: Windows 10

[cheenamalhotra]

Hi @frederic-luce

PR #1220 shall address this issue.

[frederic-luce]

Thanks a lot @cheenamalhotra !
Do you know if and when a v4 preview package will be available ?

[cheenamalhotra]

Very soon :)
(In a day or two max)

[cheenamalhotra]

HI @frederic-luce

v4.0.0-preview1 is now released.