About the MT5 code profiler - page 2

 
Ilyas :

The screenshot shows the statistics for the call string and not the SymbolInfoTick function.

In total, the given string was measured 210 times, once it was "stopped" exactly at the string, before the SymbolInfoTick call or just after, and 209 times as the return string from SymbolInfoTick

Sorry, but it's not clear.

The profiler summary says:

SymbolInfoTick () Total CPU: 209 (0.83%)

The code itself says:

SymbolInfoTick () Total CPU: 210 (2.57%)

SymbolInfoTick () occurs only ONE time in the code. What these different values are is not at all clear. OK, 209 vs 210, you said it's because it "stopped" one on that line (it doesn't make sense to me, but I guess it doesn't matter much).

What about the %?

0 2021.07.10 11: 52: 19.032 MQL5 Profiler Total measurements 25039, 0/0 errors, 99 MB stack memory analyzed (92872/1073741824)

So 209 (0.83%) means 100% = 25039. OK

But 210 (2.57%) means 100% = 8171?!? What is 8171 for Total CPU?

 
Alain Verleyen :

What about this ( post #1 )?

As you can see, SymbolInfoTick () is shown as the hardest part of the code. Which is incorrect. This is the same code as in the following posts (which shows SymbolInfoTick with Total CPU = 209 (0.83%), which is correct), the difference is that I commented out the line where SymbolInfoTick () was Total CPU = 1. Total execution time (according to historical data) didn't change with this slight change, but the profiler results were different.

I can provide the code in private if you want to check.

О профилировщике кода MT5
О профилировщике кода MT5
  • 2021.07.09
  • www.mql5.com
Я начал использовать новый профайлер. В этом разделе мы могли бы централизовать информацию о том, как его правильно использовать...
 
Alain Verleyen:

I'm sorry, but it's not clear.

The profiler summary says:

SymbolInfoTick () Total CPU: 209 (0.83%)

The code itself says:

SymbolInfoTick () Total CPU: 210 (2.57%)

SymbolInfoTick () occurs only ONE time in the code. What these different values are is not at all clear. OK, 209 vs 210, you said it's because it "stopped" one on that line (it doesn't make sense to me, but I guess it doesn't matter much).

What about the %?

0 2021.07.10 11: 52: 19.032 MQL5 Profiler Total measurements 25039, 0/0 errors, 99 MB stack memory analyzed (92872/1073741824)

So 209 (0.83%) means 100% = 25039. OK

But 210 (2.57%) means 100% = 8171?!? What is 8171 for Total CPU?

You are comparing statistics for "line of code" and for "function"

There is a line of code

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

A total of 210 times this line of code got into the statistics:

  • 209 times as a code line from which SymbolInfoTick is called
  • 1 time as if operator

There is a function SymbolInfoTick, this function hit the statistics 209 times.
The function is only called from this line of code, maybe that's why you got confused with the counters


As for the numbers:
So, 209 (0.83%) means 100% = 25039. OK

it is not, the numbers are just similar: 209 / 0.83 * 100 = 25180


But 210 (2.57%) means 100% = 8171?!? What is 8171 for Total CPU?

Correct, out of 25039 measurements, 8171 of them came from the code line with the SymbolInfoTick call

 

Alain Verleyen:

Backtest running at:

2021.07.10 08:00: 37.101 Core 01 EURUSD, H1: 230861 ticks, 998 bars generated. The test passed in 0: 03: 09.367 (including pre-processing of ticks 0: 00: 00.515).

I added code to measure the execution time of SymbolInfoTick () using GetMicrosecondCount ().

       ulong start= GetMicrosecondCount ();

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

      BENCH += GetMicrosecondCount ()-start;

Result:

2021.07.10 08:00: 37.101 Core 01 2021.05.30 23:59:59 Total = 1209572 Executed = 836973 in 661874 microseconds

Thus, SymbolInfoTick () took a total of 661 milliseconds on the historical data in 3 minutes and 9 seconds. However, the profiler shows that it uses 74.71% of the measurements. How accurate or useful this is, I don't understand.


Let me be clear, testing is not just about executing MQL code + the profiler, by capturing statistics, slows down execution a bit.


That said, in the report, 74.71% is a figure relative to MQL code, not testing in general

 

Hi @Ilyas!

Thank you. I will check again with your answers and keep you posted.

 
Ilyas:
...

As for the numbers:

it's not, the numbers are just similar: 209 / 0.83 * 100 = 25180


Correct, out of 25039 measurements, 8171 of them came from the code line with the SymbolInfoTick call

I got the numbers wrong.

Indeed, 209 is 0.83469% of 25039, which was rounded to 0.83


8171 samples were taken at the line with SymbolInfoTick called 210 times, that's 2.57%.

 
Ilyas :

I got the numbers wrong.

Indeed, 209 is 0.83469% of 25039 rounded to 0.83


8171 runs were on a branch of program execution where the line calling SymbolInfoTick was executed 210 times, which is 2.57%.

Execution from OnTimer (), so it's not quite clear why it's 8171? When OnTimer () Total CPU shows 29683.
 
Alain Verleyen:
Execution from OnTimer (), so it's not quite clear why it's 8171? When OnTimer () Total CPU shows 29683.

Please provide the code, I will double-check the operation of the counters

 
Ilyas :

Please provide the code, I will double-check the operation of the counters

I will do this in private as soon as I have time. Thank you.
 
Ilyas:

Ilyas, help me figure this out as well.

1. Why an empty function call may take 34.5% of Self CPU? At the same time, the call of the function following it, whose internals occupy 38.16% of the Total CPU, doesn't show up in the report at all?


Function code:



2. This example shows the second problem: the line with TimeCurrent() takes an unreasonably long time not only within the function but in the program in general:

Before I commented out the body of CheckTimeSeries(), the main load was on its TimeCurrent() line.

Is it really such a heavy function? What to replace it with? Or how to make it economical (caching within one loop of program execution)?

Wherever I can, I save calculations by thinning them out (once per bar, once every X seconds, once every Y ms, etc.). But it turns out that the check itself, whether to do the calculations, is quite resource intensive.


Thanks for the help.

Reason: