Книга: Настольная книга 1С:Эксперта по технологическим вопросам
Назад: 4.24.Работа с ТЖ. Как посмотреть, какие управляемые блокировки были установлены
Дальше: 4.26.Измерение динамики производительности по журналу регистрации

4.25.Работа с ТЖ. Как расследовать конфликт на управляемых блокировках

Расследование бесконфликтной ситуации

Чтобы собрать сведения об установленных управляемых блокировках и их конфликтах, нужно собрать технологический журнал с событиями TLOCK, TTIMEOUT и TDEADLOCK. Как это сделать, описано в разделе 4.24 «Работа с ТЖ. Как посмотреть, какие управляемые блокировки были установлены».

В простых случаях для работы вам потребуется простой текстовый редактор. В более сложных, например, когда у вас много рабочих процессов и/или блокировка ресурса происходит вне пределов одного часа, вам потребуется или написать парсер, или использовать файловый менеджер, позволяющий производить поиск кириллического текста одновременно в нескольких текстовых файлах (FAR Маnager, Total Commander и т. п.).

Возьмем ошибочный пример из первого издания книги, вызвавший много нареканий (рассмотрен в разделе 3.8).

Имеются два фрагмента кода (толстый клиент, обычное приложение, 8.2.18.102, «Бухгалтерия предприятия», ред. 2.0, конфигурация в управляемом режиме управления блокировками).

Фрагмент 1:

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

Блокировка = Новый БлокировкаДанных;

ЭлементБлокировки = Блокировка.Добавить("РегистрБухгалтерии.Хозрасчетный");

ЭлементБлокировки.Режим = РежимБлокировкиДанных.Исключительный;

Блокировка.Заблокировать();

Фрагмент 2:

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

НаборЗаписей = РегистрыБухгалтерии.Хозрасчетный.СоздатьНаборЗаписей();

НаборЗаписей.Отбор.Регистратор.Установить(ДокументСсылка);

НаборЗаписей.Прочитать();

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

01:51.4861-3,TLOCK,4,process=rphost,p:processName=buh20,t:clientID=32,t:applicationName=1CV8,t:computerName=ZENYA,t:connectID=8,SessionID=9,Usr=DefUser,Regions=AccRg7916.DIMS,Locks=AccRg7916.DIMS Exclusive,WaitConnections=

01:51.4865-0,Context,3,process=rphost,p:processName=buh20,t:clientID=32,t:applicationName=1CV8,t:computerName=ZENYA,t:connectID=8,SessionID=9,Usr=DefUser,Context='

{Форма.Форма1}/{КоманднаяПанель : ОсновныеДействияФормы}/{Кнопка1Выполнить}

Форма.Форма1.Форма : 9 : Блокировка.Заблокировать();'

01:59.9570-3,TLOCK,4,process=rphost,p:processName=buh20,t:clientID=22,t:applicationName=1CV8,t:computerName=ZENYA,t:connectID=4,SessionID=4,Usr=DefUser,Regions=AccRg7916.RECORDER,Locks='AccRg7916.RECORDER Shared Recorder=181:bbd70013d4b2c44611e02bd53593ce4d',WaitConnections=

01:59.9574-0,Context,3,process=rphost,p:processName=buh20,t:clientID=22,t:applicationName=1CV8,t:computerName=ZENYA,t:connectID=4,SessionID=4,Usr=DefUser,Context='

{Форма.Форма1}/{КоманднаяПанель : ОсновныеДействияФормы}/{Кнопка2Выполнить}

Форма.Форма1.Форма : 24 : НаборЗаписей.Прочитать();'

Конфликта блокировок не возникнет, поскольку DIMS и RECORDER (AccRg7916.DIMS и 'AccRg7916.RECORDER) – «измерения» и «регистратор» – это разные пространства блокировок, они не конфликтуют.

Расследование превышения максимального времени ожидания на блокировках «1С»

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

Фрагмент 1:

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

НаборЗаписей = РегистрыСведений.СчетчикВыгрузокПФР.СоздатьНаборЗаписей();

НаборЗаписей.Отбор.Год.Установить(2013);

НаборЗаписей.Прочитать();

Фрагмент 2:

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

Блокировка = Новый БлокировкаДанных;

ЭлементБлокировки = Блокировка.Добавить("РегистрСведений.СчетчикВыгрузокПФР");

ЭлементБлокировки.Режим = РежимБлокировкиДанных.Исключительный;

Блокировка.Заблокировать();

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

29:03.8024-3,TLOCK,4,process=rphost,p:processName=buh20,t:clientID=13,t:applicationName=1CV8,t:computerName=ZENYA,t:connectID=2,SessionID=2,Usr=DefUser,Regions=InfoRg7031.DIMS,Locks='InfoRg7031.DIMS Shared Fld7033=2013',WaitConnections=

29:03.8182-0,Context,3,process=rphost,p:processName=buh20,t:clientID=13,t:applicationName=1CV8,t:computerName=ZENYA,t:connectID=2,SessionID=2,Usr=DefUser,Context='

{Форма.Форма1}/{КоманднаяПанель : ОсновныеДействияФормы}/{Кнопка2Выполнить}

Форма.Форма1.Форма : 22 : НаборЗаписей.Прочитать();'

29:31.9450-0,TTIMEOUT,5,process=rphost,p:processName=buh20,t:clientID=23,t:applicationName=1CV8,t:computerName=ZENYA,t:connectID=6,SessionID=7,Usr=DefUser,WaitConnections=2

29:31.9452-200471,TLOCK,4,process=rphost,p:processName=buh20,t:clientID=23,t:applicationName=1CV8,t:computerName=ZENYA,t:connectID=6,SessionID=7,Usr=DefUser,Regions=InfoRg7031.DIMS,Locks=InfoRg7031.DIMS Exclusive,WaitConnections=2

29:31.9458-0,Context,3,process=rphost,p:processName=buh20,t:clientID=23,t:applicationName=1CV8,t:computerName=ZENYA,t:connectID=6,SessionID=7,Usr=DefUser,Context='

{Форма.Форма1}/{КоманднаяПанель : ОсновныеДействияФормы}/{Кнопка1Выполнить}

Форма.Форма1.Форма : 9 : Блокировка.Заблокировать();'

Из этого примера видно, что если воспроизвести его самостоятельно, по нему можно разобраться, как работать с логами управляемых блокировок (а фактически журнал, настроенный на сбор событий TLOCK, TTIMEOUT и TDEADLOCK, и является логом управляемых блокировок). В частности, сразу видно следующее:

  1. Разделяемая блокировка не снимается сразу после выполнения метода Прочитать (в реальности она держится до конца транзакции).
  2. Обратите внимание на число 200471 в информации о событии TLOCK, связанном с TTIMEOUT. Это время ожидания в сотнях микросекунд (если дописать два нуля справа и отбить разряды, получится «20 047 100»). По нему можно посчитать, какие на самом деле происходят потери на ожидания на управляемых блокировках в системе, даже без использования ЦУП.
  3. В информации о событии TTIMEOUT в явном виде указано, кто кого ждет (соединение с t:connectID=6 ждет (WaitConnections=2) соединение с t:connectID=2).
  4. В простых случаях, чтобы найти виновника конфликта блокировок, достаточно найти, какую именно управляемую блокировку, не совместимую с блокировкой-жертвой, установило соединение, указанное в WaitConnections. При этом даже в простых случаях она может находиться не в этом же файле. Она может быть в логах другого часа, другого рабочего процесса и даже, если в кластере несколько серверов, – в логах другого сервера. Именно для этого нужен файловый менеджер, позволяющий производить поиск кириллического текста одновременно в нескольких текстовых файлах.

Расследование неустранимого конфликта на управляемых блокировках

Выполним с двух клиентских приложений следующий код:

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

Блокировка = Новый БлокировкаДанных;

 

НаборЗаписей = РегистрыСведений.СчетчикВыгрузокПФР.СоздатьНаборЗаписей();

НаборЗаписей.Отбор.Год.Установить(2013);

НаборЗаписей.Прочитать();

 

Предупреждение("этап1");

 

ЭлементБлокировки = Блокировка.Добавить("РегистрСведений.СчетчикВыгрузокПФР");

ЭлементБлокировки.Режим = РежимБлокировкиДанных.Исключительный;

Блокировка.Заблокировать();

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

46:33.4463-3,TLOCK,4,process=rphost,p:processName=buh20,t:clientID=54,t:applicationName=1CV8,t:computerName=ZENYA,t:connectID=7,SessionID=8,Usr=DefUser,Regions=InfoRg7031.DIMS,Locks='InfoRg7031.DIMS Shared Fld7033=2013',WaitConnections=

46:33.4621-0,Context,3,process=rphost,p:processName=buh20,t:clientID=54,t:applicationName=1CV8,t:computerName=ZENYA,t:connectID=7,SessionID=8,Usr=DefUser,Context='

{Форма.Форма1}/{КоманднаяПанель : ОсновныеДействияФормы}/{Кнопка1Выполнить}

Форма.Форма1.Форма : 8 : НаборЗаписей.Прочитать();'

46:39.6554-3,TLOCK,4,process=rphost,p:processName=buh20,t:clientID=23,t:applicationName=1CV8,t:computerName=ZENYA,t:connectID=6,SessionID=7,Usr=DefUser,Regions=InfoRg7031.DIMS,Locks='InfoRg7031.DIMS Shared Fld7033=2013',WaitConnections=

46:39.6558-0,Context,3,process=rphost,p:processName=buh20,t:clientID=23,t:applicationName=1CV8,t:computerName=ZENYA,t:connectID=6,SessionID=7,Usr=DefUser,Context='

{Форма.Форма1}/{КоманднаяПанель : ОсновныеДействияФормы}/{Кнопка1Выполнить}

Форма.Форма1.Форма : 8 : НаборЗаписей.Прочитать();'

Но далее:

46:50.4951-0,TDEADLOCK,5,process=rphost,p:processName=buh20,t:clientID=54,t:applicationName=1CV8,t:computerName=ZENYA,t:connectID=7,SessionID=8,Usr=DefUser,DeadlockConnectionIntersections='7 6 InfoRg7031.DIMS Exclusive Fld7033=2013,6 7 InfoRg7031.DIMS Exclusive Fld7033=2013'

46:50.4953-471,TLOCK,4,process=rphost,p:processName=buh20,t:clientID=54,t:applicationName=1CV8,t:computerName=ZENYA,t:connectID=7,SessionID=8,Usr=DefUser,Regions=InfoRg7031.DIMS,Locks=InfoRg7031.DIMS Exclusive,WaitConnections=6

46:50.5571-0,Context,3,process=rphost,p:processName=buh20,t:clientID=54,t:applicationName=1CV8,t:computerName=ZENYA,t:connectID=7,SessionID=8,Usr=DefUser,Context='

{Форма.Форма1}

Форма.Форма1.Форма : 15 : Блокировка.Заблокировать();'

46:50.7139-34458,TLOCK,4,process=rphost,p:processName=buh20,t:clientID=23,t:applicationName=1CV8,t:computerName=ZENYA,t:connectID=6,SessionID=7,Usr=DefUser,Regions=InfoRg7031.DIMS,Locks=InfoRg7031.DIMS Exclusive,WaitConnections=7

46:50.7146-0,Context,3,process=rphost,p:processName=buh20,t:clientID=23,t:applicationName=1CV8,t:computerName=ZENYA,t:connectID=6,SessionID=7,Usr=DefUser,Context='

{Форма.Форма1}

Форма.Форма1.Форма : 15 : Блокировка.Заблокировать();'

В информации о событии TDEADLOCK в явном виде указано, кто кого ждет (DeadlockConnectionIntersections='7 6).

Это же видно в следующих за ним записях с информацией о событиях TLOCK:

t:connectID=7 InfoRg7031.DIMS Exclusive WaitConnections=6

и

t:connectID=6 InfoRg7031.DIMS Exclusive WaitConnections=7.

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

Ранее на это же пространство InfoRg7031.DIMS были наложены разделяемые блокировки:

t:connectID=6 'InfoRg7031.DIMS Shared

и

t:connectID=7 'InfoRg7031.DIMS Shared

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

Назад: 4.24.Работа с ТЖ. Как посмотреть, какие управляемые блокировки были установлены
Дальше: 4.26.Измерение динамики производительности по журналу регистрации