Добрый день, подскажите, существует ли функционал или инструменты для диагностики и оценки производительности приложения?

Какие-нибудь дашборды или графики?

Спасибо.

Нравится

4 комментария
Лучший ответ

Добрый день.

На текущий момент подобный функционал отсутствует в приложении Creatio. 

Предположительно, через несколько версий, появится нечто подобное.

Частично - в Process log есть поле с продолжительностью работы бизнес-процессов. По нему можно отслеживать, какие элементы тормозят больше всего. Но надо учитывать, что часть элементов - это взаимодействие с пользователем

Добрый день.

На текущий момент подобный функционал отсутствует в приложении Creatio. 

Предположительно, через несколько версий, появится нечто подобное.

Владимир Соколов,

Спасибо.

Также, если сайт развернут on-site, то можно с помощью инструментов отладки запросов СУБД анализировать длительность выполнения запросов. Например, для MS SQL это SQL Profiler.

Показать все комментарии

 
Заказчик выдвинул требования значительно ускорить быстродействие выполнения определенного функционала.

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

Функционал в моем случае: импорт прайс-листа из Excel по производителю с большим количеством строк.

В результате оптимизации, удалось ускорить импорт прайс-листа приблизительно раза в четыре (был 1 час, стало 15 минут).

Вот набор этих методов

(прикрепил ниже в архиве scr_ScriptExecutionAnalysis.zip).

//-----------------------------------------------------------------------------
// scr_ScriptExecutionAnalysis
//-----------------------------------------------------------------------------

var ScriptExecutionAnalysis = {};

function _StartTiming(Caller, IsMain) {
     if (!Caller) {
          return;
     }
     var Name;
     if (typeof(Caller) == 'function') {
          Name = "[fn]" + Caller.toString().split('(')[0].substring(9);
     } else {
          Name = Caller;
     }
     if (!ScriptExecutionAnalysis[Name]) {
          ScriptExecutionAnalysis[Name] = {};
          ScriptExecutionAnalysis[Name].TotalDuration = 0;
          ScriptExecutionAnalysis[Name].NumberOfCalls = 0;
          ScriptExecutionAnalysis[Name].MinDuration = 0;
          ScriptExecutionAnalysis[Name].MaxDuration = 0;
          ScriptExecutionAnalysis[Name].WasZeroDuration = false;
     }
     if (IsMain) {
          ScriptExecutionAnalysis.IsMainName = Name;
     }
     ScriptExecutionAnalysis[Name].Start = (new Date()).getTime();
}

function _EndTiming(Caller) {
     if (!Caller) {
          return;
     }
     var Name;
     if (typeof(Caller) == 'function') {
          Name = "[fn]" + Caller.toString().split('(')[0].substring(9);
     } else {
          Name = Caller;
     }
     if (!ScriptExecutionAnalysis[Name]) {
          return;
     }
     ScriptExecutionAnalysis[Name].End = (new Date()).getTime();
   
     var Duration = ScriptExecutionAnalysis[Name].End - ScriptExecutionAnalysis[Name].Start;
     if (Duration == 0) { ScriptExecutionAnalysis[Name].WasZeroDuration = true }    
         
     if ((ScriptExecutionAnalysis[Name].MinDuration == 0 &&
          !ScriptExecutionAnalysis[Name].WasZeroDuration) ||
          Duration ScriptExecutionAnalysis[Name].MinDuration) {
          ScriptExecutionAnalysis[Name].MinDuration = Duration;
     }
     if (Duration > ScriptExecutionAnalysis[Name].MaxDuration) {
          ScriptExecutionAnalysis[Name].MaxDuration = Duration;
     }
     ScriptExecutionAnalysis[Name].TotalDuration += Duration;
     ScriptExecutionAnalysis[Name].NumberOfCalls++;    
}

function _CreateScriptExecutionAnalysisReport() {
     var Item;
     var Name;
     var Main;
     if (ScriptExecutionAnalysis.IsMainName) {
          Main = ScriptExecutionAnalysis[ScriptExecutionAnalysis.IsMainName];
     }
     var FString = "[%1] TotalDuration - %2 ms, NumberOfCalls - %3, MinDuration - %4 ms, MaxDuration - %5 ms, AverageDuration - %6 ms";
     for (Name in ScriptExecutionAnalysis)   {
          if (Name == 'IsMainName') {
               continue;
          }
          Item = ScriptExecutionAnalysis[Name];
          Log.Write(1, FormatStr(FString,
               Name, Item.TotalDuration, Item.NumberOfCalls, Item.MinDuration, Item.MaxDuration,
               Math.round(Item.TotalDuration / Item.NumberOfCalls * 100) / 100) +
               (Main ? ", Portion - " + Math.round(Item.TotalDuration / Main.TotalDuration * 1000) / 10 + " %": ""));
     }
     ScriptExecutionAnalysis = {};
}

function FormatStr(Str) {
     var Ln = arguments.length;
     for (var i = 1; i Ln; i++ ) {
          Str = Str.replace(new RegExp('%' + i, 'g'), arguments[i]);
     }
     return Str;
}

Описание методов:

_StartTiming(Caller, IsMain) - используется для указания начала отсчета времени.
Аргумент Caller может быть либо объект функции, в которой вызывается этот метод, а может быть и просто текстовая строка (тэг) для унификации этого замера времени. Унификация используется при построении отчета.
Аргумент IsMain - признак того, что метод вызывается из основной функции и нужен для подсчета суммарного времени работы функционала, а суммарное время расчеты функционала в свою очередь используется для определения процентного отношения вызова функции к общему времени выполнении функционала (в отчете).
_EndTiming(Caller) - используется для указания окончания замера времени.
Аргумент Caller указывается по аналогии как в методе _StartTiming.
Каждому вызову метода _StartTiming(Caller) должен соответствовать вызов метода _EndTiming(Caller) с таким же аргументом Caller. Это нужно для построения отчета и вообще для корректного замера времени.
_CreateScriptExecutionAnalysisReport() - метод выводит в лог Террасофт отчет по выполнению функций.

Пример использования в коде:

function MainFunction() {
     _StartTiming(arguments.callee, true);
     ...
     InnerFunction();
     ...
     _EndTiming(arguments.callee);
     _CreateScriptExecutionAnalysisReport();
}

function InnerFunction() {
     _StartTiming(arguments.callee);
     ...
     _StartTiming('ScriptBlock1');
     ...
     _StartTiming('ScriptBlock2');
     ...
     _EndTiming('ScriptBlock2');
     ...
     _StartTiming('ScriptBlock3');
     ...
     _EndTiming('ScriptBlock3');
     ...
     _EndTiming('ScriptBlock1');
     ...
     _EndTiming(arguments.callee);
}

Пример отчета из "реальной жизни"

прикрепил ниже (Report.txt).
Пару строк из отчета:

[[fn]PriceListImport] TotalDuration - 9907 ms, NumberOfCalls - 1, MinDuration - 9907 ms, MaxDuration - 9907 ms, AverageDuration - 9907 ms, Portion - 100 %
[[fn]InitUpdateQuery] TotalDuration - 652 ms, NumberOfCalls - 46, MinDuration - 0 ms, MaxDuration - 31 ms, AverageDuration - 14.17 ms, Portion - 6.6 %
[ProcessOneRecord] TotalDuration - 4219 ms, NumberOfCalls - 49, MinDuration - 31 ms, MaxDuration - 329 ms, AverageDuration - 86.1 ms, Portion - 42.6 %

Расшифровка отчета:

TotalDuration - суммарное время на вызов этой функции/участка кода;
NumberOfCalls - количество вызовов этой функции / прохождения участка кода;
MinDuration - минимальное время выполнения этой функции/участка кода;
MaxDuration - максимальное время выполнения этой функции/участка кода;
AverageDuration - среднее время выполнения этой функции/участка кода;
Portion - процентное отношение суммарного вызова этой функции/участка кода к суммарному времени вызова основной функции.

В отчете [fn] обозначает, что это функция. Отсутствие [fn] обозначает, что это участок кода, который характеризуется указанным тэгом.

PriceListImport - это в моем примере основная функция (видно даже по значению Portion = 100%)
[fn]InitUpdateQuery - это вызов функции InitUpdateQuery, Portion = 6.6 %. Возможно, стоит на эту функцию обратить внимание с таким процентным соотношением.
ProcessOneRecord - участок кода с тэгом 'ProcessOneRecord'. Portion = 42.6 % - большой вес в общем функционале, стоит хорошенько пересмотреть этот участок кода.

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

Нравится

Поделиться

1 комментарий

Спасибо)) :twisted:

Показать все комментарии

Добрый день, коллеги.
Столкнулся с жалобами пользователей на производительность ПО Terrasoft CRM (да и сам стал замечать). Чаще всего жалуются на долгое открытие карточек объектов. Так вот, вопрос в чем: пробовал ли кто-нибудь копать в сторону профилирования JScript-кода Terrasoft и подсчета времени какая функция сколько работает?

Нравится

9 комментариев

Есть scr_DebugUtils для тестирования отдельных функций. Также можно пройти процесс открытия в отладке, поставив debugger на OnPrepare и посмотреть, какой шаг долго срабатывает.

Здравствуйте.
Специально для таких целей инструментарий не создавали, но можно воспользоваться, например, той же Visual Studio: http://msdn.microsoft.com/ru-RU/library/dd264908.aspx. Так же желательно определить на каком этапе возникает задержка. Кроме Jscript это может быть и сеть и сервер. Для версии 5.4 на нашем ресурсе есть скрипт, который показывает разбивку по времени (клиент, сеть, сервер) выполнения того или иного действия: http://www.community.terrasoft.ua/blogs/8480. Ещё можно использовать такой инструмент как fiddler.

"Котенко Александр" написал:Для версии 5.4

Автора интересует 3.Х.

"Котенко Александр" написал:Так же желательно определить на каком этапе возникает задержка

Вот мне и нужно понять, где задержка: сервер БД или код.
Можете поподробнее рассказать как можно применять Visual Studio для профилирования JScript кода конфигурации Terrasoft CRM? Или то что вы написали относится исключительно к BPM Online?
У меня используется платформа Terrasoft 3.3.2.

Тут и тут и тут описано. Важно оттуда:

"Лучкив Александр" написал:Часто при разработке конфигурации необходимо ставить точки останова (Breakpoint) в скриптах для пошаговой отладки.

Для этого достаточно написать в скрипте команду:
debugger;

"Пунько Наталия" написал:Активируйте отладчик скриптов, установив ключ реестра JITDebug
Windows Registry Editor Version 5.00

[HKEY_CURRENT_USER\Software\Microsoft\Windows Script\Settings]
"JITDebug"=dword:00000001
Прикрепленный файл
enabledebugger.rar

"Зверев Александр" написал:Тут и тут и тут описано.

Спасибо конечно, но как отлаживать конфигурацию Terrasoft я знаю. Я не знаю как профилировать код конфигурации и возможно ли это для Terrasoft CRM. Вот это относится только к BPM Online:
"Котенко Александр" написал:Специально для таких целей инструментарий не создавали, но можно воспользоваться, например, той же Visual Studio:
???

См. scr_DebugUtils. Инструменты BPMonline никак не связаны с 3.Х.

Когда-то тоже сталкивался с похожей проблемой.
Сделал некоторые заметки, вот они:
Ускорение работы CRM - тут есть ссылки на другие публикации

Тогда я пошел довольно не простым путем - смотрел где узкое место с помощью SQL Profiler, описал вот здесь:
Анализ быстродействия CRM с помощью SQL Profiler
С помощью этого метода я четко смог увидеть где проблема: на стороне скриптов и компьютера пользователя или на стороне сервера.

Только что добавил запись в блог с описанием разработанного мной функционала для поиска узких мест в выполнении функций:
Анализ времени выполнения скриптов и поиск "узкого" места в функционале

Показать все комментарии