ЧТО ТАКОЕ TTIMEOUT 1С:ПРЕДПРИЯТИЯ И КАК ЕГО НАЙТИ?
В этой статье мы поговорим о том, что такое таймаут на управляемых блокировках 1С:Предприятия и как расследовать причины его возникновения.
При управляемом режиме , помимо управляемых блокировок 1С:Предприятия, на стороне СУБД в этот самый момент могут действовать также свои блокировки СУБД, обеспечивая изоляцию на более низком уровне. Блокировки СУБД при этом, в общем случае, осуществляются на «запись» таблицы. В отдельных ситуациях, однако, СУБД может посчитать необходимым заблокировать и таблицу целиком.
Мы не затрагиваем описание уровня изоляции транзакций и вида блокировок в автоматическом режиме блокировок 1С:Предприятия, когда целостность и непротеворечивость данных полностью возлагается на СУБД, что обеспечивается высоким уровнем изоляции на самой СУБД и, как следствие — низкой параллельностью работы пользователей.
1. Что видит пользователь? Конфликт блокировки при выполнении транзакции.
2. Что на самом деле происходит?
3. Где указывается время ожидания освобождения управляемой блокировки 1С:Предприятия?
4. Что будет в технологическом журнале? Парсим технологический журнал в поисках таймаута.
Что видит пользователь?
Пользователь видит ошибки:
1 2 3 |
Конфликт блокировки при выполнении транзакции Превышено максимальное время ожидания предоставления блокировки. |
Данное сообщение – сообщение о таймауте на управляемых блокировках 1С:Предприятия.
Что на самом деле происходит?
Если упрощённо:
Данный сеанс попытался «использовать» пространства таблиц базы данных, которые уже заняты другим пользователь.
У него было некоторое время , чтобы дождаться освобождения этих ресурсов.
Не дождавшись освобождения – действие пользователя прерывается и он видит вышеописанную ошибку.
Надо отметить, что таймаутом называется именно событие, когда блокировка уже не дождалась ресурсов и была прервана по времени, указанному в настройках 1С:Предприятия.
А ожидание на управляемой блокировке не всегда обязательно заканчивается таймаутом. Возможно, соединение дождалось все таки освобождения требуемых ресурсов.
Блокировка – это информация о том, что данные ресурсы «заняты» и не могут быть использованы другой транзакцией.
ВАЖНО: ВНЕ ТРАНЗАКЦИИ БЛОКИРОВКИ НЕТ!!!
Где указывается время ожидания освобождения управляемой блокировки 1С:Предприятия?
Интервал этого времени ожидания освобождения управляемой блокировки указывается в конфигураторе информационной базы и по умолчанию составляет 20 секунд.
Как настроить технологический журнал для сбора событий и ошибок по управляемым блокировкам?
Файл настройки технологического журнала обычно общий и для расследования как таймаутов, так и взаимоблокировок:
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 |
<?xml version="1.0" encoding="UTF-8"?> <config xmlns="http://v8.1c.ru/v8/tech-log"> <log location="/var/log/e1c/locklogs" history="1"> <event> <eq property="name" value="TLOCK"/> </event> <event> <eq property="name" value="TDEADLOCK"/> </event> <event> <eq property="name" value="TTIMEOUT"/> </event> <property name="all"/> </log> </config> |
С помощью этого журнала будут собираться следующие события технологического журнала, относящиеся исключительно к УПРАВЛЯЕМЫМ блокировкам 1С:Предприятия.
TTIMEOUT – превышение времени ожидания блокировки.
TLOCK – управление(установка/снятие) блокировками.
TDEADLOCK – обнаружена взаимоблокировка.
Важно отметить, что, если события TTIMEOUT и TDEADLOCK являются показателем некорректной работы системы и в нормальной ситуации появляться в журнале не должны. То TLOCK — это обычная работа системы и таких событий в журнале будет очень много.
Поэтому сбор TLOCK рекомендуется включать на короткое время для расследования таймаутов, ожиданий на блокировках и взаимоблокировок. И выключать сразу после получения нужной информации.
В качестве мониторинга можем рекомендовать настроить следующий журнал:
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 |
<?xml version="1.0" encoding="UTF-8"?> <config xmlns="http://v8.1c.ru/v8/tech-log"> <log location="/var/log/e1c/locklogs" history="24"> <event> <eq property="name" value="TLOCK"/> <ge property="Durationus" value="15000000"/> </event> <event> <eq property="name" value="TDEADLOCK"/> </event> <event> <eq property="name" value="TTIMEOUT"/> </event> <property name="all"/> </log> </config> |
Таким образом мы собираем все взаимоблокировки, таймауты и собираем только длительные блокировки, длительность более 15 секунд.
При анализе такого журнала мы не сможем увидеть виновника ожидания или взаимоблокировки. Его блокировка установилась, скорее всего, быстро и в записи журнала не попадет по фильтру >15сек. Но сможем проанализировать на каких пространствах возникла проблема.
Вместо фильтра по длительности можно использовать фильтр по заполненности свойства, указывающего на ConnectionID блокировки, которое заставила ожидать текущую блокировку(WaitConnections).
1 |
<ge property="WaitConnections" value="1"/> |
Что будет в технологическом журнале? Парсим технологический журнал в поисках таймаута.
Последовательность событий в технологическом журнале будет следующая:
1 2 3 4 |
TLOCK виновника // другие TLOCK, или их отсутствие TTIMEOUT TLOCK жертвы |
Приведём пример реального анализа из технологического журнала.
1. Ищем таймауты (TTIMEOUT).
Регулярное выражение поиска таймаута.
1 2 3 4 5 |
cat /var/log/e1clogs/rphost_*/*.log | tr -d '\r' | awk -vORS= '{if(match($0, "^[0-9][0-9]:[0-9][0-9].[0-9]+-")) print "\n"$0; else print "#1s-on#" $0;}' | grep ',TTIMEOUT,' | sed -e "s/#1s-on#/\n /g" |
2. Ищем TLOCK от найденного в п.1 таймаута — жертва. Это TLOCK, который платформа наложить не смогла. Другими словами это регистрация в технологическом журнале неуспешной попытки.
Регулярное выражение поиска TLOCK по ID соединения(фиолетовый маркер) и ID ожидания(красный маркер).
1 2 3 4 5 |
cat /var/log/e1clogs/rphost_*/*.log | tr -d '\r' | awk -vORS= '{if(match($0, "^[0-9][0-9]:[0-9][0-9].[0-9]+-")) print "\n"$0; else print "#1s-on#" $0;}' | grep ',TLOCK,.*t:connectID=605730.*WaitConnections=604620' | sed -e "s/#1s-on#/\n /g" |
Где будет данное событие? Правильно! Сразу после относящегося к нему события TTIMEOUT.
Отсюда мы узнаем за какой ресурс конфликтуют блокировки (зеленый маркер).
Стоит отметить, что с блокировкой уровня Exclusive не будет совместима ни блокировка Exclusive, ни блокировка уровня Shared.
По длительности самого события также видно, что блокировка ожидала освобождения ресурсов 20 002010 мкс, то есть более 20 секунд.
3. Ищем предыдущий по времени TLOCK, конфликтующий по тем же условиям (Regions, Locks) и ID соединения, которого будет соответствовать ID ожидания(красный маркер) нашего таймаута — виновник.
1 2 3 4 5 |
cat /var/log/e1clogs/rphost_*/*.log | tr -d '\r' | awk -vORS= '{if(match($0, "^[0-9][0-9]:[0-9][0-9].[0-9]+-")) print "\n"$0; else print "#1s-on#" $0;}' | grep ',TLOCK,.*t:connectID=604620.*InfoRg4128.DIMS' | sed -e "s/#1s-on#/\n /g" |
Данное событие будет, как вы понимаете:
- ДО расследуемого TTIMEOUT
- НО максимально ближнее к расследуемому TTIMEOUT.
Также обращаем внимание на поля :Fld… Чтобы понять на каких полях произошло пересечение блокировки. В нашем случае — это полное совпадение полей блокировки.
Но возможны ситуации, когда в пространствах блокировки — можно увидеть меньше полей (1, 2 и тд) что свидетельствует о избыточной блокировки виновника, которая блокирует также все остальные поля записи.
Таким образом мы нашли источник, жертву и ресурс из-за которого возник таймаут.
4. С помощью метода ПолучитьСтруктуруХраненияБазыДанных() или обработок, использующих данный метод – определяем как называется на языке метаданных 1С объект, который стал причиной таймаута.
5. По контексту ищем в коде причину таймаута и устраняем.
Еще можно посмотреть
История одного конфликта блокировок 1С
В определенный момент времени, пользователи информационной базы, которые ранее работали без проблем — начали жаловаться на возникновение ошибок при записи элемента справочника. В нашем распоряжении оказались скрины и тексты ошибок, переданные пользователями. Без возможности самостоятельного воспроизведения проблемы в этой или каких-либо других тестовых базах данных. 1. Знакомимся с текстами ошибок. 2. Парсим технологический журнал 1С […]
Настройка и сбор логов для анализа проблем производительности систем 1С на Linux
Для осуществления мониторинга за качеством работы систем на базе 1С, а также для анализа проблем с производительностью, необходимо уметь настраивать сбор логов, дампов. Настройка сбора логов 1С под Linux имеет ряд особенностей. О них мы и поговорим в данной статье. Описание приводится для ОС Linux дистрибутивов RHEL/CentOS 7. 1. Как настроить и включить технологический журнал […]
Анализ технологического журнала 1С регулярными выражениями. От простого к сложному.
Что делать, если у пользователя возникают ошибки, «все тормозит» или возникают другие неясные проблемы, а разработчик не знает где искать проблему в коде? С этой статьи мы начинаем нашу рубрику по расследованию проблем производительности и стабильности работы систем на базе 1С:Предприятия. Речь пойдет о реальных примерах анализа технологического журнала 1С экспертами с помощью регулярных выражений. […]
1C тормозит и возникают ошибки. С чего начать расследование?
Когда мы читаем о том, как настраивать и анализировать технологический журнал 1С на предмет «узких» мест, мы не всегда представляем себе, что это отнюдь не первое, что нужно сделать, когда сталкиваемся с падением производительности и стабильности работы системы. Прежде чем «бросаться» собирать технологический журнал и его парсить, изначально рекомендуется провести первичный сбор информации о проблеме: […]
ЧТО ТАКОЕ PG_TEMP В POSTGRESQL ДЛЯ 1С И КТО ИХ СОЗДАЕТ?
pg_temp — это пространство СУБД PostgreSQL для временных таблиц, то есть таблиц, существующих в пределах жизни одного соединения (в терминах СУБД) или сеанса (в терминах кластера 1С). Такие таблицы мы можем увидеть в тексте запроса СУБД, если в запросе на языке запросов 1С присутствует конструкция ПОМЕСТИТЬ, которая и помещает выборку во временную таблицу. Таким образом […]
Технологический журнал 1С и бесконечный цикл в коде 1С
Несмотря на то, что проблема в статье История одного конфликта блокировок 1С , казалось, была решена, ее повторное появление не заставило себя долго ждать. Пользователь Лапкина вновь приступила к работе и ее сеанс снова парализовал работу пользователей системы с блокируемым справочником. Описание ошибки: Пользователь создает элемент справочника и при записи система 1С:Предприятия «повисает». Сеанс закрывается пользователем, […]
Пропажа индексов дескрипторов в 1С:Документообороте
Пользователи копии продуктивной базы начали жаловаться на полное падение производительности в 1C:Документообороте на PostgresPro Enterprise + Linux. С их слов 1С сильно тормозила и это проявлялось везде: при входе в базу, открытии документов, списков, справочников, задач. При анализе происходящего из консоли администрирования 1С в момент запуска системы видим, что зависание начинается в момент обращения к […]
Похожие записи
- ОШИБКА 1С:ПРЕДПРИЯТИЯ «ПОТЕРЯНО СОЕДИНЕНИЕ»
- ЧТО ТАКОЕ PG_TEMP В POSTGRESQL ДЛЯ 1С И КТО ИХ СОЗДАЕТ?
- НАСТРОЙКА PG_PROFILER ДЛЯ POSTGRESQL 11.
- Статистика PostgreSQL при работе с 1С:Предприятием
- Настройка непрерывного архивирования (point-in-time-recovery, PITR) в PostgresPro 11 Linux
- Пропажа индексов дескрипторов в 1С:Документообороте
- Технологический журнал 1С и бесконечный цикл в коде 1С
- История одного конфликта блокировок 1С
- 1C тормозит и возникают ошибки. С чего начать расследование?
- Анализ технологического журнала 1С регулярными выражениями. От простого к сложному.