About the MT5 code profiler - page 4

New comment
 
Renat Fatkhullin:

Take any code from the standard delivery, profiling it and base your questions on it, please. This will allow you to assess the situation reproducibly and give accurate answers.

Otherwise it's no good in small pieces of your code to be responsible for profiler reports. There's an enormous amount of optimiser work behind there that turns all your code into a completely different jumbled and embedded representation.

I understand that without reproduction there will be no accurate answers.

Standard codes are unlikely to be profiled, but I will try to give reproducible chunks.

 
Andrey Khatimlianskii:

Thank you for your answers!

1) I don't think I can reproduce it on simple code, yes. And I'm not ready to give away the whole project.

2) In this particular case, I agree.

But there are many other classes which use the same or similar check and cannot do without TimeCurrent or GetTickCount.
How to optimize their call not to request the same value several times?

And is TimeCurrent really so heavy that it can be noticeable against the background of really heavy calculations (even if performed once every 1 or 5 minutes)?
Or did I get it wrong again and 38.16% of Total CPU / 26.07% of Self CPU was occupied by checking if itself (without considering theTimeCurrent function call)? But then why is it so?


1) It doesn't help to understand why such a voracious opening parenthesis. How to interpret this?

2) About SelfCPU is now clear, thanks. It's a load of function code without regard to the functions being called.

This also explains the low SelfCPU of the string with iTime - it was very rarely reached, it was just rarely called.

But why such a large TotalCPU? Or it shows the load of all iTime (and other CopyXXX functions?) functions in the whole program?

  1. Breakaway bracket - think of it as a prologue of a function which usually takes several instructions to place and in particular initialize local variables.
    Pay attention to the size of local variables of a function, you must take into account that the size can increase due to inlining of called
    . If function consumes more than 4Kb for local, service function is called to provide stack memory - this is a harsh truth Nativa and can not get rid of it

  2. SelfCPU should not count calls, otherwise it would simply duplicate TotalCPU and the time of its own instructions would be blurred by the time of the called functions
    TotalCPU for a string is the "time" of that string only
 
Alain Verleyen:

Shouldn't it always be 100%? Or even slightly less, considering also @global_initializations and @global_deinitializations.

Here is more than 102% ...(Build 3003 on historical data).

For the old profiler the article said it could be more

Profiling gives us important statistics: how many times each function was called, how much time it took to run it. You may be a bit confused by the statistics in percentages. Here it should be understood that the statistics does not consider the nesting of functions, so the sum of all percentages will be much greater than 100%.

 
Vasiliy Pushkaryov :

On the old profiler, the article pointed out that there may be more

Thank you. But as far as I understand it should be different with the new profiler. No excuses are acceptable, an error is an error.
 
Ilyas:
  1. A tear-off bracket - think of it as a prologue of a function, usually taking several instructions to place and especially initialize local variables.
    Pay attention to the volume of local variables of the function, you should take into account that the volume may increase due to inlining of called
    If the function consumes more than 4Kb for local variables, a service function is called to provide stack memory - this is a harsh truth of nativa and there is no getting rid of it

  2. SelfCPU should not count calls, otherwise it will simply duplicate TotalCPU and the time of its own instructions will be blurred by the time of called functions
    TotalCPU for a string is the "time" of that string only

1) Only one double variable is declared in the function body (not counting the const bool simulated function parameter).

2) So the processor received iTime( m_symbol, PERIOD_CURRENT, 0 ) for one of 11 working tools (it was the one for which the "m_CloseOnFirstTickOnly || m_OpenOnFirstTickOnly" condition was triggered)?

Or do you mean "Functions by Calls" mode (I didn't show it)?


I'll try to make reproducible snippet of code with results I don't understand, to talk substantively.

 

Please help me interpret the profiler data with a simple example.

#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);
}


It looks like a lot of nonsense.

  • Sleep(2) is completely missing.
  • For some reason USAGE is eating up several times more than Sleep(1).


Really trying to get the hang of it, no luck yet.


Also tried Sleep replacement.

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

#define Sleep Sleep2

Still not clear profiler values.

 
fxsaber #:

Please help me interpret the profiler data with a simple example.


It looks like a lot of nonsense.

  • Sleep(2) is completely missing.
  • For some reason USAGE is eating several times more than Sleep(1).

This same code produces absolutely correct results on MT4.


What am I doing wrong in MT5?

ZZY The last build of MT5 with MT4 profiler is b2595 (b2593 - if it produces an Internal compiler error).

 
And what makes you think the code you write is equal to what is actually executable?

How many times do I have to tell you about over-optimisation and blending of the resulting code? The prefixes inlined clearly indicate this.

Also, there is no point in using profiler on such minuscule code, where sampling profiler does not have time to gather statistics.

A profiler effectively looks for statistically significant costly places in brutally optimized code, not a line-by-line guide to source code.

Because your code has little to do with actually executing it.




 
Renat Fatkhullin profiler on such minuscule code, where sampling profiler does not have time to gather statistics.

A profiler effectively looks for statistically significant cost spots in brutally optimized code, rather than being a line-by-line source code lookup.

Because your code has little to do with actually executing it.

I had to write such a simple example, as it was impossible to explain profiler values on militant EA with significant size of source code.

Above asked the questions. How can it be that it hits Sleep(1) but doesn't hit Sleep(2). I'm sure you haven't launched or looked at anything and just wrote your response at once.

The same nonsense is produced when optimization is disabled. Moreover, the old profiler already lies in b2596 where there was no new approach yet. Spent some time studying it...

 

I assumed that the smart optimizer is combining two Sleeps in a row into one. But check has shown that this is not the case.

#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) is not visible.

1234567
New comment