DistributedLock icon indicating copy to clipboard operation
DistributedLock copied to clipboard

Microsoft.Data.SqlClient.SqlException log noise

Open devodo opened this issue 1 month ago • 0 comments

I am using DistributedLock.SqlServer for distributed locking in an Azure hosted app that is logging to Application Insights. The locking is working great, thank you! However, it is causing a lot of log noise showing up in Application Insights as Sql Server dependency failures due to the following exception occurring fairly often:

Microsoft.Data.SqlClient.SqlException (0x80131904): A severe error occurred on the current command.  The results, if any, should be discarded.
Operation cancelled by user.
   at Microsoft.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection, Action`1 wrapCloseInAction)
   at Microsoft.Data.SqlClient.SqlInternalConnection.OnError(SqlException exception, Boolean breakConnection, Action`1 wrapCloseInAction)
   at Microsoft.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(TdsParserStateObject stateObj, SqlCommand command, Boolean callerHasConnectionLock, Boolean asyncClose)
   at Microsoft.Data.SqlClient.TdsParser.TryRun(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj, Boolean& dataReady)
   at Microsoft.Data.SqlClient.SqlCommand.FinishExecuteReader(SqlDataReader ds, RunBehavior runBehavior, String resetOptionsString, Boolean isInternal, Boolean forDescribeParameterEncryption, Boolean shouldCacheForAlwaysEncrypted)
   at Microsoft.Data.SqlClient.SqlCommand.CompleteAsyncExecuteReader(Boolean isInternal, Boolean forDescribeParameterEncryption)
   at Microsoft.Data.SqlClient.SqlCommand.InternalEndExecuteNonQuery(IAsyncResult asyncResult, Boolean isInternal, String endMethod)
   at Microsoft.Data.SqlClient.SqlCommand.EndExecuteNonQueryInternal(IAsyncResult asyncResult)
   at Microsoft.Data.SqlClient.SqlCommand.EndExecuteNonQueryAsync(IAsyncResult asyncResult)
   at Microsoft.Data.SqlClient.SqlCommand.<>c.<InternalExecuteNonQueryAsync>b__193_1(IAsyncResult asyncResult)
   at System.Threading.Tasks.TaskFactory`1.FromAsyncCoreLogic(IAsyncResult iar, Func`2 endFunction, Action`1 endAction, Task`1 promise, Boolean requiresSynchronization)
ClientConnectionId:d7f88130-dbb2-4509-8019-92a4428b47a3

I am using the following code to acquire a lock:

await using var handle = await _lockProvider.AcquireLockAsync(
    lockKey,
    lockingConfig.Value.LockTimeout,
    cancellationToken);

The Microsoft.Data.SqlClient.SqlException is only occurring if handle.HandleLostToken is called.

I was able to observe this locally by registering a custom IObserver<DiagnosticListener>. From this I can see the Microsoft.Data.SqlClient.SqlException is coming from executing the command: WAITFOR DELAY @delay. I can see this command text is defined in the method SqlDatabaseConnection.SleepAsync() that gets called by ConnectionMonitor and the monitor starts when calling handle.HandleLostToken. So I suspect the connection is closing before the command completes resulting in the exception but it gets caught and swallowed by NonThrowingAwaitable<TTask>.

Functionally this does not have an impact but Application Insights telemetry still observes it by default and reports it as a dependency failure. I expect other logging platforms would also be seeing this as their telemetry processing will be capturing .NET exception diagnostics.

I guess this ConnectionMonitor behaviour is all by design and the solution is to add filtering on the telemetry side. So I guess I have arrived at an answer but I'm sharing my findings here anyway in case there is a better solution or it helps others who come across this.

devodo avatar Nov 21 '25 18:11 devodo