От экспертов «1С‑Рарус»: Блокировки на СУБД при масштабировании бизнеса. Подробно о блокировках MS SQL и PostgreSQL
От экспертов «1С‑Рарус»: Блокировки на СУБД при масштабировании бизнеса. Подробно о блокировках MS SQL и PostgreSQL

От экспертов «1С‑Рарус»: Блокировки на СУБД при масштабировании бизнеса. Подробно о блокировках MS SQL и PostgreSQL

28.03.2024
132 мин
3709

Описание экспертного случая

Одно крупное предприятие решило расширить свой бизнес, открыв десять новых подразделений. Для того чтобы мероприятие прошло успешно, руководство назначило единую дату и согласовало план.

В качестве учетной системы использовалась типовая конфигурация «1С:УНФ 8. Управление предприятием общественного питания» с некоторыми проектными доработками, а в качестве кассовых систем — «РестАрт ред. 3».

Из-за массовой и одновременной нагрузки на один блок у клиента возникли блокировки, с которыми они обратились к нам за помощью.

Описание экспертного случая

Что же такого сделали сотрудники, что пошли блокировки да и еще на уровне СУБД? Давайте разбираться.

Инфраструктура исследуемой системы

База данных: Microsoft SQL Server 2016.
Платформа 1С:Предприятие 8: 8.3.23.1782 64х.
Операционная система: Windows Server 2012 R2.
Процессор: Intel Xeon Silver 4210 CPU @ 2.2GHz.
Оперативная память: 256 GB.
SSD: 1.5 TB.

Программная инфраструктура клиента

Рис. Программная инфраструктура клиента

Схема возникновения блокировок и отключение эскалации блокировок для «скорой помощи» пользователям

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

Схема интеграции учетной и кассовых систем

Рис. Схема интеграции учетной и кассовых систем

Однако, как только один из сотрудников начал выгружать данные на кассу, а второй продолжал настраивать актуальное меню для другой кассы, система начала выдавать блокировки на методе ЗарегистрироватьИзменения. Попытки ручной регистрации или снятия регистрации изменений также приводили к ошибке:

Схема возникновения блокировок и отключение эскалации блокировок для «скорой помощи» пользователям

Примечание

Следует отметить, что при подключении к клиенту система мониторинга еще не была полностью настроена. Поэтому для устранения стоп-фактора первичные гипотезы и рекомендации были сформированы не на основе записей технологического журнала или трассы расширенных событий СУБД, а исключительно на понимании архитектуры этого блока. Что является скорее исключением в экспертных разборах.

В конфигурации «1С:УНФ 8. Управление предприятием общепита» есть два справочника, которые хранят товарные позиции, передаваемые на кассу: «Номенклатура» и «Меню». Справочник «Номенклатура» отвечает за учетную сущность, а «Меню» за то, как данная позиция будет выглядеть на кассе, как она будет распечатана в чеке и как она будет называться в бумажном меню. При этом, чтобы не было путаницы в данных, все позиции меню подчиняются элементам справочника «Виды меню».

Пример взаимосвязи между справочниками «Номенклатура», «Виды меню» и «Меню»

Рис. Пример взаимосвязи между справочниками «Номенклатура», «Виды меню» и «Меню»

Поскольку клиент вел учет в системе несколько лет, объем данных, которые необходимо передать, оказался значительным. Например, в справочнике «Номенклатура» было 1 миллион элементов, в «Виды меню» — 300, а в «Меню» — 3 миллиона.

Причем все эти элементы не просто архивные данные, а постоянно редактируемые позиции. Где-то название может измениться, где-то одно блюдо замениться на другое. Следовательно, в любой момент может зарегистрироваться большой объем данных для изменения.

Для хранения информации об измененных объектов в данной интеграции применяются стандартные таблицы изменений. Для сохранения ссылочной целостности в кассовой системе при изменении элементов выполняется регистрация и связанных с ними. Например, объектов владельцев, а также всех родителей по иерархии.

Пример регистрации элементов с помощью стандартной таблицы изменений
Рис. Пример регистрации элементов с помощью стандартной таблицы изменений

Тут под Кассами следует понимать узлы Плана обмена.

Такое поведение может приводить к блокировкам при одновременном изменении данных.

Пример конфликта транзакций при регистрации на стандартных таблицах изменений
Рис. Пример конфликта транзакций при регистрации на стандартных таблицах изменений

Потому в свое время мы реализовали специальный механизм отложенной регистрации. Согласно этому механизму, все такие изменения фиксируются сначала не в таблицы изменений, а в служебный регистр отложенных изменений (УОП_УдаленныеКассыРегистрация) без регистрации связанных элементов.

И только перед выполнением обмена система выполняет перенос зарегистрированных данных на таблицы изменений в едином потоке, дополняя связанными элементами.

Структура регистра УОП_УдаленныеКассыРегистрация

Рис. Структура регистра УОП_УдаленныеКассыРегистрация

Пример добавления меню при отложенной регистрации

Рис. Пример добавления меню при отложенной регистрации

Начиная с версии 8.3.19 в технологической платформе появилась возможность массовой регистрации данных к изменениям, что позволило повысить скорость выполнения методов «ЗарегистрироватьИзменения» и «УдалитьРегистрациюИзменений» за счет выполнения единой операции на уровне СУБД. А так как при «отложенной» регистрации возможен большой объем данных, то данное новшество было применено и в этом механизме.

Выдержка из документации

Рис. Выдержка из документации

Мы объединили факты наличия блокировок СУБД на таблицах изменений, массовой и параллельной регистрации данных к изменениям больших объемов, а также использование СУБД Microsoft SQL Server. Исходя из этого, мы предположили, что массовые операции могли спровоцировать эскалацию блокировок, которая, в свою очередь, вызвала ожидание при создании блокировки непересекающихся данных.

Эскалация блокировок — это специальный механизм СУБД, который позволяет уменьшить количество блокировок за счет фиксации намерений на создание более укрупненной блокировки. Этот механизм позволяет системе хранить блокировки не для каждой строки или страницы, а для всей таблицы, что в свою очередь уменьшает нагрузку на оборудование.

Существуют два признака необходимости включения эскалации блокировок: количество блокировок в одной операции превышает 5000 или превышается допустимый объем памяти, задаваемый с помощью параметра конфигурации locks. Если значение параметра locks равно 0, то допустимый объем памяти будет составлять 24% от памяти компонента Database Engine, если больше, то 40% от указанного значения.

В ходе анализа работы системы проблем с памятью обнаружено не было, но было обнаружено, что операции на создание 5000 и более блокировок могли привести к проблемам с производительностью. Поэтому для устранения стоп-фактора было предложено отключить эскалацию блокировок.

Чтобы это сделать необходимо запустить SQL Server Management Studio и выполнить запросы на отключение флагов трассировки 1224 и 1211.

DBCC TRACEON (1224, -1) ;
DBCC TRACEON (1211, -1) ;

Флаги трассировки:

  • 1224 позволяет отключить запуск эскалаций блокировок по количеству блокировок.
  • 1211 позволяет отключить эскалацию блокировок и по количеству, и по доступности памяти.

Важно!

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

Для избежания этого и их автоматического применения необходимо использовать параметры -T1224 и -T1211 командной строки в Windows или mssql-conf в Linux.

При использовании Windows для этого достаточно воспользоваться утилитой SQL Server Configuration Manager и выполнить следующие действия:

  • В левой панеле выбрать SQL Server Services.
  • В правой панели вызвать контекстном меню по службе SQL Server, а затем выбрать Properties (Свойства).

    Схема возникновения блокировок и отключение эскалации блокировок для «скорой помощи» пользователям

  • Перейти на вкладку Startup Parameters (Параметры запуска).
  • Написать -T1224 и выбрать Add (Добавить), а затем повторить аналогично с -T1211.

    Схема возникновения блокировок и отключение эскалации блокировок для «скорой помощи» пользователям

  • Сохранить по кнопке ОК и перезапустить службу сервера.

    Схема возникновения блокировок и отключение эскалации блокировок для «скорой помощи» пользователям

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

Поиск причин возникновения блокировок — анализ логов технологического журнала, комбинация массового изменения объектов в транзакции и поэлементной регистрации

Чтобы это сделать, мы настроили сбор технологического журнала по событиям DBMSSQL, а также расширенных событий (Extended events) по событиям lock_escalation, lock_timeout_greater_than_0, lock_acquired и blocked_process_report.

<?xml version="1.0" encoding="UTF-8"?>
<config xmlns="http://v8.1c.ru/v8/tech-log">
	<log history="24"
			location="ПутьКЛогамТЖ">
		<property name="all"/>
		<event>
			<eq property="name" value="DBMSSQL"/>
			<eq property="p:processName" value="ИмяБазы"/>		
		</event>
	</log>
</config>
CREATE EVENT SESSION [rarus_lock] ON SERVER 
ADD EVENT sqlserver.blocked_process_report(
    ACTION(sqlserver.sql_text)),
ADD EVENT sqlserver.lock_acquired(
    WHERE ([package0].[greater_than_uint64]([duration],(0)))),
ADD EVENT sqlserver.lock_escalation,
ADD EVENT sqlserver.lock_timeout_greater_than_0(
    ACTION(sqlserver.sql_text))
ADD TARGET package0.event_file(SET filename=N'ПутьККаталогуСЛогами')
WITH (MAX_MEMORY=4096 KB,EVENT_RETENTION_MODE=NO_EVENT_LOSS,MAX_DISPATCH_LATENCY=0 SECONDS,MAX_EVENT_SIZE=0 KB,MEMORY_PARTITION_MODE=NONE,TRACK_CAUSALITY=OFF,STARTUP_STATE=OFF)
GO

Поиск причин возникновения блокировок

После фиксирования очередного таймаута сбор материалов был остановлен.

Поиск причин возникновения блокировок

В собранной трассе расширенных событий lock_escalation не были обнаружены, что подтвердило отсутствие эскалации. Однако, lock_timeout_greater_than_0 были найдены.

Поиск причин возникновения блокировок

Это событие возникает при ожидании блокировок и содержит полезную информацию. В частности, id объекта (associated_object_id), на котором произошла блокировка, режим выполняемого запроса (mode), описание ресурса, на который накладывается блокировка (поля resource), тип ресурса (resource_type) и текст запроса (sql_text).

Поиск причин возникновения блокировок

По типу ресурса KEY мы обнаружили, что блокировка возникла на уровне ключа индекса, а по тексту запроса определили, что блокировка произошла при установке номера сообщения в таблице изменений ReferenceChngR21988.

В данном случае, таблица в тексте запросов одна. Однако, если бы их было несколько, то для определения таблицы, на которой произошла блокировка, при типе ресурса KEY, достаточно выполнить следующий запрос, заменив ИдОбъекта на значение поля associated_object_id.

SELECT 
    sc.name as schema_name, 
    so.name as object_name, 
    si.name as index_name
FROM sys.partitions AS p
JOIN sys.objects as so on 
    p.object_id=so.object_id
JOIN sys.indexes as si on 
    p.index_id=si.index_id and 
    p.object_id=si.object_id
JOIN sys.schemas AS sc on 
    so.schema_id=sc.schema_id
WHERE hobt_id = ИдОбъекта;
GO

Поиск причин возникновения блокировок

А если у данного события заполнено поле resource_description, то можно получить информацию о записях, на которых произошла блокировка, с помощью следующего запроса:

SELECT
    *
FROM dbo.ИмяТаблицы (NOLOCK)
WHERE %%lockres%% = '(ХэшКлюча)';
GO

Поиск причин возникновения блокировок

Чтобы определить объект в терминах 1С, мы использовали обработку получения структуры хранения метаданных, которая визуализирует результат выполнения платформенной функции ПолучитьСтруктуруХраненияБазыДанных().

В результате мы обнаружили, что таблица, на которой возникали блокировки, была таблицей изменений справочника «Виды меню».

Поиск причин возникновения блокировок

После определения таблицы, на которой произошли блокировки, мы перешли к поиску контекстов событий. Для этого нам понадобились логи технологического журнала, которые были преобразованы и загружены конфигурацией «1С-Рарус: Мониторинг производительности» в СУБД ClickHouse. Это позволило выполнять анализ не с помощью сложных регулярных выражений, а выполняя SQL-подобные запросы в его веб-интерфейсе Tabix.

Например, для поиска обращений к базе данных — события DBMSSQL — по ключевым фразам его текста запроса достаточно выполнить следующий запрос:

SELECT
*
FROM
default.mon_table
WHERE
_event = 'DBMSSQL'
and _time BETWEEN '2024-03-01 12:29:50' and '2024-03-01 12:30:00'
and sql LIKE '%dbo._ReferenceChngR21988%'
and sql LIKE '%UPDATE%'

В его результате мы получили все события с упоминанием таблицы изменений ReferenceChngR21988 в промежуток времени фиксации расширенного события lock_timeout_greater_than_0. Стоит отметить, что за отбираемые десять секунд система зафиксировала не ожидаемый один запрос на регистрацию, а далеко за сотню, что уже говорит о подозрительных действиях системы.

Поиск причин возникновения блокировок

Рассмотрев ряд событий мы пришли к выводу, что у них общий контекст, вызываемый из сторонней обработки «ХХХ_ФормированиеМенюПоОстаткам», с регистрацией через метод ЗарегистрироватьИзменения, а не через отложенный регистр и выполняемый в расширении клиента «ИсправлениеРегистрацииВидаМеню».

Поиск причин возникновения блокировок

Перейдя в расширение убеждаемся в наличии регистрации, которую добавили, возможно, не разобравшись с механизмом отложенной регистрации.

Поиск причин возникновения блокировок

Основываясь на новых фактах, мы можем предположить, что несколько пользователей одновременно редактировали состав одного элемента справочника «Виды меню». Система фиксировала запись элементов, пыталась зарегистрировать пересекающийся вид меню и выдавала ошибку. К сожалению, эта теория рушится из-за слишком частого воспроизведения. Ведь для этого бы потребовалось иметь либо очень невезучих пользователей, либо транзакции длительностью более 20 секунд.

В типовой версии продукта нет заполнения справочника вида меню, выполняющегося в явной транзакции. Запись поэлементно выполняется меньше, чем за секунду. Однако ранее мы уже отмечали, что код выполняется из сторонней обработки. Это навело нас на мысль, что разработчик мог выполнить массовое изменение объектов в явной транзакции. В чем мы и убедились, перейдя в начало обработки.

Поиск причин возникновения блокировок

И тут, как говорит главный герой Сергея Урсуляка: «Картина маслом». Сторонние разработчики внесли две корректировки: первая заключалась в формировании меню в рамках одной длительной транзакции, а вторая — в поэлементной регистрации. Соединив оба фактора, пользователи столкнулись с блокировками.

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

Теория возникновения блокировок MSSQL и PostgreSQL в связке с 1С

Что ж, от «полевых» работ перейдем в лабораторные условия. И попробуем посмотреть на блокировки СУБД под разными углами. Для экспериментов возьмем тестовый стенд — пустую серверную базу 1С на двух СУБД — MSSQL и PostgreSQL.

Теория возникновения блокировок MSSQL и PostgreSQL в связке с 1С

Все тесты проводим в условиях:

  • Платформа 1С:Предприятие 8: 8.3.23.1912 64х.
  • Базы данных Microsoft SQL Server 2019 и PostgreSQL 11.8.

Примечание: спасибо коллегам из 1С за статьи, позволившие легче разобраться с поставленными экспериментами:

  • its.1c.ru/db/metod8dev#content:6005:hdoc:problem12,
  • kb.1c.ru/articleView.jsp?id=124.

Попытка создать блокировку на СУБД

Для разминки рассмотрим классические случаи, когда у нас могут возникнуть конфликты двух и более транзакций.

Повышение уровня захвата ресурса

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

Чтобы воспроизвести этот случай — запускаем параллельно в двух сеансах одинаковые транзакции, в которых сначала происходит чтение набора записей, а через некоторую паузу запись того же набора:

НачатьТранзакцию();

РСНЗ = РегистрыСведений.РегистрСведений1.СоздатьНаборЗаписей();
РСНЗ.Отбор.Измерение1.Установить(Справочники.Справочник1.Элемент1);
РСНЗ.Прочитать();

//Пауза

РСНЗ.Записать();
	
ЗафиксироватьТранзакцию();

Как результат — получаем ошибку управляемой взаимоблокировки, до СУБД дело не дошло:

Теория возникновения блокировок MSSQL и PostgreSQL в связке с 1С

Поведение одинаково и на MS SQL и на PоstgreSQL.

Разный порядок записи

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

Запускаем параллельно в двух сеансах разные транзакции с записью двух наборов записей в разные регистры сведений с паузой между ним:

  1. В первой транзакции порядок записи:
    1. РегистрСведений1.
    2. РегистрСведений2.
  2. Во второй транзакции порядок записи:
    1. РегистрСведений2.
    2. РегистрСведений1.

Первая

НачатьТранзакцию();
РСНЗ = РегистрыСведений.РегистрСведений1.СоздатьНаборЗаписей();
РСНЗ.Отбор.Измерение1.Установить(Справочники.Справочник1.Элемент1);
РСНЗ.Записать();

//Пауза

РСНЗ = РегистрыСведений.РегистрСведений2.СоздатьНаборЗаписей();
РСНЗ.Отбор.Измерение1.Установить(Справочники.Справочник1.Элемент1);
РСНЗ.Записать();
ЗафиксироватьТранзакцию();

Вторая

НачатьТранзакцию();
РСНЗ = РегистрыСведений.РегистрСведений2.СоздатьНаборЗаписей();
РСНЗ.Отбор.Измерение1.Установить(Справочники.Справочник1.Элемент1);
РСНЗ.Записать();

//Пауза

РСНЗ = РегистрыСведений.РегистрСведений1.СоздатьНаборЗаписей();
РСНЗ.Отбор.Измерение1.Установить(Справочники.Справочник1.Элемент1);
РСНЗ.Записать();
ЗафиксироватьТранзакцию();

Получаем аналогичную ошибку управляемой взаимоблокировки:

Теория возникновения блокировок MSSQL и PostgreSQL в связке с 1С

Поведение также не зависит MS SQL/PоstgreSQL.

Эскалация

И последний эксперимент — таймаут при эскалации.

Для этого выполним в одном сеансе в транзакции запись 100001 элемента:

Запрос = Новый Запрос;
Запрос.Текст = 
"ВЫБРАТЬ ПЕРВЫЕ 100001
|	Справочник1.Ссылка КАК Ссылка
|ИЗ
|	Справочник.Справочник1 КАК Справочник1
|ГДЕ
|	Справочник1.Ссылка <> ЗНАЧЕНИЕ(Справочник.Справочник1.ЭлементДляЭскалации)";
РезультатЗапроса = Запрос.Выполнить();
ВыборкаДетальныеЗаписи = РезультатЗапроса.Выбрать();
НачатьТранзакцию();
Пока ВыборкаДетальныеЗаписи.Следующий() Цикл
	ВыборкаДетальныеЗаписи.Ссылка.ПолучитьОбъект().Записать();
КонецЦикла;

//Пауза

ЗафиксироватьТранзакцию();

А во втором параллельном сеансе запись одного элемента, исключенного из первой выборки:

Справочники.Справочник1.ЭлементДляЭскалации.ПолучитьОбъект().Записать();

Получаем обычную ошибку таймаута на управляемых блокировках:

Получаем обычную ошибку таймаута на управляемых блокировках

Какой из этого всего делаем вывод?

Во всех случаях в первую очередь срабатывал механизм управляемых блокировок платформы. Практически везде, где могут быть блокировки СУБД платформа подстраховала нас своими неявными управляемыми блокировками.

Таймаут СУБД на таблице изменений

Теперь попробуем реализовать «синтетический» случай таймаута на СУБД, аналогичный тому, что мы расследовали на практике выше. И покажем какими способами можно расследовать подобные проблемы. Хоть разработчики платформы и свели вероятность такой ошибки к минимуму, с ней всё же ещё можно столкнуться, или ещё чаще — имея дело со старыми версиями платформы, и нужно знать как их расследовать.

Возьмем простейший код регистрации изменений одного элемента справочника на один план обмена. Запускаем его в двух параллельных сеансах, с паузой более 20 сек перед завершением транзакции:

Узел = ПланыОбмена.ПланОбмена1.НайтиПоНаименованию("Тестовый узел");
НачатьТранзакцию();
ПланыОбмена.ЗарегистрироватьИзменения(Узел, Справочники.Справочник1.Элемент1);
//Пауза
ЗафиксироватьТранзакцию();

Ожидаемо ловим ошибку, в разных СУБД текст отличается:

  • В MSSQL:

    Конфликт блокировок при выполнении транзакции:
    Microsoft OLE DB Driver for SQL Server: Lock request time out period exceeded.
    HRESULT=80040E31, SQLSrvr: SQLSTATE=HYT00, state=33, Severity=10, native=1222, line=1
  • В PostgreSQL:

    Конфликт блокировок при выполнении транзакции:
    55P03: ERROR: canceling statement due to lock timeout
    CONTEXT: while updating tuple (1028,86) in relation "_referencechngr50"

Теперь получив ошибку в «пробирке» изучим её разными способами.

Исследование блокировок по трассе MS SQL

Если мы говорим про базы на MS SQL, то данную проблему можно расследовать с помощью трассировки Extended events.

В этом случае могут пригодиться следующие события:

  • blocked_process_report — возникает, когда задача была заблокирована на период времени больше указанного в настройке blocked_process_report.
  • lock_acquired — возникает при установке блокировки.
  • lock_timeout_greater_than_0 — возникает при ожидании другой блокировки.
  • lock_escalation — возникает при увеличении гранулярности блокировки, например, при преобразовании списка блокировок строк в блокировку таблицы целиком.

Таймаут СУБД на таблице изменений

Примечания по событию blocked_process_report

Как указано в описании, чтобы оно отрабатывало — необходимо в свойствах сервера в разделе Advanced установить параметр Blocked Process Threshold в число отличное от 0 секунд, по превышению которых будет сформировано событие. Минимальное значение = 5 секунд, мы для теста установили 10 секунд.

Таймаут СУБД на таблице изменений

Помимо этого, есть нюанс по настройке отборов. Во всех событиях мы устанавливали отбор по базе данных и все события попадали в трассировку за исключением blocked_process_report. После удаления отбора по базе данных событие blocked_process_report также удалось собрать.

Поэтому рекомендуем для события blocked_process_report не ставить отбор по базе.

Далее, чтобы можно было найти по результатам трассировки контекст кода 1С, нам нужно собрать лог технологического журнала, возьмем такую настройку:

<?xml version="1.0" encoding="UTF-8"?>
<config xmlns="http://v8.1c.ru/v8/tech-log">
 <log location="C:\TJlogs" history="1">
  <event>
   <eq property="name" value="SDBL"/>
   <eq property="p:processname" value="DBMS_locks"/>
  </event>
  <event>
   <eq property="name" value="DBMSSQL"/>
   <eq property="p:processname" value="DBMS_locks"/>
  </event>
  <event>
   <eq property="name" value="EXCP"/>
   <eq property="p:processname" value="DBMS_locks"/>
  </event>
  <event>
   <eq property="name" value="EXCPCNTX"/>
   <eq property="p:processname" value="DBMS_locks"/>
  </event>
  <property name="all"/>
 </log>
</config>

Запускаем трассировку и повторяем наш эксперимент с «генерацией» таймаута СУБД. В трассировке находим событие blocked_process_report:

Таймаут СУБД на таблице изменений

В событии blocked_process_report интересующая нас информация находится в поле blocked_process, открываем его и видим такой текст формата XML:

<blocked-process-report monitorLoop="4450314">
 <blocked-process>
  <process id="process20fd206dc28" taskpriority="0" logused="0" waitresource="KEY: 35:72057594109100032 (8469d4d722c1)" waittime="11079" ownerId="2016483383" transactionname="user_transaction" lasttranstarted="2024-03-17T15:43:12.010" XDES="0x20edba10428" lockMode="U" schedulerid="4" kpid="28548" status="suspended" spid="53" sbid="0" ecid="0" priority="0" trancount="2" lastbatchstarted="2024-03-17T15:43:12.017" lastbatchcompleted="2024-03-17T15:43:12.013" lastattention="1900-01-01T00:00:00.013" clientapp="1CV83 Server" hostname="srv-name" hostpid="66048" loginname="user" isolationlevel="read committed (2)" xactid="2016483383" currentdb="35" currentdbname="DBMS_locks" lockTimeout="20000" clientoption1="671221856" clientoption2="128056">
   <executionStack>
    <frame line="1" stmtstart="74" stmtend="402" sqlhandle="0x02000000fd48ff0cdcff6e012c9b266e5ca3cab86caf2f490000000000000000000000000000000000000000" />
    <frame line="1" sqlhandle="0x0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000" />
   </executionStack>
   <inputbuf>
(@P1 varbinary(16),@P2 varbinary(16))UPDATE T1 SET _MessageNo = CAST(NULL AS NUMERIC(38,8))
FROM dbo._ReferenceChngR50 T1
WHERE T1._IDRRef = @P1 AND (T1._NodeTRef = 0x00000031 AND T1._NodeRRef IN (@P2))   </inputbuf>
  </process>
 </blocked-process>
 <blocking-process>
  <process status="sleeping" spid="61" sbid="0" ecid="0" priority="0" trancount="1" lastbatchstarted="2024-03-17T15:43:08.943" lastbatchcompleted="2024-03-17T15:43:08.943" lastattention="1900-01-01T00:00:00.943" clientapp="1CV83 Server" hostname="srv-name" hostpid="66048" loginname="user" isolationlevel="read committed (2)" xactid="2016483342" currentdb="35" currentdbname="DBMS_locks" lockTimeout="20000" clientoption1="671221856" clientoption2="128056">
   <executionStack />
   <inputbuf>
(@P1 varbinary(16),@P2 varbinary(16))SELECT
T2._NodeTRef,
T2._NodeRRef
FROM dbo._ReferenceChngR50 T2
WHERE T2._IDRRef = @P1 AND T2._MessageNo IS NULL AND (T2._NodeTRef = 0x00000031 AND T2._NodeRRef IN (@P2))   </inputbuf>
  </process>
 </blocking-process>
</blocked-process-report>

Он разделен на две части:

  1. <blocked-process> — заблокированный процесс — по сути «жертва» в привычных терминах.
  2. <blocking-process> — блокирующий процесс, т. е. «виновник».

На что здесь стоит обратить внимание:

  • В обеих частях есть область тега <inputbuf> — текст запроса SQL, который выполнялся в момент блокировки.
  • Поля spid — означают номера соединений в СУБД жертвы и виновника.
  • В разделе заблокированного процесса есть поле waitresource = «KEY: 35:72057594109100032 (8469d4d722c1)».
    Его значение — это ресурс (строка таблицы или индекса), на котором «подрались» две транзакции.

Итак, у нас есть:

  1. Данные «жертвы»:
    1. Номер соединения= 53.
    2. Текст запроса SQL:
      (@P1 varbinary(16),@P2 varbinary(16))UPDATE T1 SET _MessageNo = CAST(NULL AS NUMERIC(38,8))
      FROM dbo._ReferenceChngR50 T1
      WHERE T1._IDRRef = @P1 AND (T1._NodeTRef = 0x00000031 AND T1._NodeRRef IN (@P2))
  2. Данные “виновника”:
    1. Номер соединения = 61.
    2. Текст запроса SQL:
      (@P1 varbinary(16),@P2 varbinary(16))SELECT
      T2._NodeTRef,
      T2._NodeRRef
      FROM dbo._ReferenceChngR50 T2
      WHERE T2._IDRRef = @P1 AND T2._MessageNo IS NULL AND (T2._NodeTRef = 0x00000031 AND T2._NodeRRef IN (@P2))

Поищем соответствующие события в собранных логах ТЖ. Нам нужны события DBMSSQL с определенным номером соединения и отбором по тексту запроса. Мы для простоты в качестве искомого текста возьмем только имя таблицы «_ReferenceChngR50».

Примечание

Примите во внимание, что в продуктивной базе такой отбор может быть недостаточным и выдать много строк, стоит добавить и другие уникальные части запроса и отбор по времени, сопоставив его с временем события blocked_process_report трассировки.

Для поиска событий в логах ТЖ воспользуемся следующими bash-скриптами.

Для поиска контекста жертвы:

cat *.log | awk -vORS= '{if(match($0, "^[0-9][0-9]\:[0-9][0-9]\.[0-9]+\-")) print "\n"$0; else print $0;}' | grep ',DBMSSQL,.*dbpid=53.*_ReferenceChngR50' | sed -e "s/\xef\xbb\xbf/ /g" | head > victim.txt

Для поиска контекста виновника:

cat *.log | awk -vORS= '{if(match($0, "^[0-9][0-9]\:[0-9][0-9]\.[0-9]+\-")) print "\n"$0; else print $0;}' | grep ',DBMSSQL,.*dbpid=61.*_ReferenceChngR50' | sed -e "s/\xef\xbb\xbf/ /g" | head > culprit.txt

В результате файл victim.txt содержит одно событие:

Таймаут СУБД на таблице изменений

Тем самым мы нашли контекст кода 1С «жертвы». На это также указывает характерная длительность события ~ 20 секунд.

Файл culprit.txt содержит два события:

Таймаут СУБД на таблице изменений

В них видим одинаковый контекст «виновника».

В целом, получив оба контекста, мы уже можем с чистой совестью идти в код конфигурации и разбираться с проблемой. Но с помощью поля waitresource можно также дополнительно определить, на какой конкретно строке случилась блокировка.

В нашем случае значение поля waitresource="KEY: 35:72057594109100032 (8469d4d722c1)". Оно состоит из нескольких частей:

  • KEY — в начале идет тип блокировки, в нашем случае это KEY — блокировка на уровне записи таблицы. Также здесь может быть значение PAGE — блокировка на уровне страницы.
  • 35 — database_id, внутренний идентификатор информационной базы.
  • 72057594109100032 — hobt_id, идентификатор кучи данных или дерева B-дерева, который содержит строки для этой секции.
  • (8469d4d722c1) — хэш строки таблицы.

По database_id мы можем определить имя базы данных простым запросом к таблице sys.databases:

SELECT 
    name 
FROM sys.databases 
WHERE database_id=35;

В нашем случае это база DBMS_locks:

Таймаут СУБД на таблице изменений

С помощью hobt_id можно получить имя таблицы, на данных которой случилась блокировка. Для этого нужно в контексте нашей БД выполнить запрос к служебным таблицам:

  • sys.partitions — содержит одну строку для каждой секции всех таблиц и большинства типов индексов базы данных.
  • sys.objects — содержит строку для каждого определенного пользователем объекта области действия схемы, созданного в базе данных, включая изначально скомпилированные скалярные пользовательские функции.
  • sys.indexes — cодержит строку для каждого индекса или кучи табличного объекта, такого как таблица, представление или функция с табличным значением.
  • sys.schemas — cодержит по одной строке для каждой схемы базы данных.
USE DBMS_locks;
SELECT 
    sc.name as schema_name, 
    so.name as object_name, 
    si.name as index_name
FROM sys.partitions AS p
JOIN sys.objects as so on 
    p.object_id=so.object_id
JOIN sys.indexes as si on 
    p.index_id=si.index_id and 
    p.object_id=si.object_id
JOIN sys.schemas AS sc on 
    so.schema_id=sc.schema_id
WHERE hobt_id = 72057594109100032 ;

Таймаут СУБД на таблице изменений

В нашем случае запрос ожидал на блокировке таблицы _ReferenceChngR50 при взаимодействии с индексом _ReferenceChngR50_2. С помощью метода ПолучитьСтруктуруХраненияБазыДанных() определяем, что это таблица изменений справочника Справочник1:

Таймаут СУБД на таблице изменений

Далее по хэшу (8469d4d722c1) найдем конкретную строку таблицы. Это можно сделать отобрав в найденной таблице его значение по виртуальной колонке %%lockres%%:

SELECT
    *
FROM _ReferenceChngR50 (NOLOCK)
WHERE %%lockres%% = '(8469d4d722c1)';

Таймаут СУБД на таблице изменений

Так как в нашем случае это таблица изменений, мы можем взять поле _IDRRef, то есть ссылку справочника «Справочник1» и получить по его значению ссылку 1С.

Таймаут СУБД на таблице изменений

Ссылочные поля имеют тип BINARY(16), нам нужно взять часть строки после префикса 0x и выполнить преобразование в уникальный идентификатор, далее по нему получим ссылку на элемент справочника:

СтрUUID = "8113002590A7FB1511EEDC6398BA28AE";
GUID = Прав(СтрUUID, 8) + "-" + Сред(СтрUUID, 21, 4) + "-" + Сред(СтрUUID, 17, 4) + "-" + Лев(СтрUUID, 4) + "-" + Сред(СтрUUID, 5, 12);
ЭлементСправочника = Справочники.Справочник1.ПолучитьСсылку(Новый УникальныйИдентификатор(GUID));

В нашем случае им оказался «Элемент1», который мы и использовали в коде:

ПланыОбмена.ЗарегистрироватьИзменения(Узел, Справочники.Справочник1.Элемент1)

Таймаут СУБД на таблице изменений

Исследование блокировок по логам ТЖ — элемент <dbmslocks>

Даже без привязки к конкретной СУБД платформа сама имеет средства для расследования блокировок СУБД. Существует возможность выводить дополнительные поля с информацией о блокировках СУБД в технологический журнал. Для этого необходимо добавить в настройку logcfg.xml специальный элемент <dbmslocks>.

Информация с ИТС

Элемент <dbmslocks> включает сбор информации о блокировках СУБД в технологическом журнале. Если элемент отсутствует в файле, то информация о блокировках СУБД не включается в технологический журнал.

Информация о блокировках СУБД отображается в технологическом журнале с помощью специальных свойств.

При любом обращении к СУБД, но не чаще чем 1 раз в 2 секунды, выполняется дополнительное обращение к СУБД с запросом, какой поток был заблокирован и каким потоком. Результатом такого запроса является таблица пар («жертва блокировки», «источник блокировки»), где:

  • Жертва блокировки ‑ идентификатор соединения с СУБД, которое ожидает блокировки.
  • Источник блокировки ‑ идентификатор соединения с СУБД, которое установило блокировку.

Если в кластере несколько рабочих процессов, то запрос выполняется одним из них. Запросы о взаимных блокировках нумеруются. Сбор информации о блокировках выполняется только в том случае, если в файле настройки технологического журнала присутствует элемент <dbmslocks>.

Данные из полученной таблицы добавляются к контексту каждого потока, которому соответствуют полученные идентификаторы соединений с СУБД, и будут отображены в качестве значения блокировочных свойств очередного события технологического журнала. После того как в потоке, к контексту которого добавлена информация о блокировках, будет завершено очередное событие технологического журнала, к этому событию будут добавлены блокировочные свойства. При этом если поток был жертвой блокировки, то события блокировки будут очищены после вывода. Если поток был источником, то очистка выполняется при закрытии или откате транзакции.

Информация о блокировках добавляется к потокам в следующем порядке:

  • Если поток-жертва еще не знает об этом, то ему устанавливается номер запроса и идентификатор потока-источника блокировки.
  • К потоку-источнику блокировки добавляется номер запроса, только если у него есть жертвы, которые об этом еще не знали.

Информация о блокировках:

  • поток является источником, момент обнаружения;
  • поток является жертвой, момент обнаружения;
  • номер запроса (если поток является жертвой);
  • список номеров запросов (если поток является источником);
  • номер соединения источника (если поток является жертвой).

Блокировочные свойства событий:

  • lka=‘1’ — поток является источником блокировки.
  • lkp=‘1’ — поток является жертвой блокировки.
  • lkpid — номер запроса к СУБД, «кто кого заблокировал» (только для потока-жертвы блокировки). Например, ‘423’.
  • lkaid — список номеров запросов к СУБД, «кто кого заблокировал» (только для потока-источника блокировки). Например, ‘271,273,274’.
  • lksrc — номер соединения источника блокировки, если поток является жертвой, например, ‘23’.
  • lkpto — время в секундах, прошедшее с момента обнаружения, что поток является жертвой. Например: ‘15’.
  • lkato — время в секундах, прошедшее с момента обнаружения, что поток является источником блокировок. Например, ‘21’.

Таким образом, для анализа блокировок необходимо найти в технологических журналах процессов rphost первое событие со свойствами lka и lkp, узнать значения свойств lkaid, lkpid и найти все события с этими значениями свойств в журналах всех рабочих процессов кластера. По найденной группе событий можно установить, кто кого заблокировал, на какое время и что они при этом делали.

Ищем блокировки

Для разнообразия возьмем аналогичную тестовую базу на PostgreSQL и настроим ТЖ с добавленным элементом <dbmslocks/>:

<?xml version="1.0" encoding="UTF-8"?>
<config xmlns="http://v8.1c.ru/v8/tech-log">
 <dump create="false"/>
  <log location="C:\TJlogs" history="1">
 <event>
   <eq property="name" value="SDBL"/>
   <eq property="p:processname" value="DBMS_locks_PostgreSQL"/>
  </event>
  <event>
   <eq property="name" value="DBPOSTGRS"/>
   <eq property="p:processname" value="DBMS_locks_PostgreSQL"/>
  </event>
  <event>
   <eq property="name" value="EXCP"/>
   <eq property="p:processname" value="DBMS_locks_PostgreSQL"/>
  </event>
  <event>
   <eq property="name" value="EXCPCNTX"/>
   <eq property="p:processname" value="DBMS_locks_PostgreSQL"/>
  </event>
  <property name="all"/>
 </log>
 <dbmslocks/>
</config>

Включаем ТЖ, снова повторяем наш эксперимент с двумя сеансами и ловим уже знакомую ошибку:

Исследование блокировок по логам ТЖ — элемент <dbmslocks>

Далее, как указано на ИТС, выбираем первые события с наличием полей lka и lkp, для этого выполняем команды bash:

  • Источник блокировки:
    cat *.log | awk -vORS= '{if(match($0, "^[0-9][0-9]\:[0-9][0-9]\.[0-9]+\-")) print "\n"$0; else print $0;}' | grep 'lka=' | sed -e "s/\xef\xbb\xbf/ /g" | head -n1 > lka.txt
  • Жертва блокировки:
    cat *.log | awk -vORS= '{if(match($0, "^[0-9][0-9]\:[0-9][0-9]\.[0-9]+\-")) print "\n"$0; else print $0;}' | grep 'lkp=' | sed -e "s/\xef\xbb\xbf/ /g" | head -n1  > lkp.txt

Файл lka.txt:

Исследование блокировок по логам ТЖ — элемент <dbmslocks>

Файл lkp.txt:

Исследование блокировок по логам ТЖ — элемент <dbmslocks>

Далее ищем все события с отбором по lkaid=’5,6’ и lkpid=5:

*.log | awk -vORS= '{if(match($0, "^[0-9][0-9]\:[0-9][0-9]\.[0-9]+\-")) print "\n"$0; else print $0;}' | grep "lkaid='5,6'" | sed -e "s/\xef\xbb\xbf/ /g" > lka_all.txt
cat *.log | awk -vORS= '{if(match($0, "^[0-9][0-9]\:[0-9][0-9]\.[0-9]+\-")) print "\n"$0; else print $0;}' | grep "lkpid=5" | sed -e "s/\xef\xbb\xbf/ /g" > lkp_all.txt

Исследование блокировок по логам ТЖ — элемент <dbmslocks>

В файле lka_all.txt видим три события с одинаковым контекстом, в том числе событие компиляциии запроса SDBL с длительностью 26,5 сек., запрос которого является источником блокировки.

В файле lkp_all.txt видим только одно событие, то же самое, что было в файле lkp.txt, это и есть «жертва» блокировки с контекстом:

Исследование блокировок по логам ТЖ — элемент <dbmslocks>

Как итог — мы нашли контексты обеих сторон. Кажется, этого должно быть достаточно для анализа и разбора проблемы.

Исследование блокировок по логам PostgreSQL

Если мы имеем дело с базами на PostgreSQL, то для расследования блокировок можно воспользоваться логами СУБД. В этом случае нам нужно обратить внимание на следующие параметры в файле postgresql.conf (подробнее можно почитать в документации postgrespro.ru/docs/postgrespro/11/runtime-config-logging):

  • log_lock_waits — определяет нужно ли фиксировать в журнале события, когда сеанс ожидает получения блокировки дольше, чем указано в deadlock_timeout.
    По-умолчанию отключено.
  • log_statement — управляет тем, какие SQL-команды записывать в журнал. Допустимые значения: none (отключено), ddl, mod и all (все команды).
  • log_line_prefix — строка в стиле функции printf, которая выводится в начале каждой строки журнала сообщений.

В нашем случае настройки ставим следующие:

  • log_lock_waits = on.
  • log_statement = all — будьте осторожны, на продуктиве с такой настройкой логов может быть много.
  • log_line_prefix = ’%m [%p] %q%u@%d %x’ - из важных параметров здесь %p — id процесса, %d — имя базы данных, %x — id транзакции.

Для привязки логов к контексту кода 1С также включаем сбор лога технологического журнала:

<?xml version="1.0" encoding="UTF-8"?>
<config xmlns="http://v8.1c.ru/v8/tech-log">
 <log location="C:\TJlogs" history="1">
  <event>
   <eq property="name" value="SDBL"/>
   <eq property="p:processname" value="DBMS_locks"/>
  </event>
  <event>
   <eq property="name" value="DBPOSTGRS"/>
   <eq property="p:processname" value="DBMS_locks"/>
  </event>
  <event>
   <eq property="name" value="EXCP"/>
   <eq property="p:processname" value="DBMS_locks"/>
  </event>
  <event>
   <eq property="name" value="EXCPCNTX"/>
   <eq property="p:processname" value="DBMS_locks"/>
  </event>
  <property name="all"/>
 </log>
</config>

Далее генерируем нашу стендовую блокировку, и получаем уже такую родную ошибку:

Исследование блокировок по логам ТЖ — элемент <dbmslocks>

Для начала найдем в наших логах PostgreSQL сообщения, относящиеся к нашей базе и с текстом ошибки «canceling statement due to lock timeout». Для этого воспользуемся следующим bash-скриптом:

cat *.log | awk -vORS= '{if(match($0, "^[0-9][0-9][0-9][0-9]\-[0-9][0-9]\-[0-9][0-9] [0-9][0-9]\:[0-9][0-9]\:[0-9][0-9]\.[0-9]+")) print "\n"$0; else print $0;}' | grep "DBMS_locks_PostgreSQL.*canceling statement due to lock timeout" -A 3 | sed -e "s/\xef\xbb\xbf/ /g" > lock_timeout.txt

Исследование блокировок по логам ТЖ — элемент <dbmslocks>

Обратите внимание, как интересно логируются события: ошибка отдельно, контекст ошибки отдельно, запрос отдельно.

Из этих строк узнаем данные «жертвы» — id процесса указан в квадратных скобках — 1207, а в строке STATEMENT находим текст запроса SQL.

Далее найдем событие ожидания блокировки связанное с найденным процессом, ищем строки с текстом «still waiting for ShareLock», захватывая следующие:

cat *.log | awk -vORS= '{if(match($0, "^[0-9][0-9][0-9][0-9]\-[0-9][0-9]\-[0-9][0-9] [0-9][0-9]\:[0-9][0-9]\:[0-9][0-9]\.[0-9]+")) print "\n"$0; else print $0;}' | grep "1207.*DBMS_locks_PostgreSQL.*still waiting for ShareLock" -A 3 | sed -e "s/\xef\xbb\xbf/ /g" > still_waiting.txt

Исследование блокировок по логам ТЖ — элемент <dbmslocks>

Узнаем из строк:

  • «process 1207 still waiting for ShareLock on transaction 454151499» — id транзакции виновника 454151499.
  • «Process holding the lock: 31950. Wait queue: 1207.» — id процесса виновника 31950.

По ним найдем в логах события виновника:

cat *.log | awk -vORS= '{if(match($0, "^[0-9][0-9][0-9][0-9]\-[0-9][0-9]\-[0-9][0-9] [0-9][0-9]\:[0-9][0-9]\:[0-9][0-9]\.[0-9]+")) print "\n"$0; else print $0;}' | grep "31950.*DBMS_locks_PostgreSQL" | grep "454151499" -A 3 -B 3| sed -e "s/\xef\xbb\xbf/ /g" > log_culprit.txt

Исследование блокировок по логам ТЖ — элемент <dbmslocks>

Здесь мы можем увидеть два текста запроса SQL виновника блокировки.

Теперь, как и в случае расследования по трассе MSSQL, отберем события из технологического журнала по найденным dbpid и тексту запроса жертвы и виновника:

  • События жертвы:
    cat *.log | awk -vORS= '{if(match($0, "^[0-9][0-9]\:[0-9][0-9]\.[0-9]+\-")) print "\n"$0; else print $0;}' | grep ',DBPOSTGRS,.*dbpid=1207.*_ReferenceChngR50' | sed -e "s/\xef\xbb\xbf/ /g" | head > victim.txt
  • События виновника:
    cat *.log | awk -vORS= '{if(match($0, "^[0-9][0-9]\:[0-9][0-9]\.[0-9]+\-")) print "\n"$0; else print $0;}' | grep ',DBPOSTGRS,.*dbpid=31950.*_ReferenceChngR50' | sed -e "s/\xef\xbb\xbf/ /g" | head > culprit.txt

Тем самым находим контекст жертвы:

Исследование блокировок по логам ТЖ — элемент <dbmslocks>

И контекст виновника:

Исследование блокировок по логам ТЖ — элемент <dbmslocks>

На этом самая легкая часть завершена и можно приступить к анализу кода 1С на предмет исправления. Удачи!

Заметка про эскалацию СУБД

В наших изысканиях мы также попытались воспроизвести ошибку таймаута, связанную с эскалацией блокировок СУБД. Как мы уже писали выше, при стандартных настройках эскалация СУБД на таблице должна возникать при достижении 5000 блокировок. Поэтому для эксперимента мы в одном сеансе взяли 10000 элементов справочника, за исключением специального элемента «ЭлементДляЭскалации», и регистрировали их в одной транзакции с паузой перед завершением.

При достижении паузы в другом сеансе выполняли код регистрации изменений элемента «ЭлементДляЭскалации».

Выполнялся следующий код.

В первом сеансе:

Узел = ПланыОбмена.ПланОбмена1.НайтиПоНаименованию("Тестовый узел");
Запрос = Новый Запрос;
Запрос.Текст = 
"ВЫБРАТЬ ПЕРВЫЕ 10000
|  Справочник1.Ссылка КАК Ссылка
|ИЗ
|  Справочник.Справочник1 КАК Справочник1
|ГДЕ
|  Справочник1.Ссылка <> ЗНАЧЕНИЕ(Справочник.Справочник1.ЭлементДляЭскалации)";
	
РезультатЗапроса = Запрос.Выполнить();
ВыборкаДетальныеЗаписи = РезультатЗапроса.Выбрать();
МассивСсылок = Новый Массив;
Пока ВыборкаДетальныеЗаписи.Следующий() Цикл
  МассивСсылок.Добавить(ВыборкаДетальныеЗаписи.Ссылка);
КонецЦикла;
  
НачатьТранзакцию();
	
ПланыОбмена.ЗарегистрироватьИзменения(Узел , МассивСсылок);
//Пауза
ЗафиксироватьТранзакцию();

Во втором сеансе:

Узел = ПланыОбмена.ПланОбмена1.НайтиПоНаименованию("Тестовый узел");
ПланыОбмена.ЗарегистрироватьИзменения(Узел, Справочники.Справочник1.ЭлементДляЭскалации);

И к нашему удивлению — эскалации не происходило.

Что может влиять на использование эскалации? В первую очередь флаги трассировки 1211 и 1224, мы о них уже упоминали. Из документации (learn.microsoft.com/ru-ru/sql/t-sql/database-console-commands/dbcc-traceon-trace-flags-transact-sql?view=sql-server-ver15) :

  • 1211 — отключает укрупнение блокировки, основанное на слишком активном использовании памяти или на количестве блокировок.
  • 1224 — отключает укрупнение блокировок на основе количества блокировок. Однако слишком активное использование памяти может включить укрупнение блокировок.

Проверили их состояние с помощью команды:

DBCC TRACESTATUS (1224, 1211)

Заметка про эскалацию СУБД

В нашей базе флаги были не включены.

Следующий пункт проверки — настройки эскалации на уровне таблиц. Их можно посмотреть, выполнив следующий запрос в контексте нужной базы:

USE DBMS_locks;
SELECT top 100 lock_escalation, lock_escalation_desc, name FROM sys.tables

Заметка про эскалацию СУБД

В нашем случае на большинстве таблиц, в том числе на таблице _ReferenceChngR50 — таблице регистрации изменений справочника «Справочник1», был указан режим DISABLE, то есть эскалация оказалась отключена.

Как мы выяснили позже — это связано с версией платформы. При реструктуризации базы на более ранних релизах в таблицах указывался режим AUTO/TABLE:

Заметка про эскалацию СУБД

Чтобы убедиться в том, что это зависит от платформы, мы настроили трассировку Extended events по событиям sql_batch_complited:

Заметка про эскалацию СУБД

И увидели, что с некоторого релиза в текст запроса создания таблицы стала добавляться дополнительная команда установки режима эскалации = DISABLE.

Заключение

Давайте попытаемся сделать выводы.

Прежде всего заметим, что знания это и вправду — сила. Вот уж кажется и не встретишь более никаких блокировок на СУБД, ан нет — вот они красуются. И в этот момент нельзя сказать «как же так, мы так не договаривались», надо решать задачу. Поэтому не напрасно преподается этот раздел на курсах, экзаменуется на «Эксперте». Реальная жизнь эксперта богаче ожиданий.

Основа эффективного расследования — это построение гипотез и их отработка. Так, в нашем случае для быстрого купирования боли, нам удалось построить сильную гипотезу об эскалациях, чтобы снять болевой синдром и приступить к плановой части операции.

Кроме этого заметим, что теперь следует в обязательном порядке знать и понимать подходы, применяемые как на MS SQL так и на PostgreSQL, а они совершенно различны. И, конечно, знания bash-скриптов чрезвычайно важны, даже если у вас есть под рукой мощные инструменты. Например, мы быстро расследовали логи PostgreSQL.

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

Авторы статьи

Гримута Артем
Гримута Артем
Борисенко Станислав
Борисенко Станислав
Вы читаете статью из рубрики:
От экспертов «1С-Рарус»

Есть вопросы по статье? Задайте их нам!

Рассылка «Новости компании»: узнавайте о новых продуктах, услугах и спецпредложениях

Посмотреть все рассылки «1С‑Рарус»

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

Посмотреть все рассылки «1С-Рарус»

Иконка «Предупреждение» Отправляя эту форму, Вы соглашаетесь с Политикой конфидециальности и даете согласие на обработку персональных данных компанией «1С-Рарус»

Заинтересованы в сотрудничестве?
Нужна консультация?
Свяжитесь с нами!