Как увидеть код выполняемого модуля в хронологии выполнения

Программист 1С v8.3 (Управляемые формы) IT и автоматизация бизнеса
← На главную

В процессе разработки и отладки на платформе 1С:Предприятие программисты часто сталкиваются с ситуацией, когда стандартного замера производительности недостаточно. Обычный замер в «Конфигураторе» агрегирует данные: он показывает общее время выполнения строк и количество их вызовов, но полностью скрывает реальную последовательность (хронологию) событий. Чтобы понять, «что за чем вызывалось», нам потребуются более продвинутые методики. В этой статье мы разберем несколько эффективных способов получения трассировки кода.

Использование стека вызовов для оперативного анализа

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

Рассмотрим, как это работает: когда выполнение кода прерывается на точке останова, мы можем открыть окно «Стек вызовов». В нем в хронологическом порядке (снизу вверх) отображаются все процедуры и функции, которые были вызваны. Самая верхняя строка — это то место, где мы находимся сейчас, а строки ниже — те методы, которые инициировали текущий вызов. Это позволяет увидеть иерархическую «хронологию глубины», хотя и не показывает выполнение соседних (не вложенных) строк кода.

Программное логирование и контрольные точки

Один из самых надежных «дедовских» методов — расстановка контрольных точек вручную. Мы можем выводить сообщения в журнал регистрации или в текстовый файл в ключевых местах кода. Это создаст четкую текстовую хронологию выполнения.

Посмотрим на пример реализации такого логирования через ЗаписьЖурналаРегистрации:


Процедура ОбработкаПроведения(Отказ, РежимПроведения)
    // Фиксируем начало выполнения
    ЗаписьЖурналаРегистрации("Отладка.Хронология", УровеньЖурналаРегистрации.Информация, , , "Начало проведения документа: " + Строка(ЭтотОбъект));
    
    РассчитатьСебестоимость();
    ЗаписьЖурналаРегистрации("Отладка.Хронология", УровеньЖурналаРегистрации.Информация, , , "Завершен расчет себестоимости");
    
    СформироватьДвижения();
    ЗаписьЖурналаРегистрации("Отладка.Хронология", УровеньЖурналаРегистрации.Информация, , , "Сформированы движения");
КонецПроцедуры

Разберем этот подход подробнее. Его преимущество в том, что в журнале регистрации записи будут идти строго по времени их возникновения. Если включить в сообщение текущее время с миллисекундами, мы получим детальную картину происходящего. Однако помните, что избыточное логирование может существенно замедлить работу системы.

Профилирование в 1C:EDT (Enterprise Development Tool)

Если классический «Конфигуратор» не дает нужной визуализации, обратимся к 1C:EDT. Эта среда разработки, построенная на базе Eclipse, обладает гораздо более мощным инструментарием для профилирования.

В EDT реализован режим Timeline (Временная шкала). Проанализируем его отличия:

  1. Визуализация потока: Результаты замера отображаются не просто списком, а в виде диаграммы, где по горизонтали идет время. Мы можем наглядно увидеть, какая процедура выполнялась первой, какая второй, и как долго длились паузы между ними.
  2. Дерево вызовов: Инструмент позволяет развернуть каждый процесс и увидеть последовательность вложенных вызовов в их реальном порядке исполнения.
  3. Связь с кодом: Кликнув на блок на временной шкале, мы мгновенно переходим к соответствующей строке кода модуля.

Именно использование EDT является наиболее современным способом увидеть «живую» хронологию выполнения без модификации программного кода.

Настройка Технологического журнала для трассировки

Для глубокого анализа серверных процессов, когда использование отладчика невозможно или неэффективно, мы можем использовать Технологический журнал (ТЖ). Это мощный механизм, который протоколирует все события на уровне сервера 1С.

Выясним причину популярности ТЖ для трассировки: он позволяет логировать события CALL (входящие и исходящие вызовы) и PROC (выполнение процедур встроенного языка). Для получения хронологии нам необходимо настроить файл logcfg.xml, включив вывод свойства Context.

Рассмотрим пример настройки ТЖ для отслеживания выполнения процедур:


<config xmlns="http://v8.1c.ru/v8/tech-log">
  <log location="C:\Logs\Tracing" history="2">
    <event>
      <eq property="Name" value="PROC"/>
    </event>
    <property name="All"/>
  </log>
</config>

После активации такой настройки сервер начнет записывать в текстовые файлы каждое вхождение в процедуру и выход из нее. Проанализировав эти файлы, мы получим поминутную (и даже миллисекундную) историю выполнения кода. Для удобного чтения таких «простыней» текста рекомендуется использовать специальные парсеры или консоли анализа логов.

Специализированные инструменты разработчика

Существуют готовые программные решения, которые автоматизируют процесс получения хронологии. Например, «Инструменты разработчика» позволяют выполнять трассировку более комфортно.

Разберем, что они предлагают:

Автоматизированное тестирование как источник данных

В крупных проектах для контроля качества часто применяется Vanessa Automation или аналогичные инструменты. В процессе выполнения тестов они ведут свои логи. Хотя эти логи описывают шаги (экшены) на более высоком уровне, они также являются хронологическим подтверждением выполнения кода. Если в рамках теста вызывается определенная экспортная процедура, она будет зафиксирована в отчете о выполнении сценария со всеми входящими параметрами и временем начала/окончания.

Подведем итог: Если вам нужна моментальная хронология вложенности, используйте стек вызовов. Если требуется детальный анализ последовательности выполнения строк во времени — переходите на 1C:EDT или настраивайте Технологический журнал с выводом контекста. Для быстрой отладки простых алгоритмов наиболее эффективным остается метод ручного логирования в журнал регистрации.

← На главную