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

 

В продолжение:


Какая из строк (1, 2 или 3) все-таки ресурсоемкая?

Я не могу понять, как "тяжелый" iTime, занимающий 55% времени всей программы, показывает только 0.81% Self CPU?
И наоборот — почему открывающая скобка (1) и простейшее условие (2, истинно очень редко) показывают 33.84% Self CPU?

Почему не согласованы Self CPU и Total CPU?


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

Я явно чего-то не понимаю.

 
Andrey Khatimlianskii:

Я явно чего-то не понимаю.

Сползает может?

 
Andrei Trukhanovich:

Сползает может?

Не похоже, в отчете те же цифры.

 
Andrey Khatimlianskii:

Иляс, помогите и мне разобраться.

1. Почему вызов пустой функции может занимать 34.5% Self CPU? При этом, вызов следующей за ней функции, внутренности которой выполняются 38.16% от Total CPU, не отображен в отчете вообще?


Код функций:



2. На этом же примере видна вторая проблема: строка с TimeCurrent() занимает неоправданно много времени в рамках не только функции, но и программы вообще:

До того, как я закомментировал тело CheckTimeSeries(), основная нагрузка приходилась на ее строку с TimeCurrent().

Неужели функция такая тяжелая? Чем ее заменить? Или как сделать экономной (кэширование в рамках одного цикла выполнения программы)?

Я везде, где можно, делаю экономные расчеты, прореживая вычисления (раз в бар, раз в Х секунд, раз в Y мс, и т.д.). Но получается, что сама проверка, нужно ли делать расчеты, весьма ресурсоемкая.


Благодарю за помощь.

1) без кода сложно сказать почему такая статистика, возможно из-за оптимизации

2) Почему бы не попробовать получать время в функции Timer, до цикла и передавать его в качестве параметра дальше, в чём смысл вызывать эту функцию как минимум 2*N раз в цикле ?

 
Andrey Khatimlianskii:

В продолжение:


Какая из строк (1, 2 или 3) все-таки ресурсоемкая?

Я не могу понять, как "тяжелый" iTime, занимающий 55% времени всей программы, показывает только 0.81% Self CPU?
И наоборот — почему открывающая скобка (1) и простейшее условие (2, истинно очень редко) показывают 33.84% Self CPU?

Почему не согласованы Self CPU и Total CPU?


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

Я явно чего-то не понимаю.

1) Предположу, что функция была заинлайнена

2) Счётчики действительно не связаны, SelfCPU - нагрузка на код функции, без учёта вызванных функций, в приведённом коде, это опрератор IF (ветвление)

3) Счётчик TotalCPU показывает нагрзку ветки выполнения, по всем вызовам в этой ветки программы

 

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

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

 
Ilyas :

1) Предположу, что функция была заинлайнена

2) Счётчики действительно не связаны, SelfCPU - нагрузка на код функции, без учёта вызванных функций, в приведённом коде, это опрератор IF (ветвление)

3) Счётчик TotalCPU показывает нагрзку ветки выполнения, по всем вызовам в этой ветки программы

Как это полезно? Очевидно, что оператор IF сам по себе имеет низкую загрузку процессора. Разве он не должен включать вызовы функций?

В любом случае. Как понять (из примера Андрея):

if(!simulated) taking 3.86% ?!?

А что с этим ???


где, кажется, мы находимся в той же функции Tick ()!

Я действительно хочу использовать Profiler и понять его, но все это не имеет смысла. Сожалею.

Что делать ? Как мы можем помочь ?

 
Ilyas:

1) без кода сложно сказать почему такая статистика, возможно из-за оптимизации

2) Почему бы не попробовать получать время в функции Timer, до цикла и передавать его в качестве параметра дальше, в чём смысл вызывать эту функцию как минимум 2*N раз в цикле ?

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

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

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

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

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


Ilyas:

1) Предположу, что функция была заинлайнена

2) Счётчики действительно не связаны, SelfCPU - нагрузка на код функции, без учёта вызванных функций, в приведённом коде, это опрератор IF (ветвление)

3) Счётчик TotalCPU показывает нагрзку ветки выполнения, по всем вызовам в этой ветки программы

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

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

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

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

 
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 из 100 С++ программистов умеет пользоваться профайлером и понимает его отчеты. Виной всему оптимизатор нативного кода.

 
Alain Verleyen:

В любом случае. Как понять (из примера Андрея):

if(!simulated) taking 3.86% ?!?

Да, без учета вызова внешних функций SelfCPU мало информативен. Только на самом низком уровне, где используются нативные MQL-функции, можно будет увидеть реальную нагрузку.
Но при этом не станет понятно, из каких мест эти функции вызываются чаще (и потребляют больше), а из каких производятся единичные вызовы! Ну какой мне смысл узнать, что CopyXXX и OrderXXX функции занимают больше всего времени? Мне нужно знать из каких кусков моей программы они вызываются слишком часто/неэффективно.

Наверное, для этого режим   в сочетании с TotalCPU. Буду изучать. Но пока вижу там даже полностью закомментированные строки (!).