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

Администрирование - Оптимизация БД (HighLoad)

38
Статья о том, как я расследовал взаимоблокировки (deadlock) в 1С.

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

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

 
 Сведения об исследуемой системе:

Сервер СУБД: MS SQL 2008R2
ОС: Windows Server 2008R2
ОЗУ: 32GB
ЦП: Intel Core i7
Дисковая подсистема: Raid 1 на HDD
Платформа: 8.3.7.1845
Режим совместимости: 8.2.13
Режим блокировок: Автоматический
Конфигурация: Управление торговым предприятием для Казахстана (аналог КА 1.1)
Пиковая загрузка: 20+ пользователей, + 30 торговых представителей постоянно обменивающихся информацией с ЦБ.
Объем БД: ~35GB

 
 Немного теории

Но кто когда идет читать специальную литературу сразу встретив проблему? Правильно, у нас есть проблема, и ее решение наверняка есть в интернете. Немного погуглив, я понял, что "причин может быть множество , а последствия могут быть разными" (с).
Первым что советуют в интернете посмотреть на статистику, индексы и итоги, однако все регламентные операции были настроены и успешно выполнялись по расписанию, итоги были актуальными.
Симптомы были ясны, но непонятно было с кем бороться. Поэтому было принято решение понять как анализировать взаимоблокировки, появилось несколько вариантов:
- Включение технологического журнала, и его ручной анализ вместе с трассировкой СУБД - очень сложно
- 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С) - какие были до изменения, какие стали, я их смотрел, но интерпретировать полноценно не смог.
Основной целью статьи является побудить молодых специалистов не бояться решать проблемы различного рода, несмотря на отсутствие должного опыта.
Конструктивная критика приветствуется.

38

См. также

Комментарии
Сортировка: Древо
1. PerlAmutor 28 11.06.18 06:43 Сейчас в теме
ОбщегоНазначения.РучнаяКорректировкаОбработкаПроведения -> ОбщегоНазначения.УдалитьДвиженияРегистратора

Как я понимаю это часть механизма БСП. Если по какой-то причине этот код вставили в обработку проведения значит есть какая-то проблема с движениями ручных корректировок. В момент проведения они, видимо, не должны очищаться. Предлагаю изучить этот вопрос детальней, иначе могут быть интересные последствия уже с остатками.
2. Dream_kz 75 11.06.18 07:30 Сейчас в теме
(1)
движениями ручных корректировок

В первой процедуре проверяется ручная корректировка, и если она есть, то процедура очищения движений не вызывается.
3. PerlAmutor 28 11.06.18 08:30 Сейчас в теме
(2) "В первой" это в какой, там где "ОБЪЕДИНИТЬ ВСЕ"? Если есть ручная корректировка, то вообще никакие движения не очищаются, или только движения ручной корректировки?
4. Dream_kz 75 11.06.18 08:55 Сейчас в теме
(3) ОбщегоНазначения.РучнаяКорректировкаОбработкаПроведения
5. pahalovo 11.06.18 09:10 Сейчас в теме
Не могу понять почему пропала взаимоблокировка.
Судя по статье, причина кроется в процедуре УдалитьДвиженияРегистратора. Когда определяем наличие движений по регистру устанавливается S блокировка, а когда записываем пустой набор записей устанавливается X блокировка.

Но УдалитьДвиженияРегистратора - это типовая процедура, во многих типовых конфигурациях встречается, которые работают себе без взаимоблокировок.
6. vasilev2015 661 11.06.18 20:09 Сейчас в теме
При автоматическом режиме блокировки очистка пустой таблицы блокирует всю таблицу исключительной блокировкой (SERIALIZABLE). Когда у меня возникла такая ситуация, я поставил исключения: не записывать конкретные регистры. Это было еще до того, как прочитал Е.Филипова "Настольная книга эксперта" )))
Попробуйте посмотреть в технологическом журнале, с помощью инструментов разработчика или в текстовом редакторе. Там подробнее.
7. Dream_kz 75 11.06.18 20:20 Сейчас в теме
(6) Так они и раньше записывались, просто до этого еще и читались.

не записывать конкретные регистры

Так если движения не очистим, запросы к остаткам буду "грязные", с учетом текущих движений, разве нет?
8. vasilev2015 661 12.06.18 10:53 Сейчас в теме
(7) в конфигурации УТ 10 часто используется очистка заведомо пустых регистров. Это недопустимо.
11. СергейК 51 13.06.18 13:39 Сейчас в теме
(8)
...очистка заведомо пустых регистров. Это недопустимо.

Т.е. так как сделал автор темы это не правильно? Но вроде стало то заметно лучше?
Может ли быть что критична версия платформы, и с какого то релиза
очистка пустых регистров не мешает по крайней мере (хотя стало мешать чтение...)?
9. o.nikolaev 228 13.06.18 10:42 Сейчас в теме
С автоматического режим блокировок надо уводить базу. Уйдут и взаимоблокировки и таймауты.
abadonna83; Somebody1; +2 Ответить
10. vursan 13.06.18 13:07 Сейчас в теме
Хм, это был типовой код. Почему же раньше все было норм и проводилось без дедлоков?
Оставьте свое сообщение