Средства мониторинга производительности
Администраторы баз данных OpenEdge обычно используют для мониторинга и анализа производительности виртуальные системные таблицы (VST) и утилиту PROMON, а также ряд других методов и средств, предназначенных для оценки производительности системы в целом. Рассмотрение этих методов и средств выходит за рамки данного курса. Следует лишь иметь в виду, что они позволяют выявить и устранить все узкие места в программно-аппаратной среде приложения, а также выявить проблемные места в самом приложении. А вот для решения проблем в приложении администратор базы данных обратится к разработчику – то есть к Вам.
Как правило, первичная идентификация узкого места в приложении не дает точной информации, в какой именно программе теряется время. Вам могут просто сказать: при начислении процентов по вкладам… Ваша первая задача – точно определить программу (программы), в которой имеется проблема.
Определение критических программ
Для выявления критических с точки зрения производительности программ можно использовать стартовый параметр –yx (Statistics With Cross-reference). Этот параметр включает сбор статистики по вызовам процедур и записывает ее в файл. Смотри также описание параметров –y, -yc и –yd в документации по OpenEdge и в таблице (Таблица 12).
Эта информация позволят анализировать:
- Количество вызовов процедур за определенный период времени.
- Время исполнения процедур.
- Частоту подкачки процедур в кэш (файл SRT).
По умолчанию статистика записывается в файл proc.mon в текущем рабочем каталоге. Указать другое место и имя для файла статистики можно с помощью переменной среды окружения PROCMON.
Запись в файл выполняется по завершению сессии. Для принудительной записи статистики в файл можно использовать оператор SHOW-STATS. Выполнение SHOW-STATS с опцией CLEAR сбрасывает все счетчики и таймеры статистики в ноль. Оператор SHOW-STATS также записывает значение атрибута SESSION:STARTUP-PARAMETERS в файл client.mon.
Таблица 12. Параметры сбора статистики
|
Параметр |
Описание |
| Statistics (-y) | Выполняет сбор статистики по использованию процедур в течение сессии OpenEdge и записывает ее в выходной файл (по умолчанию в client.mon в текущем рабочем каталоге). Используйте оператор SHOW-STATS для выполнения записи без выхода из сессии. |
| Statistics with CTRL+C (-yc) | Выполняет сбор статистики аналогично параметру -y, но позволяет сохранять статистику во время сессии с помощью комбинации CTRL+C. Используйте этот параметр, если Вы не можете использовать оператор SHOW-STATS (например, в Runtime среде). |
| Segment Statistics (-yd) | Выполняет сбор статистики по сегментам r-кода и записывает ее в выходной файл (по умолчанию в client.mon в текущем рабочем каталоге). Показывает разбивку r-кода по типам сегментов, включая количество и размер сегментов. Показывает также статистику по использованию файла подкачки r-кода по типу сегмента, типу доступа и объему прочитанных/записанных данных. |
| Statistics with
Cross-reference (-yx) |
Выполняет сбор статистики по вызовам процедур и записывает ее в выходной файл (по умолчанию в proc.mon в текущем рабочем каталоге). Используйте этот параметр для получения ответа на вопросы:
• Сколько раз вызывалась процедура? • Сколько времени исполнялась процедура? • Как часто процедура записывалась (читалась) в (из) файл (а) подкачки? |
Примечания:
- Если оператор SHOW-STATS выполнен без указания параметра Statistics (-y), AVM (ABL Virtual Machine, Engine, движок – исполняющая код подсистема OpenEdge) открывает файл client.mon, как если бы Вы динамически указали –y. Однако, первый оператор SHOW-STATS не записывает никакой статистики в client.mon; только открывает файл. Последующие операторы SHOW-STATS записывают статистику в файл. Значение атрибута SESSION:STARTUP-PARAMETERS в этом случае в файл не записывается.
- Если Вы хотите получать статистику по вызовам процедур, параметр –yx (Statistics with Cross-Reference) должен быть явно указан при запуске сессии.
Пример файла статистики приведен на рисунке Рис. 19. Колонки в файле имеют следующие значения:
- Caller – имя вызывающей процедуры. <top> означает, что процедура вызвана из редактора.
- Callee – имя вызываемой процедуры.
- Load Size – размер загружаемой программы в байтах. 0 означает, что программа не была скомпилирована, или r-код уже находился в памяти.
- Calls – количество вызовов вызываемой процедуры из вызывающей.
- Rd Bytes – первоначально равно Load Size. Но если процедура выгружалась в файл подкачки (SRT), то при каждой повторной загрузке ее в память, добавляется объем данных, считанных из файла подкачки.
- Reread – количество байтов, считанное из файла подкачки для восстановления вызывающей программы, если она была выгружена.
- Time – Общее время исполнения вызываемой процедуры.
Wed Feb 6 16:19:05 2002 Procedure call statistics: 16:19:21 Caller Callee Load Size Calls Rd Bytes Reread Time top _edit 3789 1 3789 0 16 _edit _adeload 9542 1 9542 0 10 _edit _prostar 6931 1 6931 0 23 _prostar _login 5087 1 5087 0 73 _edit _setcurs 562 2 562 0 20 _edit _proedit 181029 1 181029 0 12180 _proedit _toollic 2570 1 2570 0 268 _proedit _tmpfile 1510 2 1510 0 140 _proedit _kvlist 2624 2 2624 0 26 _proedit _setcurs 562 4 0 0 63 _proedit _adehelp 3279 1 3279 0 97
Рис. 19. Файл статистики вызовов процедур
Итак, анализ файла статистики позволяет вам выявить наиболее часто и долго исполняющиеся процедуры. Теперь требуется найти самые неэффективные участки кода внутри процедуры.
Трассировка и функция ETIME
Простейшим методом трассировки программы с целью поиска неэффективных участков кода является вставка сообщений в текст программы, содержащих идентификатор точки выдачи сообщения и время.
Метод простой, требует некоторых затрат на вставку сообщений (и последующее их удаление), но обеспечивает достаточную эффективность поиска – при условии правильного выбора «контрольных точек».
Для ускорения процесса поиска может быть применен итерационный подход: создав для начала несколько контрольных точек можно сузить область поиска, добавляя затем новые контрольные точки только в «подозрительную» часть кода.
Сообщения лучше выдавать не на экран, а в текстовый файл. Для выдачи сообщений может быть использован простой include-файл, например (Рис. 20).
/*
trace.i – Program tracing
Set ETIME(TRUE) before first use
Usage: {trace.i “CheckPoint One” [variable 1 [variable 2]]}
*/
OUTPUT TO VALUE("/home/" + LC(getUserid()) + "/trace.log") APPEND.
MESSAGE PROGRAM-NAME(1) {1} ‘Time:’ ETIME() {2} {3}.
OUTPUT CLOSE.
Рис. 20. Выдача сообщений трассировки
Измерение времени при трассировке выполняется с помощью функции ETIME. Функция ETIME возвращает целое (INT64) значение времени в миллисекундах, прошедшего с начала сессии ABL или с момента последнего сброса времени в ноль. Для сброса времени ETIME в ноль, функция должна быть вызвана с положительным логическим значением в качестве параметра: ETIME (TRUE).
Пример использования трассировки показан на Рис. 21:
PROCEDURE process-web-request:
DEFINE VARIABLE lcData AS CHARACTER NO-UNDO.
ETIME(TRUE).
{trace.i "Trace Start"}
lcPage = get-field("prog").
lcFunction = get-field("func").
RUN outputHeader.
{trace.i "Point 1"}
{&OUT}
"<HTML>":U SKIP
"<HEAD>":U SKIP
"<TITLE> {&FILE-NAME} </TITLE>":U SKIP
'<script>
function searchButton() ~{
lchref = location.pathname;
lchref = lchref + "?prog='+ lcPage + '&func=' +
lcFunction + '&Navigate=Search&SearchVal=" +
thisForm.search.value;
location.replace(lchref);
~}
</script>'
"</HEAD>":U SKIP
"<BODY>":U SKIP
'<FORM method="POST" name="thisForm">':U SKIP.
RUN generateTitle (lcFunction).
{trace.i "Point 2"}
FIND FIRST wb_page WHERE wbp_name = lcPage NO-LOCK.
lcData = wbp_dataobject.
startDataObject(lcData).
lhData = dynamic-function("getDataSource").
iTableRows = wbp_rows.
{trace.i "Point 3"}
IF wbp_type = "Browse" THEN RUN generateBrowse(iTableRows).
ELSE IF wbp_type = "Detail" THEN RUN generateDetails.
{trace.i "Point 4"}
{&OUT}
"</FORM>":U SKIP
"</BODY>":U SKIP
"</HTML>":U SKIP.
setContext().
IF anyMessage() THEN showDataMessages().
{trace.i "Point 5"}
END PROCEDURE.
Рис. 21. Пример трассировки
process-web-request webmain1.p Trace Start Time: 18 process-web-request webmain1.p Point 1 Time: 36 process-web-request webmain1.p Point 2 Time: 37 process-web-request webmain1.p Point 3 Time: 195 process-web-request webmain1.p Point 4 Time: 238 process-web-request webmain1.p Point 5 Time: 240
Рис. 22. Результат трассировки
Результаты трассировки (Рис. 22), показывает, что максимальное время было затрачено на выполнение процедуры между точками 2 и 3 – так что на следующем этапе необходимо выполнить трассировку этой части более подробно.
LOG MANAGER
Для выполнения трассировки Вы также можете использовать встроенные в OpenEdge средства журнализации. Управление журнализацией возможно через стартовые параметры сессии или через системный хэндлер LOG-MANAGER. Подробно средства журнализации описаны в руководстве «OpenEdge Development: Debugging and Troubleshooting».
Средства журнализации позволяют протоколировать различные события, возникающие при работе приложения OpenEdge, в том числе и трассировку вызовов процедур, обработка такого журнала не очень удобна.
Для наших целей можно использовать возможность записи в файл журнала пользовательских сообщений. Для этого используется метод WRITE- MESSAGE() системного хэндлера LOG-MANAGER.
Примечание: Для интерактивного или пакетного клиентов, метод WRITE-MESSAGE() записывает сообщения в файл клиентского журнала, указанный атрибутом LOGFILE-NAME или параметром запуска -clientlog. Для WebSpeed-агентов и агентов AppServer метод записывает сообщения в файл журнала сервера (server log).
Синтаксис вызова метода:
LOG-MANAGER:WRITE-MESSAGE( msg-exp [, subsys-expr ] )
Вызов вида:
LOG-MANAGER:WRITE-MESSAGE(“Got here: x=” + string(x), “DEBUG1”).
приведет к появлению в файле журнала следующей строки:
[06/10/31@13:19:19.742-0500] P-003616 T-001984 1 4GL DEBUG1 Got here: x=5
Естественно, для того, чтобы сообщение было записано, необходимо, чтобы журнализация была включена. Для этого достаточно указать имя файла журнала:
LOG-MANAGER:LOGFILE-NAME = “my.log”.
Это включит журнализацию, и установит ее уровень в 2 (Basic).