-
Notifications
You must be signed in to change notification settings - Fork 240
Description
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.