Часто при поиске причин высокой нагрузки на сервер 1С возникает необходимость определить, какая именно строка кода потребляет больше всего процессорного времени. Представим ситуацию: сервер 1С и SQL-сервер разнесены на разные физические машины. Нагрузка идет именно на сервер 1С. Вы настроили Технологический журнал (ТЖ), видите события CALL с общим CpuTime для метода, но не можете понять, что происходит внутри него. Замер производительности показывает только астрономическое время и количество вызовов. Давайте разберем по шагам, можно ли получить процессорное время с точностью до строки и какие инструменты помогут нам локализовать проблему.
Сразу ответим на главный вопрос: платформа 1С не умеет подсчитывать процессорное время (такты CPU) с детализацией до каждой конкретной строчки кода. Встроенного механизма для такого профилирования не существует.
При использовании стандартного «Замера производительности» в Конфигураторе мы получаем так называемое «чистое» астрономическое время (в миллисекундах или секундах). Важно понимать, что это время включает в себя абсолютно все задержки, в том числе:
Тем не менее, если наша цель — найти узкое место в коде (bottleneck), то существующих инструментов в комбинации с аналитическим подходом обычно вполне достаточно. Для автоматизации этого процесса можно использовать инструмент для сбора технологического журнала и поиска узких мест производительности.
Рассмотрим подробнее, как работает свойство CpuTime в ТЖ. Оно измеряется в микросекундах и фиксируется преимущественно для событий серверных вызовов (таких как CALL и SCALL).
Помимо события CALL, проанализируем событие ATTN. В новых версиях платформы 1С в нем реализована отличная возможность оценивать использование процессора за время работы сеанса. Вы можете получить данные:
Это помогает очень быстро выявлять сеансы, которые «сжигают» ресурсы процессора. Чтобы не собирать огромный и нечитаемый лог ТЖ, мы рекомендуем настроить фильтрацию событий CALL. Таким образом, в лог будут попадать только те вызовы, процессорное время которых превышает заданный порог.
Чтобы замер производительности показал нам реальную картину на сервере, выясним важное условие: кластер серверов 1С обязательно должен быть запущен с ключом отладки -debug. Если этого не сделать, в замер попадет только клиентский код, и мы не увидим, какая именно строка на сервере выполняется подозрительно долго.
Для мониторинга нагрузки на процессор конкретными сеансами и процессами давайте посмотрим на Сервер администрирования кластера (RAS). С его помощью мы можем получать параметры сеансов в режиме реального времени. Обратите внимание на метрики cpu-time-current (текущее процессорное время) и duration-current (общее время обслуживания вызова процессом). Резкий скачок этих метрик у конкретного соединения позволит нам быстро локализовать зависший или слишком ресурсоемкий код. Для непрерывного сбора и обработки таких данных можно использовать решение для передачи и парсинга метрик RAS и ТЖ.
Дополнительно, для анализа на уровне ОС, можно использовать системный монитор Windows, где включается замер нагрузки на процессор по каждому конкретному процессу (например, по рабочим процессам rphost).
Поскольку сопоставить CpuTime с каждой строкой невозможно, проанализируем ситуацию и применим комбинированный подход. Выполним следующие шаги:
CpuTime.Запрос.Выполнить(), чтение или запись ссылочных объектов. Если сервер БД находится на другой машине, время выполнения этих строк — это время ожидания ответа по сети и работы дисков/процессора SQL-сервера, а не процессора сервера 1С.Чаще всего процессор сервера 1С перегружают следующие участки кода:
ТаблицаЗначений или Массив в цикле без использования индексов);Таким образом, хотя платформа и не выдает нам готовую таблицу "строка кода — такты процессора", применяя отладку, замер времени и фильтрацию вызовов СУБД, мы сможем с высокой точностью определить алгоритмы, которые требуют оптимизации.