1С висела, серверы перезагрузили: какие следы аварии остались и сколько они живут
Иван Недомолков · Жарияланды:
Самый частый ответ на вопрос “почему вчера всё висело” звучит как “перезагрузили, и отпустило”. Он честный, но причину не называет. Хуже того, перезагрузка и есть главный стиратель улик: SQL Server после рестарта забывает статистику ожиданий и занятость tempdb, кластер 1С забывает сеансы, журналы с перезаписью дописывают поверх старого.
Ниже разбор по источникам: что каждый из них знает об аварии, сколько это хранится и что надо сделать заранее. Иллюстрацией идёт настоящий случай из розницы, в котором через три недели после зависания касс назвать виновника было уже не по чему. Короткий рассказ о нём опубликован на Инфостарте, здесь методика целиком.
Две минуты до перезагрузки
Если всё висит прямо сейчас и рестарт уже решён, сначала сохраните в файл три вещи. Это занимает пару минут и потом стоит дороже всего остального.
- Кто занимает tempdb и кто кого блокирует. Запрос ниже считает и идущие задачи, и сеансы, которые держат временные таблицы между запросами: в 1С это частый случай, ПОМЕСТИТЬ живёт до конца сеанса.
- Список сеансов и процессов кластера через
rac session listиrac process list. - Текущий ERRORLOG:
EXEC xp_readerrorlog 0, 1;с выводом в файл.
-- Кто занимает tempdb: завершённые аллокации сеанса плюс идущие задачи
SELECT TOP (20)
s.session_id,
s.host_name,
s.host_process_id AS pid_rphost,
DB_NAME(s.database_id) AS база,
s.program_name,
(ss.pages + ISNULL(ts.pages, 0)) * 8 / 1024 AS tempdb_mb,
r.status,
r.wait_type,
r.blocking_session_id,
at.transaction_begin_time
FROM sys.dm_exec_sessions AS s
JOIN (SELECT session_id,
SUM(user_objects_alloc_page_count - user_objects_dealloc_page_count
+ internal_objects_alloc_page_count - internal_objects_dealloc_page_count) AS pages
FROM sys.dm_db_session_space_usage
GROUP BY session_id) AS ss ON ss.session_id = s.session_id
LEFT JOIN (SELECT session_id,
SUM(user_objects_alloc_page_count - user_objects_dealloc_page_count
+ internal_objects_alloc_page_count - internal_objects_dealloc_page_count) AS pages
FROM sys.dm_db_task_space_usage
GROUP BY session_id) AS ts ON ts.session_id = s.session_id
LEFT JOIN sys.dm_exec_requests AS r ON r.session_id = s.session_id
LEFT JOIN sys.dm_tran_session_transactions AS st ON st.session_id = s.session_id
LEFT JOIN sys.dm_tran_active_transactions AS at ON at.transaction_id = st.transaction_id
WHERE s.is_user_process = 1
ORDER BY tempdb_mb DESC;rac cluster list localhost:1545
rac session list --cluster=<id кластера> localhost:1545 > sessions.txt
rac process list --cluster=<id кластера> localhost:1545 > processes.txtПоле host_process_id у соединения 1С совпадает с PID рабочего процесса rphost, а в выводе rac session list у каждого сеанса есть поле db-proc-info с номером соединения СУБД, которое он держит прямо сейчас. Вместе эти три файла отвечают на вопрос “кто” с точностью до сеанса. Через пять минут после рестарта на него не ответит уже никто.
Сколько живёт каждый след
Таблица собрана по реальной описи логов, которую админы сделали через три недели после аварии. Сроки в ней - настройки по умолчанию или то, что стояло на серверах.
| Источник | Что знает об аварии | Сколько живёт | Что поменять заранее |
|---|---|---|---|
| Статистика SQL Server в памяти (ожидания, задержки файлов, tempdb по сеансам) | на чём стоял сервер и кто грузил tempdb | до перезапуска службы | писать снимки в свою базу по расписанию |
| system_health | долгие ожидания, взаимоблокировки, нехватка памяти | несколько файлов по кругу, при активном сервере дни | увеличить число и размер файлов или писать свою сессию Extended Events |
| ERRORLOG | перезапуски, kill соединений, часть ошибок | 6 файлов, новый на каждый старт службы | 30 файлов |
| Технологический журнал 1С | долгие запросы, исключения, ожидания блокировок | сколько указано в history, у нас было 48 часов | 7 суток, плюс TLOCK, TTIMEOUT, TDEADLOCK, EXCP |
| Сеансы и процессы кластера 1С | кто на каком процессе и что держал | только текущее состояние | писать историю сеансов регламентным заданием |
| Журнал Application сервера 1С | падения процессов, ошибки служб | 20 МБ с перезаписью | 512 МБ |
| Журнал System | кто и с какой причиной перезагружал | долго, событие 1074 | ничего |
| PerfMon | нагрузка по минутам | не собирался вовсе | сборщик счётчиков с записью в файл |
| Графики vCenter | процессор, память, диски машин | прошлый месяц только средние за 2 часа | ничего, минутные пики там не живут |
| События vCenter | расширения дисков, вход админов в консоль, тревоги хранилищ | 30 дней по умолчанию | права на чтение событий хостов заранее |
Отдельная оговорка про ERRORLOG. Это единственное место SQL Server, которое помнит что-то после перезапуска, но и он не всё. Часть ошибок нехватки места в tempdb туда не попадает, поэтому пустой ERRORLOG не доказывает, что tempdb был в порядке. Число файлов меняется в свойствах журналов сервера или запросом:
-- Хранить 30 файлов ERRORLOG вместо 6
EXEC xp_instance_regwrite
N'HKEY_LOCAL_MACHINE',
N'Software\Microsoft\MSSQLServer\MSSQLServer',
N'NumErrorLogs',
REG_DWORD,
30;Как доказать, что беда общая для всех баз
Первый вопрос любого разбора: виноват код одной базы или общий слой (СУБД, tempdb, кластер, железо). На него отвечает журнал регистрации, если искать не ошибки, а входы. Кассир при зависании перезапускает 1С, и каждый перезапуск это событие _$Session$_.Start. Фоновые задания и веб-сервисы тоже дают входы, но в обычный день их фон стабилен, поэтому сравнивать надо с тем же днём недели неделей раньше.
// Входы по часам за выбранный день. Запускать на сервере с правами администратора,
// потом тот же код для дня неделей раньше.
Функция ВходыПоЧасам(День) Экспорт
Отбор = Новый Структура;
Отбор.Вставить("ДатаНачала", НачалоДня(День));
Отбор.Вставить("ДатаОкончания", КонецДня(День));
Отбор.Вставить("Событие", "_$Session$_.Start");
Записи = Новый ТаблицаЗначений;
ВыгрузитьЖурналРегистрации(Записи, Отбор, "Дата");
Результат = Новый Соответствие;
Для Каждого Запись Из Записи Цикл
Ч = Час(Запись.Дата);
Было = Результат[Ч];
Результат.Вставить(Ч, ?(Было = Неопределено, 0, Было) + 1);
КонецЦикла;
Возврат Результат;
КонецФункцииВ нашем случае входов в часы аварии было в 7-15 раз больше обычного: 158 против 22 в 14:00, 194 против 16 в 15:00, 233 против 16 в 17:00. Но доказательством стали не числа, а минуты. Пики пришлись на 14:20, 15:10 и 17:10-17:20, и совпали во всех одиннадцати базах сразу. Ошибка в коде одной базы соседей в ту же минуту не роняет, если не забивает общий ресурс. Значит, болел общий слой, а одна база могла быть его причиной.
Метод дорогой. На больших базах выборка журнала регистрации за двое суток падает по таймауту, и позже заказчик запретил её на рабочих базах. Если журнал огромный, берите один час вокруг пика, а не сутки.
Тем же приёмом исключаются блокировки: таймаутов блокировок в рознице в день аварии было 28, неделей раньше тоже 28. Это фон закрытия смен, а не причина.
События vCenter: что видно без доступа к хостам
Если 1С работает под VMware, у админов в истории vCenter лежат вещи, которые сами они не считают уликами. В нашем случае главная находка пришла именно оттуда: в день аварии диск tempdb расширяли трижды, с 250 до 300 ГБ за 1 час 41 минуту. В переписке это выглядело рабочими действиями, а не симптомом.
События читаются без библиотек, голым SOAP на адрес /sdk. REST-интерфейс /api событий не отдаёт. Порядок такой: RetrieveServiceContent, затем SessionManager.Login, дальше запросы с cookie из ответа на вход.
<QueryEvents xmlns="urn:vim25">
<_this type="EventManager">EventManager</_this>
<filter>
<entity>
<entity type="VirtualMachine">vm-NN</entity>
<recursion>self</recursion>
</entity>
<time>
<beginTime>2026-01-01T00:00:00Z</beginTime>
<endTime>2026-01-02T00:00:00Z</endTime>
</time>
</filter>
</QueryEvents>Что искать в ответе:
| Событие | Что значит |
|---|---|
VmReconfiguredEvent с capacityInKB до и после | диск расширяли, видно на сколько и когда |
VmAcquiredTicketEvent | админ открыл консоль машины, то есть кто-то уже смотрел |
| перезагрузки и выключения | сверить с событием 1074 в журнале System |
Время в событиях UTC. Графики берутся через QueryPerf, и для прошлого месяца там есть только intervalId 7200, средние за два часа. В них сервер СУБД выглядел спокойным (процессор 13-18 %, задержка дисков до 1 мс), но минутный пик в таком среднем тонет. Снятым подозрение с ресурсов считать нельзя, только ослабленным.
Хронология, которая сложилась, когда события vCenter положили рядом с остальным:
| Время | Что произошло |
|---|---|
| около 13:00 | зависают кассы |
| 13:53 | диск tempdb 250 → 252 ГБ |
| 14:20 | первая волна перезапусков 1С во всех базах |
| 14:42 | диск tempdb 252 → 260 ГБ |
| 15:10 | падает рабочий процесс rphost, в ту же минуту самая сильная волна |
| 15:34 | диск tempdb 260 → 300 ГБ |
| 17:22 / 17:25 | перезагрузка сервера 1С, затем сервера СУБД |
| 20:48 | ручной рестарт службы SQL Server |
| 21:00 | ещё одна перезагрузка сервера 1С |
| утро | перезагрузка обоих серверов |
Трижды за два часа диск просто так не растят, tempdb явно кончался. Но кто его занял, к этому моменту не знал никто: три запуска SQL Server за сутки трижды обнулили статистику.
Что проверить в настройках, пока ищете виновника
Виновника назвать не удалось, но гипотеза осталась, и её половины проверяются на любом сервере. Первая - параллелизм. На том сервере стояли max degree of parallelism = 0 и cost threshold for parallelism = 5: один запрос мог занять все 48 ядер, а параллельный план получал почти любой запрос. Наутро после аварии за 8 минут прошло 550 взаимоблокировок внутри параллельных запросов.
-- Текущие настройки параллелизма
SELECT name, value_in_use
FROM sys.configurations
WHERE name IN (N'max degree of parallelism', N'cost threshold for parallelism');
-- Значения, которые мы предложили для этого сервера
EXEC sp_configure 'show advanced options', 1; RECONFIGURE;
EXEC sp_configure 'max degree of parallelism', 8; RECONFIGURE;
EXEC sp_configure 'cost threshold for parallelism', 50; RECONFIGURE;Вторая - брошенная транзакция. В той же инфраструктуре раньше уже был случай: транзакция ERP держала около 56 000 эксклюзивных блокировок и 27 тысяч страниц tempdb, сброс сеанса 1С её не закрыл, помог только KILL на стороне SQL Server. Объём там был около 210 МБ, но механизм тот же: транзакция пережила сеанс, и 1С о ней больше ничего не знала.
-- Транзакции дольше 5 минут: кто держит и сколько журнала
SELECT s.session_id,
s.host_process_id AS pid_rphost,
DB_NAME(dt.database_id) AS база,
at.transaction_begin_time,
DATEDIFF(MINUTE, at.transaction_begin_time, SYSDATETIME()) AS минут,
dt.database_transaction_log_bytes_used / 1048576 AS журнал_мб
FROM sys.dm_tran_active_transactions AS at
JOIN sys.dm_tran_session_transactions AS st ON st.transaction_id = at.transaction_id
JOIN sys.dm_exec_sessions AS s ON s.session_id = st.session_id
JOIN sys.dm_tran_database_transactions AS dt ON dt.transaction_id = at.transaction_id
WHERE at.transaction_begin_time < DATEADD(MINUTE, -5, SYSDATETIME())
ORDER BY at.transaction_begin_time;Обе настройки, число файлов tempdb против числа ядер и скрипты “кто занимает tempdb” и “долгие транзакции” собраны в Чек-апе СУБД под 1С. Как разбирать саму ошибку переполнения журнала tempdb, если до неё дошло, - в отдельной статье про ошибку 9002.
Что поставить заранее
Вывод из этой истории один: следы надо писать до перезагрузки и туда, где рестарт их не достанет.
- Снимки SQL Server раз в минуту в свою базу. Активные запросы с текстом, tempdb по сеансам, блокировки, долгие транзакции, прирост ожиданий и задержек файлов, место на дисках, хранение две недели. Задание SQL Agent работает внутри сервера СУБД и пишет, даже когда кластер 1С не отвечает. Мы собрали это в Чёрный ящик SQL Server под 1С: на нашем стенде снимок занимает 166 мс, около 0,02 % сервера на 12 ядрах.
- Связка с сеансами 1С. SQL Server знает у соединения только PID rphost, а на одном процессе живут сеансы разных баз. Точного пользователя даёт свойство сеанса
СоединениеСУБД, которое кластер отдаёт через RAS, если его записывать раз в минуту вместе с PID. В ящике это отдельная команда. Историю нагрузки самого кластера копит Анализ нагрузки кластера 1С. - Сроки хранения журналов. Техжурнал 7 суток с событиями блокировок и исключений, ERRORLOG 30 файлов, Application 512 МБ.
- Тревога на свободное место в tempdb. Узнать раньше касс.
- Ограничения памяти рабочих процессов на кластере. На том сервере их не было, утром процессы держали 73 ГБ, самые большие по 10 ГБ.
- Порядок действий на аварию, записанный заранее. Первым пунктом: убедиться, что свежий снимок есть, и только потом перезагружать. Когда кассы стоят, все торопятся, и правило, которое не записано и не закреплено за человеком, не выполнится.
В том случае всё это было предложено техлиду заказчика, и на начало ноября внедрение не начиналось. Если нужна такая запись у вас, ставим её под ключ в рамках мониторинга 1С: снимки, сроки журналов и порядок действий на аварию.
