О профилировщике кода MT5 - страница 4

Новый комментарий
 
Renat Fatkhullin:

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

Иначе это никуда не годится по маленьким кускам вашего кода отвечать за отчеты профайлера. Там за бортом громадная работа оптимизатора, который весь ваш код превращает в совершенно другое перемешанное и встроенное представление.

Понимаю, что без воспроизведения точных ответов не будет.

Стандартные коды вряд ли возьмусь профилировать, но постараюсь давать воспроизводимые куски.

 
Andrey Khatimlianskii:

Благодарю за ответы!

1) На простом коде вряд ли воспроизведу, да. А весь проект отдать не готов.

2) В этом конкретном случае — согласен.

Но есть еще много других классов, в которых используется такая же или похожая проверка, и без TimeCurrent или GetTickCount не обойтись.
Как оптимизировать их вызов, чтобы не запрашивать то же значение несколько раз?

И действительно ли TimeCurrent настолько тяжелый, что может быть заметен на фоне действительно тяжелых расчетов (хоть и проводимых раз в 1 или 5 минут)?
Или я опять неправильно понял, и 38.16% Total CPU / 26.07% Self CPU занимала сама проверка if (без учета вызова функции TimeCurrent)? Но тогда почему это так?!


1) Это не помогает понять, почему такая прожорливая открывающая скобка. Как это интерпретировать?

2) Про SelfCPU теперь ясно, спасибо. Это нагрузка на код функции без учета вызываемых функций.

Это объясняет и низкий SelfCPU у строки с iTime — до нее доходило очень редко, она просто редко вызывалась.

Но почему при этом такой большой TotalCPU? Или он показывает на нагрузку всех iTime (и других CopyXXX функций?) во всей программе?

  1. Отрывающая скобка - считайте её прологом функции, как правило занимающий несколько инструкций размещения и в особенности инициализации локальных переменных.
    Стоит обратить внимание на объём локальных переменных функции, нужно учитывать, что объём может увеличиться из-за инлайнинга вызываемых
    Если функция потребляет более 4Кб под локальные, то для обеспечения стековой памяти вызывается служебная функция - это суровая правда натива и от этого не избавиться

  2. SelfCPU не должен учитывать вызовы, иначе он будет просто дублировать TotalCPU и время собственных инструкций будет размыто временем вызываемых функций
    TotalCPU для строки - это "время" только этой строки
 
Alain Verleyen:

Разве не всегда должно быть 100%? Или даже немного меньше, учитывая также @global_initializations и @global_deinitializations.

Здесь больше 102% ...(Build 3003 on historical data).

По старому профилировщику в статье указывалось, что может быть больше

Профилирование дает нам важную статистику: сколько раз каждая из функций была вызвана, сколько времени было затрачено на ее выполнение. Возможно, вас немного собьет с толку статистика в процентах. Здесь нужно понимать, что статистика не рассматривает вложенность функций, поэтому сумма всех процентов будет много больше 100%.

 
Vasiliy Pushkaryov :

По старому профилировщику в статье указывалось, что может быть больше

Спасибо. Но, насколько я понимаю, с новым профилировщиком все должно быть иначе. Никакие отговорки недопустимы, ошибка есть ошибка.
 
Ilyas:
  1. Отрывающая скобка - считайте её прологом функции, как правило занимающий несколько инструкций размещения и в особенности инициализации локальных переменных.
    Стоит обратить внимание на объём локальных переменных функции, нужно учитывать, что объём может увеличиться из-за инлайнинга вызываемых
    Если функция потребляет более 4Кб под локальные, то для обеспечения стековой памяти вызывается служебная функция - это суровая правда натива и от этого не избавиться

  2. SelfCPU не должен учитывать вызовы, иначе он будет просто дублировать TotalCPU и время собственных инструкций будет размыто временем вызываемых функций
    TotalCPU для строки - это "время" только этой строки

1) В теле функции объявляется только одна double переменная (не считая параметра функции const bool simulated).

2) То есть, процессор 55% времени получал iTime( m_symbol, PERIOD_CURRENT, 0 ) для одного из 11 рабочих инструментов (именно для него срабатывало условие "m_CloseOnFirstTickOnly || m_OpenOnFirstTickOnly")?

Или имеется в виду режим "Functions by Calls" (я показывал не его)?


Постараюсь сделать воспроизводимый отрывок кода с непонятными мне результатами, чтобы разговаривать предметно.

 

Прошу помочь с интерпретацией данных профайлера на простом примере.

#include <fxsaber\Usage\Usage.mqh> // https://www.mql5.com/ru/code/33875

const bool Init = EventSetMillisecondTimer(1);

void f()
{
  Sleep(1);
}

void OnTimer()
{
  _USAGE
  
  f();
  Sleep(2);
}


Все выглядит, как лютый бред.

  • Sleep(2) напрочь отсутствует.
  • По какой-то причине USAGE выжирает в несколько раз больше, чем Sleep(1).


Очень стараюсь въехать, не выходит пока.


ЗЫ Пробовал замену Sleep.

void Sleep2( uint Interval )
{
  const ulong StartTime = GetMicrosecondCount();
  
  Interval *= 1000;
  
  while (GetMicrosecondCount() - StartTime < Interval)
    ;
}

#define Sleep Sleep2

Все также непонятные значения профайлера.

 
fxsaber #:

Прошу помочь с интерпретацией данных профайлера на простом примере.


Все выглядит, как лютый бред.

  • Sleep(2) напрочь отсутствует.
  • По какой-то причине USAGE выжирает в несколько раз больше, чем Sleep(1).

На MT4 этот же код выдает абсолютно логичные результаты.


Что делаю не так в MT5?

ЗЫ Последний билд MT5 с профилировщиком из MT4 - b2595 (b2593 - если выдает Internal compiler error).

 
А почему вы думаете, что написанный вами код равен тому, что фактически исполняется?

Сколько раз повторять про сверхоптимизацию и смешивание результирующего кода? Приставки inlined на это четко указывают.

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

Профайлер эффективно ищет статистически значимые затратные места зверски оптимизированного кода, а не является построчным поводырем исходного кода.

Потому как ваш код имеет мало общего с реально исполняемым.




 
Renat Fatkhullin #:
А почему вы думаете, что написанный вами код равен тому, что фактически исполняется?

Сколько раз повторять про сверхоптимизацию и смешивание результирующего кода? Приставки inlined на это четко указывают.

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

Профайлер эффективно ищет статистически значимые затратные места зверски оптимизированного кода, а не является построчным поводырем исходного кода.

Потому как ваш код имеет мало общего с реально исполняемым.

Мне пришлось написать столь простой пример, т.к. невозможно было объяснить значения профайлера на боевом советнике с значительным по размеру исходным кодом.

Выше задал вопросы. Как может, что он попадает в Sleep(1), но не попадает в Sleep(2). Уверен, Вы ничего не запускали и не смотрели, а просто сходу написали свой ответ.

Такая же ерунда выдается и при отключении оптимизации. Более того, старый профилировщик врет уже в b2596, где еще нового подхода не было. Потратил время на изучение...

 

Предположил, что умный оптимизатор два Sleep подряд объединяет в один. Но проверка показала, что это не так.

#include <fxsaber\Usage\Usage.mqh> // https://www.mql5.com/ru/code/33875

const bool Init = EventSetMillisecondTimer(1);

void f()
{
  Sleep(1);
}

ulong Temp;

void OnTimer()
{
  _USAGE
  
  f();
  
  Temp += GetMicrosecondCount() - Temp;
  
  Sleep(2);
}

void OnDeinit( const int )
{
  Print(Temp);
}

Sleep(2) не виден.

12345678910
Новый комментарий