[Из песочницы] Один день из жизни DBA Microsoft SQL Server
В арсенале Microsoft SQL Server есть одна интересная штука — service broker. По сути своей это очередь сообщений, встроенная в СУБД, способная обеспечить транзакционную целостность данных. Вещь удобная и, в грамотных руках, способная выстроить систему обмена между SQL Server«ами без применения дополнительных внешних сервисов — прямо из коробки.
С одной стороны service broker удобен, но с другой — от него не мало сюрпризов, способных поломать голову нюансами своей работы. О решении одного из таких сюрпризов поговорим прямо сейчас.
Обнаружили, что логи MS SQL Server, одной из наших, систем жутко забиты сообщениями от service broker типа :
An error occurred in dialog transmission: Error: 601, State: 3.
Could not continue scan with NOLOCK due to data movement.Не долгие поиски на просторах всемирной сети так или иначе выводили на информацию о том, что какие то данные в БД закораптились и требуется их обнаружение (для дальнейшего восстановления) при помощи инструкции DBCC CHECKDB. Счастье было не долгим, ибо данный подход не выявил ни одной проблемы — ни в пользовательских БД, ни в системных.
Так как логи продолжали ужасать своим натиском (пару десятков записей за несколько секнд), а первый план по выявлению причин этого «наводнения» провалился — было решено вести поиски на стороне service broker, ибо читался след от брокера — как минимум по словам «dialog transmission ».
Подобные поиски в системах начинаются с просмотра очередт на отправку sys.transmission_queue — не стал исключением и наш случай. Первый же select из sys.transmission_queue вывалил на экран тот самый »Could not continue scan with NOLOCK due to data movement», что с одной стороны вселило уверенности, что копаем в правильную сторону, но с другой — как выявить проблему, если select заканчивается таким сообщением?
Лезем в данные по конечным точкам диалогов sys.conversation_endpoints. С ужасом обнаруживаю, что там весит около 12 миллионов не закрытых диалогов. Первый 10 минут зачистки ненужных накоплений показали, что впереди нас ждет целая неделя ожиданий — ибо чистка протекала крайне медлено. Само закрытие диалога было долгим. У нас был главный подозреваемый — куча не закрытых диалогов service broker’а и надо было его «расколоть».
Так как сидеть целую неделю, и закрывать диалоги не хотелось, был накидан такой план:
- через sqlcmd пачками вычитываем хендлеры подвисших диалогов
- формируем sql batch на завершение полученых диалогов
- через sqlcmd выполняем сформированный sql batch и гоняем это по циклу, по не закроем все подвисшие диалоги
set nocount on;
select 'set nocount on;'
union all
select 'set xact_abort off;'
union all
select top 900 'end conversation ''' + cast(conversation_handle as varchar(100)) + ''' with cleanup;' from sys.conversation_endpoints where far_service = '//far_db.far_host/far_service'batch.sql (пример sql batch — для пункта 2)
@echo off
for /L %%B in (0,1,13000) do (
sqlcmd -i c:\usr\sql_cd.sql -o c:\usr\res.sql -S server_name -d db_name -r1
sqlcmd -i c:\usr\res.sql -S server_name -d db_name -r1
del c:\usr\res.sql
)end_conversation.bat (батник для пунктов 1 и 3)
Этот товарищ отработал чуть менее двух суток и закрыл все подвисшие диалоги. Как видно из примера — все эти диалоги были открыты для одного конкретного сервиса. С самим удаленным сервисом брокера разобрались до начала массового закрытия диалогов.
К счастью или сожалению, но после закрытия всех не нужных диалогов брокера — ошибки в логах так и не прекратились массово появляться.
Следующей мыслью было потушить service broker end point на СУБД в целом и отключить брокер на основной БД в частности, но и это, увы, не спасло от продолжающихся ошибок в логах.
В какой то из дней решения вопроса возникла необходимость переключиться на зеркало от основной БД. Именно в момент переключения на зеркало нашей БД и вылезла в логах информация о проблеме:
2019–08–12 16:42:40.41 spid41s SQL Server detected a logical consistency-based I/O error: incorrect pageid (expected 6:260707; actual 559:-641654744). It occurred during a read of page (6:260707) in database ID 2 at offset 0×0000007f4c6000 in file 'D:\TempDB\tempdb_mssql_5.ndf'. Additional messages in the SQL Server error log or operating system error log may provide more detail. This is a severe error condition that threatens database integrity and must be corrected immediately. Complete a full database consistency check (DBCC CHECKDB). This error can be caused by many factors; for more information, see SQL Server Books Online.
Глядя на неё и стало понятно, что виновником торжества выступает tempdb нашей СУБД.
Как известно, у tempdb одно лекарство — рестарт службы sql. Выбиваем окно у бизнеса для простоя сервиса и перезагружаем основную ноду. После рестарта сервера логи перестало заваливать.
Как оказалось — проблема на самом деле крылась в закорапченных данных. Так, что применяя DBCC CHECKDB — не забывайте применять его и к tempdb и следите за диалогами.
