Поиск причин блокировок СУБД

31.05.21

База данных - HighLoad оптимизация

Расследование блокировок СУБД. Статья написана по мотивам вебинара Виктора Богачева.

Вступление

Количество пользователей нашей основной базы данных активно увеличивается за счет слияния второстепенных баз. Динамика примерно такая: 2020 – 150, 2021 – 300, 2022 – 500 (план). Поэтому оптимизация и быстродействие для нас важны: при увеличении числа пользователей проблемы растут нелинейно. Одно время даже хотели заключить договор ЦКТП, но пока справляемся своими силами.

Был один случай..

.. участились ошибки блокировки СУБД.


Анализ типов блокировок на сервере СУБД (за пол-дня). Ожидания LCK_M_X, LCK_M_U занимают доминирующие позиции.

Что делать ?

Нашел видео по ключевым словам «блокировки, эксперт», автор - Виктор Богачев. Составил краткий конспект

0-3 Вступление, рабочие инструменты

3-4 Поиск блокировок по dmv

4-5 Причина блокировок - отсутствует подходящий индекс

5-8 План запроса, поиск запроса в 1С, используя logcfg

8-10 Ключ dbmslocks

10-12 Заключение, контакты

Решил посмотреть в СУБД. В видео использован запрос

SELECT
db.name,
a.session_id,
a.blocking_session_id,
a.transaction_id,
a.wait_time,
a.wait_type,
st.text,
qp.query_plan
FROM sys.dm_exec_requests AS a
OUTER APPLY sys.dm_exec_sql_text(a.sql_handle) AS st
OUTER APPLY sys.dm_exec_query_plan(a.sql_handle) AS qp
LEFT JOIN sys.sysprocesses AS p
OUTER APPLY sys.dm_exec_sql_text(p.sql_handle) AS stblock
ON a.blocking_session_id > 0 AND a.blocking_session_id = p.spid
LEFT JOIN sys.databases db
ON a.database_id = db.database_id
WHERE NOT a.status IN ('background', 'sleeping')
ORDER BY a.cpu_time DESC

представление sys.dm_exec_requests показывает выполняемые запросы в реальном времени, оно содержит поле blocking_session_id которое указывает на блокирующую сессию. (Доступна документация)

 

Как я уже говорил, у нас большая компания с развитой инфраструктурой. Физически невозможно иметь доступ ко всем серверам компании. Получение информации с сервера целевой СУБД — через системного администратора. Поэтому просматривать состояние базы данных в реальном времени с помощью динамических представлений было неудобно. Мы не знали - в какой момент происходит блокировка. Договорились, что системный администратор соберет extended events по описанию (Спасибо, Юрий Пермитин) но напрямую задачу решить не удалось — события блокировок в СУБД происходят настолько часто, что производительность сервера упала. Составил более подробное описание, с фильтрами по длительности.

 

Количество логируемых событий сократилось до приемлемого уровня. Оказалось неожиданностью: событие lock_timeout тоже нуждается в ограничении по длительности. Оказывается, при соединении внутренних процессов с tempdb, команда SET LOCK_TIMEOUT timeout_period не выполняется, и работа с временными таблицами #tt сопровождается lock_timeout, длительность=0. Файл записался при остановке сессии сбора данных. В результате я получил файл и открыл его Management Studio на тестовом сервере.

События lock_timeout, фрагменты sql_text

1. DELETE FROM T1 FROM dbo._InfoRg18447 T1 WHERE (T1._Fld18454RRef = @P1) AND (T1._Fld1420 = @P2)

С помощью функции ПолучитьСтруктуруБазыДанных() нашел имя регистра и имя поля. Как вы догадываетесь, индекс поля отсутствует. Очень похоже на ситуацию из видео на минуте 7. Для поля поставил значение «индексировать», флаг «ведущее» использовать не стал: могут быть пустые значения. Кстати, до добавления индекса события lock_deadlock на таблице dbo._InfoRg18447 тоже происходили. Причина блокировок СУБД подробно описана в видео: отсутствует индекс, происходит сканирование (с захватом) всей таблицы в режиме исключительной блокировки. При этом управляемые блокировки не учитывают план запроса, блокируют по значениям конкретных полей, конфликта между ними не происходит.

 

2. UPDATE T1 SET _Description = @P1, …. FROM dbo._ScheduledJobs31390 T1 WHERE T1._ID = @P15 AND T1._Version = @P16

Может показаться, что не хватает индекса по полю Version. Я даже полез на сайте смотреть возможные индексы https://its.1c.ru/db/metod8dev/content/1590/hdoc, но потом сообразил, что это регламентное задание. Такие таблицы содержат только одну строку, индекс не нужен. Регламентное задание запускалось в устарелой версии УТ при открытии программы, для целей rls. В новой версии его можно отключить.

 

3. Было несколько ошибок блокировок, связанных с шиной обмена Datareon. При зависании службы шины, отслеживаемые события в 1С не записывались, создавали lock_timeout. Эта ситуация была исправлена без моего участия.

 

События lock_escalation

Иногда происходит эскалация при работе с ценами по регистру «Цены номенклатуры» и табличной части документа «Установка цен». Документы больше 5000 строк табличной части, решение этой проблемы лежит в области организации процессов.

 

Итоги работы

Стало заметно лучше. Ниже анализ ожиданий на сервере СУБД за неделю, суммарная длительность ожиданий LCK_M_X, LCK_M_U составляет 18 минут, до начала работ суммарная длительность ожиданий могла быть до 2 часов в день.

 

P.S. Чтобы счастье было полным

настроил технологический журнал для dbmslocks (важно, что события собираются без отборов).

<?xml version="1.0"?>
<config xmlns="http://v8.1c.ru/v8/tech-log">
<log location="C:\Log\Logs\UT" history="24">
<event>
<eq property="name" value="DBMSSQL"/>
<eq property="p:processName" value="My_Database_Name"/>
</event>
<property name="all"/>
<property name="lkaid"/>
<property name="lka"/>
<property name="lkp"/>
<property name="lkpid"/>
<property name="lksrc"/>
</log>
<dbmslocks />
</config>

Свойства описаны на сайте ИТС.

 
 Есть один способ эффективно находить информацию на сайте ITS.


    lka=‘1’ поток является источником блокировки.

    lkp=‘1’ поток является жертвой блокировки.

    lkpid номер запроса к СУБД, «кто кого заблокировал» (только для потока-жертвы блокировки).

    lkaid список номеров запросов к СУБД, «кто кого заблокировал» (только для потока-источника блокировки).

    lksrc номер соединения источника блокировки, если поток является жертвой.

    lkpto время в секундах, прошедшее с момента обнаружения, что поток является жертвой.

    lkato время в секундах, прошедшее с момента обнаружения, что поток является источником блокировок.

Файлы по часам получились более 6 Гб, поэтому для выделения информации использовал bash:

egrep -e ',lk.id=' -B20 -A20 '21042614.log' > result14.txt

Для строчек, содержащих lkaid / lkpid выбрать 20 строк сверху и снизу, поместить в файл. Ниже пример: два источника, одна жертва. Ожидание длилось 0,84 секунды, прежде чем команда ПланыОбмена.ЗарегистрироватьИзменения() дождалась освобождения ресурса и установила блокировку.

********************************************************************************************************************************************************************
48:57.589056-4,DBMSSQL,6,process=rphost,p:processName=My_Database_Name,OSThread=9868,t:clientID=19295,t:applicationName=1CV8C,t:computerName=my_pc,t:connectID=73248,SessionID=345069,Usr=Иванов И.И.,AppID=1CV8C,DBMS=DBMSSQL,DataBase=My_Database_Name,Trans=1,dbpid=113,Sql=TRUNCATE TABLE #tt364,lka=1,lkaid=10,lkato=0,Context='Форма.Записать : Документ.ЗаказКлиента.Форма.ФормаДокумента
Документ.ЗаказКлиента.МодульОбъекта : 914 : ПроведениеСерверУТ.ЗаписатьНаборыЗаписей(ЭтотОбъект);
	ОбщийМодуль.ПроведениеСерверУТ.Модуль : 355 : Объект.Движения.Записать();
		РегистрНакопления.СвободныеОстатки.МодульНабораЗаписей : 69 : СформироватьТаблицуИзмененийДвижений();
			РегистрНакопления.СвободныеОстатки.МодульНабораЗаписей : 347 : Результат = Запрос.ВыполнитьПакет();'

********************************************************************************************************************************************************************
48:57.589064-2,DBMSSQL,5,process=rphost,p:processName=My_Database_Name,OSThread=9868,t:clientID=19295,t:applicationName=1CV8C,t:computerName=my_pc,t:connectID=73248,SessionID=345069,Usr=Иванов И.И.,AppID=1CV8C,DBMS=DBMSSQL,DataBase=My_Database_Name,Trans=1,dbpid=113,Sql='SELECT
T1._Fld14389
FROM dbo._Const14388 T1
WHERE ((T1._Fld1420 = ?)) AND (T1._RecordKey = ?)
p_0: 0N
p_1: 0x31
',Rows=1,RowsAffected=-1,lka=1,lkaid=10,lkato=0,Context='Форма.Записать : Документ.ЗаказКлиента.Форма.ФормаДокумента
Документ.ЗаказКлиента.МодульОбъекта : 914 : ПроведениеСерверУТ.ЗаписатьНаборыЗаписей(ЭтотОбъект);
	ОбщийМодуль.ПроведениеСерверУТ.Модуль : 355 : Объект.Движения.Записать();
		ОбщийМодуль.обменУправлениеРегистрацией.Модуль : 9 : ЗарегистрироватьДляВыгрузки(Источник);
			ОбщийМодуль.обменУправлениеРегистрацией.Модуль : 142 : ОписанияСобытий = обменКэшированиеПовтИсп.ПолучитьОписанияСобытий(ИмяМетаданных, обменПривелигированный.ПоследнееИзменениеНастроекОбмена());
				ОбщийМодуль.обменПривелигированный.Модуль : 6 : Возврат Константы.обменПоследнееИзменениеНастроекОбмена.Получить();'

********************************************************************************************************************************************************************
48:58.293069-1,DBMSSQL,5,process=rphost,p:processName=My_Database_Name,OSThread=9868,t:clientID=19295,t:applicationName=1CV8C,t:computerName=my_pc,t:connectID=73248,SessionID=345069,Usr=Иванов И.И.,AppID=1CV8C,DBMS=DBMSSQL,DataBase=My_Database_Name,Trans=1,dbpid=113,Sql='UPDATE T1 SET _Fld20718 = T1._Fld20718 + ?, _Fld20719 = T1._Fld20719 + ?, _Fld20720 = T1._Fld20720 + ?, _Fld20721 = T1._Fld20721 + ?, _Fld20722 = T1._Fld20722 + ?
FROM dbo._AccumRgT20725 T1
WHERE (T1._Period = ? AND T1._Fld20715RRef = ? AND T1._Fld20716_TYPE = 0x08 AND T1._Fld20716_RTRef = 0x00000205 AND T1._Fld20716_RRRef = ? AND T1._Fld20717RRef = ? AND T1._Fld1420 = ? AND T1._Splitter = ?) AND (T1._Fld1420 = ?)
p_0: 1679366.4N
p_1: 1679366.4N
p_2: 1679366.4N
p_3: 302N
p_4: 302N
p_5: 40210201000000
p_6: 0x8D0E005056B09D4611EB55AD87043C08
p_7: 0x8D0E005056B09D4611EB55AC6E9EE5B2
p_8: 0x8CAA005056B05DE111EAD5B0BAFEE5A6
p_9: 0N
p_10: 0N
p_11: 0N
',Rows=0,RowsAffected=1,lka=1,lkaid=10,lkato=0,Context=Форма.Записать : Документ.ЗаказКлиента.Форма.ФормаДокумента

********************************************************************************************************************************************************************
48:58.308002-843849,DBMSSQL,6,process=rphost,p:processName=My_Database_Name,OSThread=2360,t:clientID=6553,t:applicationName=1CV8C,t:computerName=my_pc,t:connectID=61336,SessionID=331639,Usr=Иванов И.И.,AppID=1CV8C,DBMS=DBMSSQL,DataBase=My_Database_Name,Trans=1,dbpid=90,Sql='UPDATE T1 SET _MessageNo = CAST(NULL AS NUMERIC(38,8))
FROM dbo._ReferenceChngR26488 T1
WHERE (T1._IDRRef = ? AND (T1._NodeTRef = 0x0000005A AND T1._NodeRRef IN (?))) AND (T1._Fld1420 = ?)
p_0: 0xA9C2001060A2672011DBFFF79783C8BB
p_1: 0x8CEE005056B09D4611EB2A5A6D45303C
p_2: 0N
',Rows=0,RowsAffected=1,lkp=1,lkpid=10,lksrc=73248,lkpto=0,Context='Форма.Записать : Документ.ЗаказКлиента.Форма.ФормаДокумента
Документ.ЗаказКлиента.МодульОбъекта : 914 : ПроведениеСерверУТ.ЗаписатьНаборыЗаписей(ЭтотОбъект);
	ОбщийМодуль.ПроведениеСерверУТ.Модуль : 355 : Объект.Движения.Записать();
		ОбщийМодуль.Б_ОбменССайтомСервер.Модуль : 190 : ЗарегистрироватьИзменения(Источник, Замещение);
			ОбщийМодуль.Б_ОбменССайтомСервер.Модуль : 594 : ПланыОбмена.ЗарегистрироватьИзменения(МассивУзловТовары, Запись.Номенклатура);'
********************************************************************************************************************************************************************

По предварительной оценке, на подобных ожиданиях мы теряем 1 секунду в час. Эта информация интересная, вернусь к ней позже.

 
 прилагаю разрешение на цитирование

 

технологический bash context регулярные Богачев grep egrep awk gawk cat sed print printf echo sort logcfg

См. также

Оптимизация нагрузки на ЦП сервера СУБД используя типовые индексы

HighLoad оптимизация Платформа 1С v8.3 Конфигурации 1cv8 Бесплатно (free)

Анализ простого плана запроса. Оптимизация нагрузки на ЦП сервера СУБД используя типовые индексы.

13.03.2024    3003    spyke    27    

42

Быстродействие типовой 1С

HighLoad оптимизация Платформа 1С v8.3 Бесплатно (free)

Оказывается, в типовых конфигурациях 1С есть, что улучшить!

13.03.2024    5124    vasilev2015    19    

37

Анализируем SQL сервер глазами 1С-ника

HighLoad оптимизация Инструменты администратора БД Платформа 1С v8.3 Конфигурации 1cv8 Абонемент ($m)

Обработка для простого и удобного анализа настроек, нагрузки и проблем с SQL сервером с упором на использование оного для 1С. Анализ текущих зааросов на sql, ожиданий, конвертация запроса в 1с и рекомендации где может тормозить

1 стартмани

15.02.2024    7664    159    ZAOSTG    68    

96

Удаление строк из таблицы значений различными способами с замером производительности

HighLoad оптимизация Платформа 1С v8.3 Конфигурации 1cv8 Абонемент ($m)

Встал вопрос: как быстро удалить строки из ТЗ? Рассмотрел пять вариантов реализации этой задачи. Сравнил их друг с другом на разных объёмах данных с разным процентом удаляемых строк. Также сравнил с выгрузкой с отбором по структуре.

09.01.2024    6003    doom2good    48    

63

Опыт оптимизации 1С на PostgreSQL

HighLoad оптимизация Бесплатно (free)

При переводе типовой конфигурации 1C ERP/УТ/КА на PostgreSQL придется вложить ресурсы в доработку и оптимизацию запросов. Расскажем, на что обратить внимание при потерях производительности и какие инструменты/подходы помогут расследовать проблемы после перехода.

20.11.2023    8888    ivanov660    6    

76

ТОП проблем/задач у владельцев КОРП лицензий 1С на основе опыта РКЛ

HighLoad оптимизация Бесплатно (free)

Казалось бы, КОРП-системы должны быть устойчивы, быстры и надёжны. Но, работая в рамках РКЛ, мы видим немного другую картину. Об основных болевых точках КОРП-систем и подходах к их решению пойдет речь в статье.

15.11.2023    5117    a.doroshkevich    20    

72

Начните уже использовать хранилище запросов

HighLoad оптимизация Запросы

Очень немногие из тех, кто занимается поддержкой MS SQL, работают с хранилищем запросов. А ведь хранилище запросов – это очень удобный, мощный и, главное, бесплатный инструмент, позволяющий быстро найти и локализовать проблему производительности и потребления ресурсов запросами. В статье расскажем о том, как использовать хранилище запросов в MS SQL и какие плюсы и минусы у него есть.

11.10.2023    16199    skovpin_sa    14    

98
Комментарии
В избранное Подписаться на ответы Сортировка: Древо развёрнутое
Свернуть все
1. Hatson 528 28.04.21 12:22 Сейчас в теме
3. vasilev2015 2687 28.04.21 13:45 Сейчас в теме
(1) Здравствуйте, Василий !

Краткость - сестра ! :-))
2. пользователь 28.04.21 12:42
Хорошая статья. Напишу немного информации. Интересно будет что скажите.

Вы, наверное, использовали этот скрипт для анализа:LOCKS
Он годится для более детального сбор данных. Обычно результаты загружаю в ClickHouse или PostgreSQL, чтобы потом делать более детальный анализ и ретроспективу тоже можно со старыми периодами сделать. Но на постоянной основе нереально его использовать, чаще для точечной диагностики или на ненагруженных базах.

Для постоянного мониторинга, чтобы минимум нагружать сервер, использую отчеты по блокировкам (вот оф. док)

С их помощью можно собирать информацию о дедлоках и ожиданиях на блокировках более 5 секунд (это настраивается). Объем информации намного меньше, но позволяет расследовать все основные проблемы с ожиданиями. Чтобы сопоставлять соединение с СУБД и сеанс 1С также отдельно собирают раз в минуту информацию о сеансах 1С. В большинстве случаев этого достаточно.

Вот пример скрипта настройки сбора отчетов по блокировкам с помощью Extended Events.

Событие dbmslocks в ТЖ стараюсь вообще не включать, потому что создает замедление в работе системы. По моему мнению это больше для расследования конкретной проблемы в указанный промежуток времени, но не для постоянного мониторинга.

Это один из подходов. Также есть еще некоторые способы мониторинга и диагностики, но комментарий и так уже большой получился. :)
vasilev2015; mirco; +2 Ответить
4. vasilev2015 2687 28.04.21 13:49 Сейчас в теме
(2) Здравствуйте, Юрий !

Спасибо, у Вас хорошие материалы. Часто пользуюсь.
5. ardn 622 28.04.21 19:01 Сейчас в теме
Николай, отличная статья. Вместе с тем вопросы:
Зачем вообще искали ошибки управляемых блокировок - ведь по тексту ошибки понятно, что это проблема SQL?
В анализе ожиданий у вас совсем нет CXPacket - MDOP на сервере равен 1 или просто этот тип ожиданий не учитываете?
6. vasilev2015 2687 28.04.21 19:18 Сейчас в теме
(5) Здравствуйте, Юрий !

Спасибо за одобрение.
Мне было интересно, почему отсутствуют управляемые блокировки.
К решению этой практической задачи я пришел постепенно,
проверял разные гипотезы, которые не вошли в статью.
Про задержки CXPacket буду уточнять.
7. Gilev.Vyacheslav 1910 29.04.21 10:10 Сейчас в теме
я так понимаю нормальным путём любой дурак сможет http://www.gilev.ru/latch/ так слишком легко...
8. vasilev2015 2687 29.04.21 10:40 Сейчас в теме
(7) Здравствуйте, Вячеслав !

У Вас неплохие сервисы и они имеют свою долю на рынке, но лично меня отталкивает,
для их использования необходимо вводить пароль от сервера СУБД в другую программу.
Думаю, если Вы измените этот порядок - будет больше клиентов.
Желаю удачи.
gabrielyants; +1 1 Ответить
9. Gilev.Vyacheslav 1910 29.04.21 15:05 Сейчас в теме
(8) 1. бесплатный сервис и доля на рынке... ну-ну
2. а вас не смущает что у клиентской части открытый код и видно что авторизация нужна для сбора трассировки и никуда дальше не передается, а код контролируете вы, а не мы
думаю если вы измените порядок, то у вас будет более результативная работа
Желаю удачи
efin; Дмитрий74Чел; +2 4 Ответить
10. bulpi 215 30.04.21 13:38 Сейчас в теме
(7)
Я использовал Ваш сервис, он мне помог, спасибо. Но если бы мне хватило мозгов, то сделал бы сам, так надежнее. Вот автор и сделал - ему хватило.
11. Gilev.Vyacheslav 1910 30.04.21 17:45 Сейчас в теме
(10) да я так и понял аргументов не будет почему не использовать бесплатные инструменты
просто делаешь людям добро, а не рубку бабок как некоторые, и в ответ "нате" - тихие минусы от альтернативноориентированных...
efin; Smilk; Дмитрий74Чел; toltec; itmind; maXon777; +6 2 Ответить
12. Smilk 27.05.21 19:17 Сейчас в теме
(11) Ваши инструменты помогают многим людям, но есть отдельные личности которые в профессиональном плане считают себя ровней с вами и сами хотят копать поэтому возможно предвзято относятся к вашим инструментам. Не нужно на них обижаться, другие ведь вам все равно благодарны.
13. buganov 200 23.08.21 09:17 Сейчас в теме
(12) А чем плохо самим копать? Мне вот, например, просто интересно порой под субботний вечер изобрести велосипед, лучше вникнуть, получить опыт
Apo; akR00b; +2 Ответить
14. Gilev.Vyacheslav 1910 14.09.22 15:36 Сейчас в теме
(13) ну копать это для самоудовлетворения, и использовать проверенное готовое решение это если нужен РЕЗУЛЬТАТ с приемлемой себестоимостью в приемлемое время
надо различать получение знание и применение знаний
Оставьте свое сообщение