вопрос по отладке кода

В bpm'online 7.5 обновился инструмент профилирования клиентского кода - performanceManager. Инструмент основан на использовании UserTimingApi. Для браузеров, которые не поддерживают этот стандарт, реализован эмулятор. Профилировщик находится в модуле performancecountermanager.

Включение профайлера

Чтобы не нагружать приложение, по умолчанию функциональность профайлера отключена. Сам объект performanceManager доступен, но все его методы - пустые функции. Для включения профилировщика, необходимо добавить настройку EnablePerformanceManager в секцию appSettings в файл web.config в папке Terrasoft.WebApp:

<appSettings>
    <add key="EnablePerformanceManager" value="true"/>

Профилирование
Установка меток

Профилирование осуществляется на основе временных меток с помощью методов start() и stop(). Метод start начинает профилирование метки с указанным именем. Метод stop, соответственно, завершает профилирование. Профилирование одной метки можно выполнять несколько раз. Для этого нужно вызвать метод start еще раз.

Важно!
Если вызвать метод start для метки, для которой еще не завершена предыдущая итерация профилирования (не был вызван метод stop), запрос будет отклонен.

Например, необходимо выполнить профилирование метода, который делает некий расчет:

function calculateSomething() {
    performanceManager.start("calculateSomething");
    setTimeout(function() {
        performanceManager.stop("calculateSomething");
        console.log("done");
    }, 200);
}

Теперь для каждого вызова функции calculateSomething() будет сохраняться время начала ее работы и время завершения.

Важно!
При профилировании консоль браузера обязательно должна быть закрыта. Открытая консоль искажает замеры, т.к. выполнение javascript-кода, отображение и расчет стилей DOM-элементов замедляется в несколько раз.

Вывод результатов профилирования
Для вывода результатов профилирования используются методы getProfileInfo() и getHierarchyProfileInfo().
Метод getProfileInfo() выводит результат как есть, без дополнительной обработки.
Метод getHierarchyProfileInfo() выводит результат в иерархическом виде. Этот метод удобно использовать для профилирования сложных асинхронных объектов. Более детальная информация о функциях и их параметрах ниже.
getProfileInfo
Результатом вызова метода getProfileInfo() будет следующий вывод в консоль:
> [Имя метки 1]:
> avgDuration: [Среднее время выполнения метки 1]ms
> time: [Общее время выполнения метки 1]ms
> callsCount: [Количество итерация профилирования метки 1]

Пример вывода результата для вызова метода getProfileInfo():

function calculateSomething() {
    performanceManager.start("calculateSomething");
    setTimeout(function() {
        performanceManager.stop("calculateSomething");
        console.log("done");
    }, 200);
}
calculateSomething();
> done
calculateSomething();
> done
calculateSomething();
> done
performanceManager.getProfileInfo();
> calculateSomething:
>    avgDuration: 717ms;
>    time: 2152ms
>    callsCount: 3

Важно!
Метод setTimeout не гарантирует вызов callback-функции через переданное количество миллисекунд, этот метод гарантирует, что код выполнится не раньше чем заданный промежуток времени. Этим и объясняется большее время выполнения функции.
Для вывода полной информации о каждой итерации профилирования, нужно вызвать метод getProfileInfo() с параметром showAllCalls:
performanceManager.getProfileInfo({ showAllCalls: true });
> calculateSomething:
> avgDuration: 717ms;
> time: 2152ms
> callsCount: 3
> call №0
> duration: 523ms
> startTime: 24 m : 24 s : 367 ms
> endTime: 24 m : 24 s : 890 ms
> call №1
> duration: 763ms
> startTime: 24 m : 26 s : 128 ms
> endTime: 24 m : 26 s : 891 ms
> call №2
> duration: 866ms
> startTime: 24 m : 28 s : 30 ms
> endTime: 24 m : 28 s : 896 ms

Более подробно о выводе профайлера далее.

getHierarchyProfileInfo

Метод getHierarchyProfileInfo() выводит результат в иерархическом виде. Иерархия меток строится на основе имени метки и разделителя (по умолчанию "_"). Т.е. имена меток интерпретируются как полное имя с указанным пространством имен (namespace).
Например есть метка с именем "MyCommonModule_MySectionModule_MyModule". Профайлер будет интерпретировать это имя так: в пространстве имен "MyCommonModule" есть пространство имен "MySectionModule" в котором есть метка "MyModule". Будет построена следующая структура:
MyCommonModule = {
MySectionModule: {
MyModule: Метка
}
}
Если при профилировании встретится другая метка с именем "MyCommonModule_MySectionModule2_MyModule3", структура перестроится следующим образом:
MyCommonModule = {
MySectionModule: {
MyModule: Метка 1
},
MySectionModule2: {
MyModule3: Метка 2
}
}
Количество пространств имен не ограничено.
Таким образом можно визуально отобразить вложенность вызова меток. Пример - загрузка модулей приложения.
В файле core.js уже установлены метки для профилирования процесса загрузки модулей. Приложение bpm'online при загрузке модулей формирует идентификаторы модулей путем добавления нижнего подчеркивания к идентификатору родительского модуля и имени загружаемого модуля (moduleId = ownerModule.id + "_" + module.name). Вывод информации о профилировании загрузки модулей удобно делать в иерархическом виде.
Пример вывода результатов при вызове метода getHierarchyProfileInfo():

 performanceManager.getHierarchyProfileInfo();
>    ViewModuleWrapper
>        loadModule
>            avgDuration: 10392ms
>            time: 10392ms
>            callsCount: 1
>    ViewModule
>        loadModule
>            avgDuration: 10691ms
>            time: 10691ms
>            callsCount: 1
>        NavigationModule
>            loadModule
>                avgDuration: 618ms
>                time: 618ms
>                callsCount: 1
>        ProcessModuleV2
>            loadModule
>                avgDuration: 4538ms
>                time: 4538ms
>                callsCount: 1

Метод так же поддерживает опцию showAllCalls, которая выводит информацию о всех итерациях профилирования для каждой метки.

API
performanceManager имеет следующее API:

• start(markName) - Начинает профилирование метки.
• stop(markName) - Завершает профилирование метки.
• clear(markName) - Удаляет метку
• clearAll() - Удаляет все метки.
• getProfileInfo(config) - Выводит результаты профилирования в плоском виде.
• getHierarchyProfileInfo(config) - Выводит результаты профилирования в иерархическом виде.
• setLogObject(logObbject) - Устанавливает объект логирования.

Методы, которые остались от старого профайлера и не поддерживаются больше в версиях выше 7.5.0:

• startCounter
• stopCounter
• startAsyncCounter
• stopAsyncCounter
• setTimeStamp
• getTimeStamp
• getTimeSpan
• clearTimeStamp
• clearAllTimeStamps
• start(markName)

start(markName)
Начинает профилирование метки с переданным именем.. Если метки не существует - она создается. Если метка существует и для нее предыдущая итерация профилирования не закончена, запрос на профилирование отклоняется.
stop(markName)
Завершает профилирование метки с переданным именем.. Если метки нет или предыдущая итерация профилирования уже завершена, запрос отклоняется.
clear(markName)
Удаляет метку с переданным именем.
clearAll()
Удаляет все метки.
setLogObject(logObbject)
Устанавливает объект логирования.
getProfileInfo(config) / getHierarchyProfileInfo(config)
Выводит результаты профилирования. Разница между этими методами лишь в форме вывода результата. В качестве аргумента, методы принимают конфигурационный объект, с помощью которого можно настраивать или фильтровать результат.
Параметры конфигурационного объекта
filter
Фильтр для вывода меток. Фильтр применяется для каждой метки при выводе результата. Может быть одним из двух типов:
Функция - фильтр должен возвращать булево значение, в качестве аргумента передается копия метки.
Строка - Выполняется проверка соответствия строки регулярному выражению avgDurationLimit:\s*(\d+)\s* (avgDurationLimit: Number)
Строка соответствует регулярному выражению - выводится результат только для тех меток, среднее время выполнения которых превышает лимит.
Строка не соответствует регулярному выражению - выводится результат только для тех меток, в имени который содержится переданная подстрока.
showFlat
Признак вывода результата в плоском виде. Является предустановленным значением для метода getProfileInfo(), методом getHierarchyProfileInfo() не используется.
showByNamespace
Признак вывода результата в иерархическом виде. Является предустановленным значением для метода getHierarchyProfileInfo(), методом getProfileInfo() не используется.
namespaceSeparator
Разделитель для построения иерархии меток. Значение по умолчанию "_". Используется только методом getHierarchyProfileInfo().
showAllCalls
Признак того, что надо выводить все итерации замеров. Значение по умолчанию false.
hightlightDurationOverflow
Признак того, что надо подсвечивать значения, которые превышают лимит заданный настройкой durationLimit. Значение по умолчанию false.
Проверяется как время профилирования каждой итерации, так и среднее время профилирования метки.
durationLimit
Лимит значения для подсветки результатов. используется в связке с настройкой hightlightDurationOverflow.

Настройки hightlightDurationOverflow и durationLimit работает не во всех браузерах. Поддерживаемые браузеры: Chrome, FireFox, Safari.

Механизм performanceManager
В основе механизма работы performanceManager-а лежит W3C-стандарт UserTimingApi. Браузеры реализуя этот стандарт предоставляют объект window.performance. Для performanceManager важно наличие следующих методов:
now - возвращает количество миллисекунд прошедших с момента начала загрузки страницы. Использует DOMHighResTimeStamp.
mark - сохраняет временную метку и сохраняет ее с параметром startDate равным now().
measure - выполняет расчет количества миллисекунд между двумя временными метками.
getEntriesByName - возвращает массив временных меток с указанным именем.
clearMeasures - удаляет сохраненный результат расчета с указанным именем. Если имя не передано, удаляет все результаты.
clearMarks - удаляет временную метку с указанным имеем. Если имя не передано, удаляет все метки.
Не все браузеры поддерживают UserTimingApi, поэтому был реализован эмулятор, который работает на основе объекта Date. При инициализации, performanceManager проверяет наличие объект performance, а также наличие перечисленных методов у этого объекта. Если какого-либо метода нет, либо нет объекта performnce - подключается эмулятор.
Далее вводится внутренний класс Mark (метка), который может хранить в себе несколько замеров.

Свойства класса Mark:

• name - имя метки.
• measurements - массив замеров метки.
• requiredCalculateProperties - массив свойств, необходимых для расчета показателей.
• durationOverflowHighlightStyle - стиль для подсветки результатов при выводе.
• Методы класса Mark:
• clear - Удаляет все временные метки и сохраненные результаты расчета для метки (mark и measure).
• isCalculated - Возвращает признак того, что все показатели для метки расcчитаны (рассчитано время замера и среднее время замера метки).
• isMeasureCalculatable - Возвращает признак того, переданный замер уже расcчитан (рассчитано время замера endTime - startTime).
• isCalculatable - Возвращает признак того, что метка рассчитываемая (При фильтрации выводимого результата передается копия метки из которой удаляются имена временных меток, что бы случайно не удалить результаты вызовом метода calculate(). Метод проверяет наличие этих свойств.).
• calculate - Выполняет расчет показателей метки и ее замеров.
• copy - Возвращает Копию метки и ее замеров.
• createMeasure - Создает объект замера для метки и возвращает его (Для созданного замера генерируются имена временных меток для времени старта замера, времени завершения замера и результата расчета).
• getLastMeasure - Возвращает последний объект замера для метки.
• isStopped - Возвращает признак того, что для метки в данный момент закончено профилирование и установлены все временные метки.
• log - Выполняет логирование метки и ее замеров.
• logMeasurements - Выполняет логирование замеров метки.
• logMetric - Выполняет логирование метрики метки или замера.

Чтобы профилирование не влияло на работу приложения, расчет всех показателей выполняется при выводе результата. При вызове метода start() устанавливается временная метка начала замера, а при вызове метода stop - устанавливается временная метка завершения замера. Другими словами вызов методов start и stop создают объект класса Mark и устанавливают временный метки.
При вызове метода getProfileInfo() либо метода getHierarchyProfileInfo() выполняется расчет показателей всех меток, для которых завершено профилирование. После, анализируется переданный конфигурационный объект и происходит вывод результатов.
Метод getProfileInfo() перебирает все метки, применяя фильтр, и выводит результат.
Метод getHierarchyProfileInfo() сначала строит объект иерархии меток, в процессе построения которого выполняет фильтрацию, после чего выводит результат.

Не понял - это похоже для web-клиента? У нас толстый-клиент.

Толстого клиента для 7.X нет (кроме Mobile). У вас Terrasoft 3.X? Об отладке для неё есть статья с описанием более лёгких аналогов Студии.

В конфигурации также есть стандартный скрипт scr_DebugUtils. Тут некоторое обсуждение. И ещё есть такая сторонняя разработка scr_ScriptExecutionAnalysis.

"Зверев Александр" написал:

Толстого клиента для 7.X нет (кроме Mobile). У вас Terrasoft 3.X? Об отладке для неё есть статья с описанием более лёгких аналогов Студии.

В конфигурации также есть стандартный скрипт scr_DebugUtils. Тут некоторое обсуждение. И ещё есть такая сторонняя разработка scr_ScriptExecutionAnalysis.