Нужна помощь в диагностике странных тайм-аутов запросов SQL Server из C # - PullRequest
5 голосов
/ 28 марта 2019

Я разработал много приложений .NET / SQL Server, но я страдаю от тайм-аутов запросов SQL, которые я не могу понять до конца.У меня есть большой опыт в этой области, чтобы найти оскорбительные запросы и переиндексировать / переписать их.Мое веб-приложение размещено на AWS с использованием RDS для SQL Server и EC2 для веб-приложения.У нас 100-200 уникальных пользователей в день, а база данных составляет около 15 ГБ с парой таблиц> 1 ГБ.

Я вижу исключения в течение дня с сообщением:

'Execution Timeout Expired.  The timeout period elapsed prior to completion of the operation or the server is not responding.'

Запросыте, которые страдают от таймаутов, так же случайны, как и тайм-ауты.Кажется, это не совпадает ни с чем очевидным (резервные копии выполняются за ночь и т. Д.).

Я попытался взять каждый запрос из приложения C # и запустить его непосредственно в SQL (с такими же параметрами SET, как Arith Abort) иони все бегают просто отлично.Некоторые из них являются медленными запросами по своей природе, но самый медленный выполняется примерно за 2 секунды и имеет ~ 400 тыс. Логических чтений.Тем не менее, я также вижу тайм-аут запросов, которые выполняются в 15 мс и имеют <10 логических чтений. </p>

Самое странное, что я видел, я взял запрос из веб-приложения и закодировал его в консольприложение, которое работает в течение 24 часов, вызывая запрос раз в секунду.У него не было ни одного исключения / тайм-аута, хотя я видел, что в основной системе есть тайм-ауты для того же запроса во время его выполнения.

Недавно я обновил сервер RDS до M5 Large и всеиндексы перестраиваются в одночасье каждый день.В какой-то момент я запустил DBCC FREEPROCCACHE, чтобы убедиться, что нет никаких устаревших планов запросов, вызывающих проблему.

Я чувствую, что это перехват параметров или моя последняя мысль - аппаратные / сетевые сбои, но которые действительно сжимают соломинки!

Трассировка стека, которую я получаю, выглядит так, как будто она находится в середине запроса, а не на этапе соединения.

at System.Data.SqlClient.SqlInternalConnection.OnError(SqlException exception, Boolean breakConnection, Action`1 wrapCloseInAction)  
   at System.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(TdsParserStateObject stateObj, Boolean callerHasConnectionLock, Boolean asyncClose)  
   at System.Data.SqlClient.TdsParserStateObject.ReadSniError(TdsParserStateObject stateObj, UInt32 error)  
   at System.Data.SqlClient.TdsParserStateObject.ReadSniSyncOverAsync()  
   at System.Data.SqlClient.TdsParserStateObject.TryReadNetworkPacket()  
   at System.Data.SqlClient.TdsParserStateObject.TryPrepareBuffer()  
   at System.Data.SqlClient.TdsParserStateObject.TryReadByteArray(Byte[] buff, Int32 offset, Int32 len, Int32& totalRead)  
   at System.Data.SqlClient.TdsParserStateObject.TryReadString(Int32 length, String& value)  
   at System.Data.SqlClient.TdsParser.TryReadSqlStringValue(SqlBuffer value, Byte type, Int32 length, Encoding encoding, Boolean isPlp, TdsParserStateObject stateObj)  
   at System.Data.SqlClient.TdsParser.TryReadSqlValue(SqlBuffer value, SqlMetaDataPriv md, Int32 length, TdsParserStateObject stateObj, SqlCommandColumnEncryptionSetting columnEncryptionOverride, String columnName)  
   at System.Data.SqlClient.SqlDataReader.TryReadColumnInternal(Int32 i, Boolean readHeaderOnly)  
   at System.Data.SqlClient.SqlDataReader.TryReadColumn(Int32 i, Boolean setTimeout, Boolean allowPartiallyReadColumn)  
   at System.Data.SqlClient.SqlDataReader.GetValueInternal(Int32 i)  
   at System.Data.SqlClient.SqlDataReader.GetValue(Int32 i) 

Любая помощь с некоторыми методами, чтобы добраться до сути этого, будет высоко оценена, так как она тревожит иЯ боюсь, что это вдруг станет намного хуже.

Спасибо

РЕДАКТИРОВАТЬ 1

Я попытался создать ту же проблему локально, запустивтестируйте приложение (как указано выше) один раз каждые 10 мс и одновременно выполняйте транзакцию медленной блокировки в SSMS.

Запрос из приложения

SELECT TOP 10 *
FROM MyTable
WHERE LastModifiedBy = 'Stu'

Запрос в SSMS

BEGIN TRAN
UPDATE TOP (10000) MyTable SET LastModifiedBy = 'Me' where LastModifiedBy = 'Me'
WAITFOR DELAY '00:00:35'
COMMIT

При таких ошибках я вижу то, что обычно ожидаю увидеть в SQL Profiler, где запрос приложения занимает ровно 30000 мс, и я получаю исключение в приложении.Тем не менее, полезным выводом этого является то, что трассировка стека отличается от той, которую я вижу в рабочей (выше).

at System.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection, Action`1 wrapCloseInAction) 
   at System.Data.SqlClient.SqlInternalConnection.OnError(SqlException exception, Boolean breakConnection, Action`1 wrapCloseInAction) 
   at System.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(TdsParserStateObject stateObj, Boolean callerHasConnectionLock, Boolean asyncClose) 
   at System.Data.SqlClient.TdsParser.TryRun(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj, Boolean& dataReady) 
   at System.Data.SqlClient.SqlDataReader.TryConsumeMetaData() 
   at System.Data.SqlClient.SqlDataReader.get_MetaData() 
   at System.Data.SqlClient.SqlCommand.FinishExecuteReader(SqlDataReader ds, RunBehavior runBehavior, String resetOptionsString, Boolean isInternal, Boolean forDescribeParameterEncryption, Boolean shouldCacheForAlwaysEncrypted) 
   at System.Data.SqlClient.SqlCommand.RunExecuteReaderTds(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, Boolean async, Int32 timeout, Task& task, Boolean asyncWrite, Boolean inRetry, SqlDataReader ds, Boolean describeParameterEncryptionRequest) 
   at System.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method, TaskCompletionSource`1 completion, Int32 timeout, Task& task, Boolean& usedCache, Boolean asyncWrite, Boolean inRetry) 
   at System.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method) 
   at System.Data.SqlClient.SqlCommand.ExecuteReader(CommandBehavior behavior, String method) 
   at System.Data.SqlClient.SqlCommand.ExecuteDbDataReader(CommandBehavior behavior) 
   at System.Data.Common.DbCommand.System.Data.IDbCommand.ExecuteReader(CommandBehavior behavior) 

Я читаю эту трассировку стека, так как запрос не начал выполняться, так как он все ещепытаясь прочитать метаданные для запроса.Однако это контрастирует с трассировкой стека от производства, которая (на мой взгляд), кажется, находится в середине чтения данных из столбцов, но имеет время ожидания в середине выполнения.

Я также читал о .NET 4.6.2 какая версия мы используем.Я обновлю все до 4.7.2 этим вечером, чтобы исключить это.( Соединение с удаленным сервером SQL прерывается при обновлении веб-сервера до .net framework 4.6.1 )

1 Ответ

0 голосов
/ 04 апреля 2019

После недели напряженного расследования это исправлено !! Он работает уже более 2 часов без единого тайм-аута: -)

Оказалось, что это какая-то ошибка или несоответствие .NET v4.6.2.

Моя конфигурация была:

  • SQL Server 2017, веб-версия на AWS RDS
  • .NET v4.6.2
  • Dapper v1.50.5

Мои изменения:

  • Установить .NET 4.7.2 на веб-сервере
  • Обновите Web App и все проекты DLL в Visual Studio для использования .NET 4.7.2 (убедитесь, что web.config был обновлен до <httpRuntime targetFramework="4.7.2" />)
  • Обновите Dapper через Nuget до последней версии v.1.60.0 (я не думаю, что Dapper был виноват, я просто обновил его, делая все остальное, так как он связан с базой данных)

Эти вопросы помогли мне указать направление:

СПАСИБО В ИНТЕРНЕТЕ - КАК НА ЗЕМЛЕ Я КОДИРОВАЛ ПЕРЕД ТЕБЕМ, ЧТОБЫ ВЫ ПРИШЛИ В ТЕЧЕНИЕ

...