На форуме Инфостарта есть тема, которую полезно прочитать перед любым большим обновлением. База на 450 ГБ, переход с 11.4 на 11.5, отложенные обработчики идут четырнадцатый день и прошли процентов семьдесят. Работать в базе при этом тяжело, а вопрос у автора один: это нормально или уже пора что-то делать?
Штатная форма "Результаты обновления программы" на этот вопрос не отвечает. Она пишет "Выполнено: 17 из 215" и крутит индикатор. Отчёт БСП (Библиотеки стандартных подсистем) "Прогресс отложенного обновления" добавляет процент и остаток в объектах. Времени окончания нет нигде, а на обработчик, который стоит, отчёт намекает фразой "возможно, другие обработчики держат его выполнение".
При этом всё, чтобы ответить числом, БСП уже хранит у себя. Почасовую историю обработанных объектов, время завершения каждого обработчика, число попыток и текст последней ошибки, остаток в плане обмена. Не хватает деления одного на другое. Ниже разбираю, где это лежит в БСП 3.1, как из этого получить "закончится около 17:00" или "стоит вот этот обработчик, попытки кончились, причина в журнале", и на чём споткнулась первая версия моего расчёта на живой очереди.
Проверял на копии базы УТ 11.5.22 (БСП 3.1.11, около 23 ГБ), где штатным методом БСП ПерезапуститьОтложенноеОбновление перезапустил отложенное обновление: 215 настоящих обработчиков типовой, 207 параллельных и 8 последовательных. Очередь шла четыре часа. Прогноз за два часа до конца ошибся на пять минут, а один обработчик, которого я уронил блокировкой, БСП в итоге записала как "зацикливание".
Где БСП 3.1 держит очередь
Смотрел по метаданным живой базы: механизм менялся между версиями.
| Где | Что там полезного |
|---|---|
РегистрСведений.ОбработчикиОбновления |
по строке на обработчик: Статус, ЧислоПопыток, ИнформацияОбОшибке, ОчередьОтложеннойОбработки, режим (параллельно или последовательно), хранилище СтатистикаВыполнения со временем начала и завершения |
РегистрСведений.ПрогрессОбновления |
сколько объектов обработал каждый обработчик в каждый час (ИнтервалЧас, ОбъектовОбработано) |
ПланОбмена.ОбновлениеИнформационнойБазы |
что осталось: каждая запись таблицы изменений это объект, который обработчик ещё не прошёл |
константа СведенияОбОбновленииИБ |
когда отложенное обновление началось и закончилось, успешно ли |
| журнал регистрации, событие "Обновление информационной базы" | попытки и ошибки обработчиков |
Статусов у обработчика пять: не выполнялся, выполняется, выполнен, ошибка, приостановлен. Выбрать только отложенные можно одним запросом, и в нём нет ничего экзотического:
Запрос = Новый Запрос( "ВЫБРАТЬ | О.ИмяОбработчика КАК Имя, | О.Статус КАК Статус, | О.ЧислоПопыток КАК Попыток, | О.ИнформацияОбОшибке КАК Ошибка, | О.ОчередьОтложеннойОбработки КАК Очередь, | О.СтатистикаВыполнения КАК Статистика, | О.ОбрабатываемыеДанные КАК Данные |ИЗ | РегистрСведений.ОбработчикиОбновления КАК О |ГДЕ | О.РежимВыполнения = ЗНАЧЕНИЕ(Перечисление.РежимыВыполненияОбработчиков.Отложенно)");
Одна тонкость, если пишете внешнюю обработку. Прямое обращение к ОбновлениеИнформационнойБазыСлужебный в коде не даст ей даже открыться на конфигурации, где такого модуля нет. ЗНАЧЕНИЕ(Перечисление...) в тексте запроса упадёт позже, при выполнении. Поэтому всё, что зависит от версии БСП, держите в тексте запроса и заранее проверяйте через Метаданные: тогда на старой базе обработка честно скажет "механизма нет".
Сколько осталось
Когда БСП регистрирует данные для отложенного обработчика, она кладёт их в план обмена ОбновлениеИнформационнойБазы, узел соответствует очереди. Очередь здесь - номер этапа: обработчики очереди 2 ждут, пока обработчики очереди 1 пройдут общие с ними данные. Обработчик прошёл объект - запись изменений удаляется. Значит, остаток это число записей в таблицах изменений по всем объектам состава плана. Пример для одного справочника, в обработке такие запросы собираются по всему составу через ОБЪЕДИНИТЬ ВСЕ:
ТекстЗапроса =
"ВЫБРАТЬ
| Т.Узел.Очередь КАК Очередь,
| КОЛИЧЕСТВО(*) КАК Количество
|ИЗ
| Справочник.ВидыКонтактнойИнформации.Изменения КАК Т
|ГДЕ
| Т.Узел.Временная = ЛОЖЬ
|СГРУППИРОВАТЬ ПО
| Т.Узел.Очередь";
Отбор Временная = ЛОЖЬ нужен из-за перезапуска. Когда отложенное обновление перезапускают, БСП регистрирует данные на новые узлы с пометкой "временный", а закончив регистрацию, меняет пометки местами: новые узлы становятся постоянными, старые временными, и их регистрация стирается (процедура ПерезапуститьОтложенноеОбновление). В рабочей очереди временными остаются только старые узлы, в остаток они не идут, штатный отчёт БСП поступает так же. Какой обработчик за какой объект и очередь отвечает, лежит в ОбрабатываемыеДанные, внутри структура ДанныеОбработчика: полное имя объекта, очередь, сколько зарегистрировали изначально.
Сверил это с прямым подсчётом. По всему составу плана на стенде было 277 записей, по объектам, которые числятся за обработчиками, 195. Разница, 82 записи, это хвосты шести справочников интеграций, которые не принадлежат ни одному текущему обработчику. Отчёт БСП такие строки тоже выбрасывает.
Скорость: объекты и обработчики
Первая мера очевидная. ПрогрессОбновления хранит обработанные объекты по часам, поэтому скорость можно получить с первого же замера, без ожидания:
Запрос = Новый Запрос( "ВЫБРАТЬ | П.ИмяОбработчика КАК Имя, | СУММА(ВЫБОР КОГДА П.ИнтервалЧас >= &НачалоОкна | ТОГДА П.ОбъектовОбработано ИНАЧЕ 0 КОНЕЦ) КАК ЗаОкно |ИЗ | РегистрСведений.ПрогрессОбновления КАК П |СГРУППИРОВАТЬ ПО | П.ИмяОбработчика"); Запрос.УстановитьПараметр("НачалоОкна", НачалоЧаса(ТекущаяДатаСеанса()) - 3600);
Окно берётся с начала прошлого часа до текущего момента, и делить сумму надо на реально прошедшие секунды, а не на час. Если отложенное обновление стартовало внутри окна, начало окна сдвигается на старт. Историю за вчера не ищите: БСП сама удаляет интервалы раньше начала текущего дня (при каждом запуске отложенного обновления, в многопоточном режиме раз в десять минут процедурой ОчиститьПрогрессОбработкиЗаИнтервалыПредыдущегоДня), так что в половине первого ночи истории будет полчаса.
Первая версия на этом и остановилась, и на живой очереди сразу соврала. Через три минуты после старта, на втором замере, она написала красным "похоже, стоит: остаток не уменьшился". Остаток и правда стоял на 195. А обработчики тем временем завершались по одному в минуту: первыми шли последовательные, у которых объектов в плане обмена нет вообще: данные они выбирают сами. "Выполнено: N из 215" в штатной форме при этом росло, а процент по объектам стоял, и по нему легко решить, что всё встало.
Поэтому вторая мера - обработчики в час. Время завершения каждого БСП пишет в СтатистикаВыполнения:
Статистика = Выборка.Статистика.Получить(); // Соответствие Если ТипЗнч(Статистика) = Тип("Соответствие") И ТипЗнч(Статистика["ЗавершениеОбработкиДанных"]) = Тип("Дата") И Статистика["ЗавершениеОбработкиДанных"] >= НачалоОкна Тогда ВыполненоЗаОкно = ВыполненоЗаОкно + 1; КонецЕсли;
Прогноз считается дважды: остаток объектов на их скорость и остаток обработчиков на их скорость. Обновление кончится, когда кончится и то и другое, поэтому берётся более поздняя дата.
Вторая ошибка была тише, и чинить её пришлось дважды. ПрогрессОбновления и регистрация в плане обмена считают в разных единицах. Обработчик групп значений доступа ничего не зарегистрировал, а в прогресс записал 867 обработанных. Обработчик групп доступа зарегистрировал 2 объекта и записал 1 705. Когда в окне скорости лежали только первые 867, за 16,5 минуты окна (оно началось со старта очереди) это давало 3 150 объектов в час, и остаток 195 по такой скорости кончался "через четыре минуты". Штатный отчёт БСП эту ловушку знает: в его коде обработанное обрезается зарегистрированным (Если ОбъектовОбработано > ВсегоОбъектов Тогда ОбъектовОбработано = ВсегоОбъектов). После такой же обрезки 867 превращаются в 0, 1 705 в 2, и вместе с остальными обработчиками за 58 минут окна набирается 12 объектов, то есть 12 в час. Ровно на столько упал остаток за тот же час по двум замерам: со 195 до 183.
Третья ошибка вылезла сразу за второй. Честные 12 в час на остаток 183 дают окончание в пять утра следующего дня. Но 116 из этих 183 объектов принадлежат одному обработчику, который ещё ждёт своей очереди и пройдёт их за один запуск. Объекты ждущих обработчиков сейчас никто не обрабатывает, делить их на текущую скорость бессмысленно. Поэтому прогноз по объектам считается только по обработчикам, которые сейчас в работе: для каждого его остаток делится на его скорость, и берётся самая поздняя из этих дат. Ждущих обработчиков покрывает прогноз по обработчикам.
Как ведёт себя такой прогноз, видно по замерам каждые две минуты. Очередь стартовала в 13:01, первый прогноз появился в 13:10 и до 13:21 держался в пределах "17:00-17:30" (код я правил по ходу, так что часть этих замеров снята ещё первой версией). С 13:20 до 13:33 не завершился ни один обработчик: регламентное задание все тринадцать минут было занято одним, который упёрся в блокировку, о нём ниже. Прогноз за это время честно уехал с "17:20" на "19:50", потому что скорость в обработчиках падала. Когда затор прошёл, к 14:00 он вернулся к "17:50-18:00".
Очередь закончилась в 17:05. Прогноз, снятый в 15:06, говорил "около 17:00" и дальше не менялся почти час; снятый в 14:01 ошибся на 45 минут, первый, в 13:10, на 25. Средний темп за всю очередь вышел около 52 обработчиков в час. Закончилась она, правда, не успехом: два обработчика так и остались невыполненными, о них следующий раздел.
Кто держит
Порядок проверки у меня такой: сначала то, что останавливает всё сразу, потом отдельный обработчик.
Регламентное задание не работает. Отложенное обновление в клиент-серверной базе идёт регламентным заданием "Отложенное обновление", в типовом расписании раз в 60 секунд. Если оно выключено или у базы стоит флаг "Блокировка регламентных заданий" в консоли администрирования серверов 1С, очередь стоит целиком, и никакие обработчики тут ни при чём. На стенде это был первый же кадр: базу я создал с запретом регламентных заданий, задание в конфигурации включено, фоновых заданий нет. Проверяется так:
Задания = РегламентныеЗадания.ПолучитьРегламентныеЗадания( Новый Структура("Метаданные", Метаданные.РегламентныеЗадания.ОтложенноеОбновлениеИБ)); Если Задания.Количество() > 0 Тогда Фоновые = ФоновыеЗадания.ПолучитьФоновыеЗадания( Новый Структура("РегламентноеЗадание", Задания[0])); КонецЕсли; // Включено, а последний запуск давно или его нет - смотреть флаг в консоли серверов 1С
Этот случай штатная форма БСП ловит и сама: "Вероятно включена блокировка выполнения регламентных заданий".
Обработчик исчерпал попытки. Когда обработчик падает, БСП ставит ему статус "Ошибка", увеличивает ЧислоПопыток и повторяет его позже. Предел в коде БСП 3.1.11 такой (функция МаксимумПопытокОбновления): обычному обработчику три попытки, многопоточному 3 * (объекты * регистры + потоки). Многопоточный - это параллельный обработчик, чьи данные БСП режет на порции и раздаёт потокам обновления; объекты и регистры в формуле - число таблиц, которые он обрабатывает, из его параметров выборки. Дошёл до предела - больше его не запустят, и отложенное обновление закончится с сообщением "Не все процедуры удалось выполнить". Это главный кандидат на "кто держит". Держит он в прямом смысле: последний обработчик БСП, ОчиститьУстаревшиеДанныеПолностью, ждёт всех остальных, и на стенде он так и не запустился.
В журнал регистрации ошибка обработчика пишется под событием "Обновление информационной базы", но уровнем, который зависит от попытки: пока попытки есть, это Предупреждение, на последней - Ошибка. На стенде первый запуск упавшего обработчика оставил в журнале 39 предупреждений и ни одной ошибки, "Ошибкой" стали только две итоговые записи второго запуска. Отбор журнала "Уровень = Ошибка" весь первый запуск не покажет.
Ещё одна неочевидная вещь: в первой строке ошибки имени обработчика может не быть вовсе, оно есть только в стеке вызовов ниже. На стенде было ровно так: "Не удалось обработать некоторые виды контактной информации (пропущены): 38". Связать запись журнала с обработчиком помогает то, что перед каждым запуском БСП пишет в том же сеансе строку Выполняется процедура обновления "<имя>"., а ошибка идёт следом:
Маркер = "Выполняется процедура обновления """; Для Каждого Запись Из ТаблицаЖурнала Цикл Если СтрНачинаетсяС(Запись.Комментарий, Маркер) Тогда Хвост = Сред(Запись.Комментарий, СтрДлина(Маркер) + 1); ОбработчикСеанса.Вставить(Запись.Сеанс, Лев(Хвост, СтрНайти(Хвост, """") - 1)); Продолжить; КонецЕсли; // Предупреждение или Ошибка дальше относим к ОбработчикСеанса[Запись.Сеанс] КонецЦикла;
Блокировка. На стенде я искусственно уронил один обработчик: из отдельного сеанса взял исключительную управляемую блокировку на весь справочник видов контактной информации и держал её в открытой транзакции. Обработчику надо было пройти 38 элементов. Каждый ждал блокировку положенные 20 секунд и пропускался, и один запуск обработчика занял 13 минут. Всё это время регламентное задание было активно, в статусе обработчика стояло "Выполняется", а в штатной форме ничего не менялось. Потом статус "Ошибка", попытка вторая из трёх, и в регистре тот самый текст про 38 пропущенных, без слова "блокировка".
Причина нашлась в журнале. За один запуск там легли 39 предупреждений: по одному на каждый элемент с интервалом почти ровно 20 секунд и итоговое про 38 пропущенных. У каждого элемента текст такой:
Не удалось обработать "Мобильный телефон" по причине:
Ошибка при вызове метода контекста (Заблокировать)
{Справочник.ВидыКонтактнойИнформации.МодульМенеджера(642)}:Блокировка.Заблокировать();
...
Конфликт блокировок при выполнении транзакции:
Превышено максимальное время ожидания предоставления блокировки
Первые строки у всех 38 разные (имя элемента в кавычках), корневая причина одна. Если сравнивать тексты ошибок целиком, получится 38 разных ошибок; если убрать то, что в кавычках, и взять последнюю строку, получится одна ошибка, повторённая 38 раз. Для вопроса "держит ли что-то один и тот же" нужен второй вариант.
Второй раз БСП взялась за этот обработчик в 15:57, пройдя большую часть очереди. Те же 12 минут 41 секунда ожидания по 20 секунд на элемент, те же 38 пропусков, только теперь в журнале две записи уровнем "Ошибка". И вот здесь ловушка: последней ошибкой в регистре встало не "не удалось обработать", а "Произошло зацикливание процедуры обработки данных. Выполнение прервано." Счётчик попыток показал 4 при пределе 3 (откуда четвёртая, объясняю в вопросах в конце). Отчёт БСП и форма со списком обработчиков покажут именно "зацикливание", и искать будут цикл в коде обработчика. Причина при этом лежит в журнале, в 76 предупреждениях по элементам (по 38 за запуск) с одной и той же последней строкой про ожидание блокировки.
Здесь полезно сразу видеть сеансы базы: самый долгий сеанс - первый кандидат в держатели блокировки, но не доказательство. У меня держателем было COM-соединение, и в первом же списке оно стояло третьим: выше висели два зависших сеанса от прерванных мной процессов. В жизни там чаще забытая обработка или обмен.
Час без движения. Последний признак самый грубый: за последний час по базе не обработано ни одного объекта и не завершилось ни одного обработчика. Есть и короткий вариант: между двумя замерами прошло десять минут, и не изменилось вообще ничего, ни статус, ни остаток, ни счётчик попыток. Красный по этим признакам бывает в двух случаях: есть подозреваемый в ошибке, или прогноза нет совсем. Если прогноз есть, вердикт остаётся зелёным или жёлтым, а тревогу подаёт сам прогноз, уезжая вперёд. Так и было в тот 13-минутный затор на блокировке: задание активно, обработчик "Выполняется", вокруг тишина, вердикт зелёный, конец отодвинулся на два с половиной часа. Называть это остановкой через пять минут было бы неправдой.
Чего я не проверил
Стенд маленький по объёму данных: очередь была длинной по числу обработчиков (215), а объектов в ней оставалось меньше двухсот. Поэтому прогноз здесь в основном шёл по обработчикам. Как поведёт себя прогноз по объектам на базе вроде той, с форума, где один обработчик сутками идёт по миллионам документов, я на живой очереди не видел. По коду там сработает та же ветка, что у обработчиков в работе: его остаток на его скорость, и это честнее общего процента. По той же причине у форумного случая не работает "70 % за 14 дней, значит, ещё шесть": оставшиеся проценты могут принадлежать одному тяжёлому обработчику. Но цифрой это не подтверждено, и если у вас сейчас идёт такое обновление, мне было бы интересно сравнить прогноз с фактом. Не мерил я и время самого замера на такой очереди: на стенде в плане обмена было меньше трёхсот записей.
Вторая граница - версия БСП. Регистр ОбработчикиОбновления есть в БСП 3.1.11 (УТ 11.5.22). В БСП 3.1.2 (Бухгалтерия для Казахстана 3.0.40) и 2.4.6 (УТ для Казахстана 3.4) его нет: очередь там хранится деревом внутри константы СведенияОбОбновленииИБ, с теми же колонками статуса и попыток. Точную версию, где регистр появился, я не искал.
Что получилось в обработке
Всё это собрано в обработку "Отложенное обновление: когда закончится и что держит". При открытии она сама делает замер и показывает одну цветную строку. Вот реальные строки со стенда:
- жёлтая, 14:06: "Идёт, закончится около 17:50 сегодня (не выполнено обработчиков: 165, объектов в очереди: 183; прогноз по обработчикам: 45,8 в час, по времени их завершения с 13:01). Внимание: Справочники.ВидыКонтактнойИнформации... - ошибка, БСП повторит (2 из 3)". Зелёная выглядит так же, только без "Внимание";
- красная по обработчику: "Стоит обработчик Справочники.ВидыКонтактнойИнформации.ОбработатьДанныеДляПереходаНаНовуюВерсию: попытки кончились (4 при пределе 3), БСП его больше не запустит (в регистре "зацикливание", настоящая причина в журнале: нажмите "Кто держит")";
- красная после конца очереди: "Отложенное обновление остановилось 27.09 в 17:05, не выполнено обработчиков: 2. Первым держит Справочники.ВидыКонтактнойИнформации.ОбработатьДанныеДляПереходаНаНовуюВерсию (в регистре "зацикливание", настоящая причина в журнале: нажмите "Кто держит")".
Под строкой таблица обработчиков с той же оценкой в первой колонке. Кнопка "Кто держит" раскрывает виновника: попытки, полный текст ошибки, сколько записей в журнале с одной и той же причиной, долгие сеансы. "Отчёт" даёт текст для админа, "Выгрузить в Markdown для нейросети" собирает один файл с вердиктом, таблицами и контекстом базы, без паролей, сеансы без имён пользователей. Обработка только читает: перезапуск и число потоков остаются в штатной форме.
Частые вопросы
Можно ли смотреть на рабочей базе прямо во время обновления? Да. Это несколько запросов к регистрам БСП и чтение журнала по одному событию: на стенде с живой очередью замер занимал 0,14-0,18 секунды, "Кто держит" 0,11-0,14 (журнал там был маленький). Ничего не пишется.
Почему попыток четыре при пределе три, а запусков было два? Счётчик попыток не равен числу запусков. Кроме попытки за исключение в обработчике БСП добавляет ещё одну, если обработчик минимальной очереди отработал и не обработал ни одного объекта: так она ловит зацикливание (процедура ПослеЗапускаПроцедурыОбработкиДанных в ОбновлениеИнформационнойБазыСлужебный). На стенде первый запуск дал 2 из 3, второй довёл до 4 и закончился текстом про зацикливание.
Где взять динамику за неделю? Почасовой прогресс БСП чистит до начала суток. Время завершения обработчиков остаётся в СтатистикаВыполнения, запуски и ошибки в журнале. Кривую за неделю придётся снимать самому.
На старой конфигурации заработает? Нужен регистр ОбработчикиОбновления: в БСП 3.1.11 он есть, в 3.1.2 и 2.4 нет, и обработка там так и пишет.
Что делать с обработчиком, исчерпавшим попытки? Прочитать текст ошибки, устранить причину и запустить его кнопкой "Запустить" в форме "Отложенные обработчики". Сбрасывать счётчик попыток правкой регистра не надо.
Ссылки
Обработка по статье: "Отложенное обновление: когда закончится и что держит".
Другие наши инструменты:
- Чек-ап СУБД под 1С
- Карта объёмов базы 1С
- Анализ нагрузки кластера 1С: кто блокировал базу, кто грузил сервер
- Чек-ап сервера 1С: настройки кластера и рабочих процессов
- Журнал регистрации, свёрнутый для нейросети
А у вас какое отложенное обновление было самым долгим, и что в итоге держало: данные, блокировка или регламентное задание, которое никто не включил?
Вступайте в нашу телеграмм-группу Инфостарт