О профилировщике кода MT5

 

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

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

Отчет о профилировании, который используется в советнике, работающем на исторических данных:

2021.07.08 15:43:06.269 MQL5 profiler 139098 total measurements, 0/0 errors, 320 mb of stack memory analyzed (92848/1073741824)

2021.07.08 15:43:06.269 MQL5 profiler 982065 total function frames found (279627 mql5 code, 122460 built-in, 571051 other, 8927 system)

Результаты (Функции по вызовам):

Q1. В отчете говорится о 139098 измерениях, но OnTick () Total CPU составляет 150026, как это возможно? (однако CopyHistoryData 80087 как 57,58% правильно означает 100% = 139098).

Q2. В отчете говорится о 571 051 другой «функции». Что это за функции, если они не являются ни mql, ни встроенными, ни системными?

Q3. CopyHistoryData показывает 80087 Total CPU, с 3 сообщенными вызовами функций (CopyHigh, CopyLow, CopyTime), имеющими разную общую CPU, ок. Однако собственный ЦП для этих функций одинаков и равен общему ЦП (стек вызовов). Кажется, что это неверные данные, поскольку на 80087 (стеки) для CopyHistoryData сумма для 3 функций составляет 62 161 (44286 + 9448 + 8427), как это может быть, при 62 161 вызове он обнаруживает 80 087 пауз в этих 3 функциях? Невозможно, единственное объяснение состоит в том, что это число является глобальным для CopyHistoryData и поэтому бесполезно. Я что-то упустил?

 

Форум по трейдингу, автоматическим торговым системам и тестированию торговых стратегий

О профилировщике кода MT5

Ален Верлейен , 2021.07.10 14:20

До сих пор профилировщик не имеет для меня никакого смысла. Пример :

Профилирование по историческим данным.

2021.07.10 08:00: 37.101 Профилировщик MQL5 Всего 39289 измерений, ошибок 0/0, проанализировано 141 МБ памяти стека (93304/1073741824)

2021.07.10 08:00: 37.101 Профилировщик MQL5 Всего найдено 464876 функциональных кадров (39328 код mql5, 30115 встроенных, 269752 других, 125681 система)

В строке кода с SymbolInfoTick всплывающая подсказка говорит: Всего ЦП: 29353 (99,85%) Собственный ЦП: 0 (0,00%)

Бэктест выполняется в:

2021.07.10 08:00: 37.101 Ядро 01 EURUSD, H1: 230861 тик, сгенерировано 998 баров. Среда синхронизирована в 0: 00: 00.144. Тест пройден за 0: 03: 09.367 (включая предварительную обработку тиков 0: 00: 00.515).

Я добавил код для измерения времени выполнения SymbolInfoTick () с помощью GetMicrosecondCount ().

       ulong start= GetMicrosecondCount ();

       //--- Get tick information
       if (! SymbolInfoTick (symbol,tick))
         return ( false );

      BENCH += GetMicrosecondCount ()-start;

Результат:

2021.07.10 08:00: 37.101 Ядро 01 2021.05.30 23:59:59 Всего = 1209572 Выполнено = 836973 за 661874 микросекунды

Таким образом, SymbolInfoTick () в общей сложности занял 661 миллисекунду на исторических данных за 3 минуты 9 секунд. Тем не менее, профилировщик показывает, что использует 74,71% измерений. Насколько это точно или полезно, я не понимаю.


 

Другой пример странных данных.

Согласно глобальной статистике, SymbolInfoTick () находился в стеке вызовов 209 раз. Но внутри кода написано 210. Хорошая точность.

Согласно глобальной статистике, выборка достигает SymbolInfoTick 209 раз (что составляет 0,83% от общего числа выборок). ОК. Теперь данные по коду говорят, что он достиг его 1 раз (что сейчас составляет 1,49%, поэтому, если обратиться к другому общему количеству, какое?). После расчета 1, равное 1,49%, означает, что общее количество (100%) равно 67. Таким образом, 1,49% относится к OnTimer (), который в данном случае является основной функцией. Но как может быть 1 там и 209 в глобальной статистике?

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

 

Еще один

Это строка кода над SymbolInfoTick (), как было показано ранее. Таким образом, такое присвоение, как newTick = false, было "выбрано" 5 раз! Еще 5 раз после вызова SymbolInfoTick () ( 1 - 1.49%)? Шутки в сторону ?

 
Наверно это баг, обратитесь в сервисдеск.
 

Поинтересуйтесь, что такое и в чем разница:

  • профайлинг на основе семплинга (как у нас сейчас, аналогично Visual Studio C++ и другим)
  • профайлинг на основе инструментации кода (как было у нас раньше)

 
Renat Fatkhullin :

Поинтересуйтесь, что такое и в чем разница:

  • профайлинг на основе семплинга (как у нас сейчас, аналогично Visual Studio C++ и другим)
  • профайлинг на основе инструментации кода (как было у нас раньше)

Разница очевидна.

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

 
Alain Verleyen:

Другой пример странных данных.

Согласно глобальной статистике, SymbolInfoTick () находился в стеке вызовов 209 раз. Но внутри кода написано 210. Хорошая точность.

Согласно глобальной статистике, выборка достигает SymbolInfoTick 209 раз (что составляет 0,83% от общего числа выборок). ОК. Теперь данные по коду говорят, что он достиг его 1 раз (что сейчас составляет 1,49%, поэтому, если обратиться к другому общему количеству, какое?). После расчета 1, равное 1,49%, означает, что общее количество (100%) равно 67. Таким образом, 1,49% относится к OnTimer (), который в данном случае является основной функцией. Но как может быть 1 там и 209 в глобальной статистике?

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

На скрине отображдается статистика для строки вызова, а не функции SymbolInfoTick.

Всего данная строка попала в замер 210 раз, один раз была "остановка" именно на строке, перед вызовом SymbolInfoTick или сразу после, и 209 раз как строка возврата из SymbolInfoTick

 
Alain Verleyen:

Еще один

Это строка кода над SymbolInfoTick (), как было показано ранее. Таким образом, такое присвоение, как newTick = false, было "выбрано" 5 раз! Еще 5 раз после вызова SymbolInfoTick () ( 1 - 1.49%)? Шутки в сторону ?

Не совсем понял что написано.

Читать это скриншот нужно так: строке "остановились" 5 раз, из общей нагрузки это 0.06%, для кода функции, которой принадлежит строка - 7.46%


 

Счётчик "Self CPU" отображает влияние кода строки на скорость работы функции, в которой эта строка находится.
Важно, время вызванной в строке функции не учитывается этим счётчиком, возможно это неверно, будем думать


Счётчик "Total CPU" показывает влияние кода строки на всю программу и этот счётчик учитывает вызванные в строке функции.

 
Ilyas :

Не совсем понял что написано.

Читать это скриншот нужно так: строке "остановились" 5 раз, из общей нагрузки это 0.06%, для кода функции, которой принадлежит строка - 7.46%


Да, я знаю. (Извините за мой предыдущий тон, я немного разозлился).

Проблема в :

      newTickф  = false ;                     // Total CPU : 5 (0.06%)    Self CPU : 5 (7.46%)

пока

       if (! SymbolInfoTick (symbolф,tickф))     // Total CPU : 210 (2.57%)  Self CPU : 1 (1.49%)

Общий процессор в порядке.

Но что касается Self CPU, как это возможно, что «newTick = false» равно 5, а вызов функции, такой как SymbolInfoTick (), равен только 1? Для меня это не имеет смысла.

Причина обращения: