Оптимизация 1С на реальном примере. История №2 — deadlock

Наверное, каждый из нас сталкивался (или столкнется) с проблемой взаимоблокировок (deadlock), это когда 1С настойчиво нам выдает сообщения вида: "Транзакция (идентификатор процесса XX) вызвала взаимоблокировку ресурсов блокировка с другим процессом и стала жертвой взаимоблокировки".

Вот и мне удостоилась честь столкнуться с этим феноменом. Обратился клиент, с жалобой на подобного рода сообщения. Раньше косвенно слышал об этом "звере", но никогда не погружался с головой.

Но кто когда идет читать специальную литературу сразу встретив проблему? Правильно, у нас есть проблема, и ее решение наверняка есть в интернете. Немного погуглив, я понял, что "причин может быть множество , а последствия могут быть разными" (с).
Первым что советуют в интернете посмотреть на статистику, индексы и итоги, однако все регламентные операции были настроены и успешно выполнялись по расписанию, итоги были актуальными.
Симптомы были ясны, но непонятно было с кем бороться. Поэтому было принято решение понять как анализировать взаимоблокировки, появилось несколько вариантов:
— Включение технологического журнала, и его ручной анализ вместе с трассировкой СУБД — очень сложно
— 1С:Центр управления производительностью (ЦУП) — дорого и сложно
— Сервисы Гилева http://www.gilev.ru/deadlock/ — бесплатно и просто, это кажется то, что нужно
Повозившись с настройкой, включил мониторинг на 15 минут в самый нагруженный момент времени. Вот что удалось словить:

Хорошо, дедлок словили, но что делать дальше с этой информацией? А теперь нам понадобится теория. Чтобы понять причину дедлока, нужно выяснить, какие таблицы были заблокированы, затем проанализировать код. Также желательно научиться воспроизводить взаимоблокировку, чтобы изучить ее подробнее.

• С помощью обработки СтруктураХраненияБазыДанных (или глобальный метод ПолучитьСтруктуруХраненияБазыДанных) выясняем, что _AccRgED652 это таблица РегистрБухгалтерии.Типовой.ЗначенияСубконто, а _AccRgAT2618 это РегистрБухгалтерии.Налоговый.ИтогиПоСчетамССубконто2.
• По времени процессов, и журналу регистрации выясняем, что проводились параллельно 2 документа: РеализацияТоваровУслуг и КомплектацияТМЗ. Также удалось смоделировать дедлок: проводим документ КомплектацияТМЗ под отладкой, ставим точку останова, параллельно проводим документ РеализацияТоваровУслуг, снимает точку останова и получаем ошибку. В обратном порядке ошибка не воспроизводится.

Теперь попробуем понять, что в итоге случилось:
Второй процесс строкой кода ОбщийМодуль.УправлениеЗапасамиПартионныйУчет.Модуль : 3383 читает остатки товаров из регистра бухгалтерии Типовой, а первый процесс строкой ОбщийМодуль.УправлениеЗапасамиПартионныйУчет.Модуль : 3664 читает остатки из регистра бухгалтерии Налоговый. На первый взгляд, ошибка "захват ресурсов в разном порядке". Но если проанализировать порядок вызова процедур из общего модуля по списанию товаров, то вроде как он одинаковый для всех документов (сначала упр. регистры, затем регистр по бух.учету, затем регистр по нал.учету). Хм, хорошо, анализируем код дальше, в этих запросах, по чтению остатков, нет конструкции "ДЛЯ ИЗМЕНЕНИЯ", которая позволила бы однозначно заблокировать остатки на чтение, казалось бы, добавляем ее в запросы, и дело в шляпе. Редактируем тексты запросов, блокируем данные на чтение, но чуда не случается, дедлок также устойчиво воспроизводится, причем оказывается и с другими документами, типа СписаниеТМЗ, ПеремещениеТМЗ и т.д. Таким образом проблема принимает глобальный характер. Заходим в тупик.
От безысходности делаются различные тестирования ИБ, пересчеты итогов и так далее, но уже на копии. От нее же, взор устремляется на свойство режим разделения итогов для регистров бухгалтерии, так как что-то было не так с остатками, были предположения что разделитель каким-либо образом "портит" запрос. Разделение итогов для регистров бухгалтерии было включено. Выключаем, проверяем. Что-то изменилось, а именно дедлока теперь нет, но транзакции ждут друг друга, и одна отваливается по таймауту (то есть не дождавшись освобождения ресурсов, один процесс освобождает свои ресурсы), deadlock заменился на ожидание на блокировке, но его суть осталась, раньше сервер СУБД явно видел такие ошибки, и пресекал их сразу, а теперь перестал. Что это нам дает? В общем-то не особо много, но есть инструмент для анализа ожиданий на блокировках в тех же сервисах Гилева http://www.gilev.ru/latch/, почему бы не попробовать, терять нечего.
Настраиваем, проводим опыты, ждем пока все данные будут обработаны.

Так, а здесь уже что-то новое. Расшифровка нам показывает ожидания в двух местах на таблице _AccumRg12498 (РегистрНакопления.ТоварыОрганизацийБУ), казалось бы причем здесь это, если проблемы были с регистрами бухгалтерии? Но может сервис что-то не то показывает, посмотрим код. В общем модуле НомераГТДСервер читаются остатки из вышеназванного регистра, но чтение также неблокирующее. Добавляем конструкцию "ДЛЯ ИЗМЕНЕНИЯ", тестируем — документы проводятся как надо, ожидание не заканчивается по таймауту. Неужели это оно? Но что-то не сходится, из сознания никак не выходит чувство того, что это костыль.
У нас еще одна строка с проблемой. Попробуем посмотреть что в общем модуле ПолныеПрава. Выполняется процедура ОпределитьНаличиеДвиженийПоРегистратору. Зачем она нужна и откуда вызывается? Запускаем отладку и ставим точку останова. Через Стек вызовов смотрим откуда вызывается эта процедура: ОбработкаПроведения -> ОбщегоНазначения.РучнаяКорректировкаОбработкаПроведения -> ОбщегоНазначения.УдалитьДвиженияРегистратора. Ага, перед началом проведения очищаются движения документа, а процедура нужна чтобы определить по каким регистрам проведен документ. Определяет она это следующим кодом:

Для Каждого Движение ИЗ МетаданнныеДокумента.Движения Цикл

Если счетчик_таблиц > 0 Тогда
счетчик_таблиц = счетчик_таблиц - 1;
Продолжить;
КонецЕсли;

ТекстЗапроса = ТекстЗапроса + "
|" + ?(ТекстЗапроса = "", "", "ОБЪЕДИНИТЬ ВСЕ ") + "
|ВЫБРАТЬ ПЕРВЫЕ 1 """ + Движение.ПолноеИмя() +  """ КАК Имя ИЗ "
+ Движение.ПолноеИмя() + " ГДЕ Регистратор = &Регистратор";

КонецЦикла;

Запрос.Текст = ТекстЗапроса;
Выборка = Запрос.Выполнить().Выбрать();

То есть читаем в транзакции и накладываем блокировку в самом ее начале, но зачем? Можно же безусловно записать пустые наборы по всем регистрам. Корректируем процедуру ОбщегоНазначения.УдалитьДвиженияРегистратора

//****Как было
// получение списка регистров, по которым существуют движения
//ТаблицаДвижений = ПолныеПрава.ОпределитьНаличиеДвиженийПоРегистратору(ДокументОбъект.Ссылка);

//****Как стало
//безусловно очищаем все регистры
ТаблицаДвижений = Новый ТаблицаЗначений;
ТаблицаДвижений.Колонки.Добавить("Имя");

Для Каждого Движение ИЗ ДокументОбъект.Метаданные().Движения Цикл
НоваяСтрока = ТаблицаДвижений.Добавить();
НоваяСтрока.Имя = Движение.ПолноеИмя();
КонецЦикла;

Дальше ТаблицаДвижений перебирается и производится запись пустых наборов, эту часть я не менял. Все предыдущие изменения откатываем. Итак, момент истины, пытаемся воспроизвести дедлок и он не происходит.
В следующие несколько дней изменения были сделаны на продуктивном сервере и производились измерения в часы активной нагрузки с помощью выше названных сервисов Гилева (также был использован сервис http://www.gilev.ru/status/ в качестве комплексного анализа).
Взаимоблокировки прекратились, но уверен что они еще возникнут, и были устранены лишь те, что лежали на поверхности. 
 

P.S Статья не является руководством, а отражает лишь личный опыт, который был новым и интересным.
Не рассмотрен вопрос о наложенных блокировках (инструмент Просмотр заблокированных строк в 1С) — какие были до изменения, какие стали, я их смотрел, но интерпретировать полноценно не смог.
Основной целью статьи является побудить молодых специалистов не бояться решать проблемы различного рода, несмотря на отсутствие должного опыта.
Конструктивная критика приветствуется.