Замер производительности малой кровью
— Что ты пишешь? — спросили программиста.
— Сейчас запустим — узнаем! — ответил программист.
Задача повышения производительности стояла и стоит перед нами (разработчиками) всегда. Не только в процессе написания свежего кода, но и месяцы (годы) спустя — когда нагрузка на систему естественным образом возрастает. Или неестественно — в тяжелые предновогодние дни, когда графики всех показателей похожи на карпатские горы. А особенно критичные — напоминают пик Эверест.
В общем, такие вещи надо мониторить, желательно — автоматически и постоянно, с извещениями о том, что на каком-то фронте (процессе) происходят невиданные доселе вещи — например, учет документа стал занимать 5 минут вместо 5 секунд.
Для этих целей был написан спец.инструмент — я бы даже назвал его мини-фреймворком :) Идея почерпнута из аспектно-ориентированного программирования.
По-простому говоря, очередной лог производительности, до безобразия простой в использовании:
- Имеется таблица Log, куда отписываются события трех видов — CheckPoint, Start и Finish.
- Checkpoint — идет фиксация прохождения некой контрольной точки.
- Start — начало процесса (например, начало выполнения функции).
- Finish — окончание процесса (выход из функции).
- На каждую функцию может быть только один Start и несколько Finish’ей — один в конце и один перед каждым EXIT’ом.
- Допускается вложенность процессов — т.е., если внутри одной функции идет вызов другой — это необходимо отражать в логе. При этом есть т.н. «уровень вложенности процессов», который при каждой открывающей скобке (Start) ныряет на единичку вглубь, а при каждой закрывающей скобке (Finish) выныривает обратно.
- Если за стартом сразу идет финиш — то две строки в логе только запутывают. Такая конструкция схлопывается в одну строчку со временем начала и окончания и ей присваивается тип Execution.
- В логе фиксируется:
- Тип события.
- Пользователь.
- Дата и время события.
- Дата-время начала и окончания процесса (для типа Start).
- Длительность процесса (в миллисекундах).
- Затраты на запись в лог (в миллисекундах), для того, чтобы иметь адекватную картину производительности.
- Сессия и хост.
- Имеется singleinstance-кодеюнит со следующими функциями:
- Start (txtMessage) — отписывает в лог новое событие — начало процесса.
- Finish (txtMesage) — закрывает скобку начала процесса, при этом ищется предыдущая открытая скобка с таким же сообщением (т.е. лучше, чтобы они были уникальными, но не обязательно). Рекурсия в данной версии не обрабатывается.
- Checkpoint (txtMessage) — отписывает в лог новое событие — прохождение контрольной точки.
- Имеется форма для анализа лога, в которой с помощью Indentation показана вложенность процессов.
Какие бонусы мы получаем при запуске такого протоколирования:
- Сразу видим тормозящие процессы.
- Видим вложенность вызовов функций, а в больших проектах она не всегда очевидна, учитывая огромное количество кода на Validate’ах и т.п. Я в первый день «промышленной эксплуатации» нашел процесс, в котором 3 (три) раза подряд вызывается одна и та же функция.
- Можем оценить результат оптимизации, сравнив время выполнения процесса до и после, прям как на фотках рекламы средств для похудения.
Сам процесс внедрения такого логгирования крайне прост — обертываем в скобки «Старт-Финиш» все критичные процессы, перезапускаем систему, наливаем кофе и следим за логом. Каждый найдет для себя массу интересного :)
К этому можно прикрутить еще много разных вещей, например ссылку на обрабываемый документ, по результатам работы лога можно автоматически выстроить дерево функций проекта. При должной усидчивости и смекалке можно обернуть ВСЕ функции навижна (в автоматическом режиме), запустить лог на месяц и снять дерево использованных функций самого навижна. Можно… В общем, много чего можно, но и без этого — очень полезная вещь.
Текущая версия — 0.5, скачать можно здесь — «Productivity Logger (RU)».
Замечания, здоровая критика и прочая — приветствуются :) Пишите на mailbox@naviart.ru
Инджой!

Автор: Андрей Стрельников
В области Navision - с 2003 года. Профессиональные интересы: NAV, MS SQL, .NET, BPMN, IT-менеджмент. Предметная область: логистика, финансы, склады, 3PL.
Количество статей, опубликованных автором: 86.