About the MT5 code profiler - page 3

 

As a follow-up:


Which of the lines (1, 2 or 3) is still resource intensive?

I can't understand how the "heavy" iTime, which takes 55% of the time of the whole program, only shows 0.81% Self CPU?
And vice versa - why do the opening bracket (1) and the simplest condition (2, true very rarely) show 33.84% Self CPU?

Why are Self CPU and Total CPU not matched?


The function is really heavy, but all its heaviness is located further down the code. And the profiler suggests looking for a replacement for iTime and two boolean variables?!

I obviously don't understand something.

 
Andrey Khatimlianskii:

I obviously don't understand something.

Slipping maybe?

 
Andrei Trukhanovich:

Slipping maybe?

Doesn't look like it, the figures in the report are the same.

 
Andrey Khatimlianskii:

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.

1) Without code it's hard to say why these statistics are so bad, maybe due to optimization

2) Why not try to get the time in the Timer function, before the loop and pass it as a parameter further, what is the point of calling this function at least 2*N times in the loop ?

 
Andrey Khatimlianskii:

As a follow-up:


Which of the lines (1, 2 or 3) is still resource intensive?

I can't understand how the "heavy" iTime, which takes 55% of the time of the whole program, only shows 0.81% Self CPU?
And vice versa - why do the opening bracket (1) and the simplest condition (2, true very rarely) show 33.84% Self CPU?

Why are Self CPU and Total CPU not matched?


The function is really heavy, but all its heaviness is located further down the code. And the profiler suggests looking for a replacement for iTime and two boolean variables?!

I obviously don't understand something.

1) I will assume that the function has been inlined

2) The counters are really unrelated, SelfCPU is the load on the function code, not taking into account the called functions, in the code given, it is an IF opener (branching)

3) TotalCPU counter shows the load of the execution branch, for all calls in this branch of the program

 

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).

 
Ilyas :

1) I will assume that the function has been inlined

2) The counters are really not related, SelfCPU is the load on the function code, without taking into account the called functions, in the above code, it is an IF opener (branching)

3) TotalCPU counter shows the load of a branch of execution, for all calls in this branch of the program.

How is it useful? Obviously, the IF statement by itself has a low CPU load. Shouldn't it include function calls?

In any case. How to understand (from Andrew's example):

if(!simulated) taking 3.86% ?!?

What about this ???


where we seem to be in the same Tick () function!

I really want to use Profiler and understand it, but none of this makes sense. Sorry.

What to do ? How can we help ?

 
Ilyas:

1) Without code it's hard to say why the statistics are so high, probably due to optimization

2) Why not try to get the time in Timer function before the loop and pass it as a parameter further, what is the point of calling this function at least 2*N times in the loop ?

Thanks for the answers!

1) I can hardly reproduce it on a 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 on the background of really heavy calculations (even if performed 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 why is this so?


Ilyas:

1) I will assume the function was inline

2) The counters are really not related, SelfCPU is the load on the function code, not taking into account the called functions, in the above code, it is the IF opener (branching)

3) TotalCPU counter shows the load of a branch of execution, for all calls in this branch of the program

1) It doesn't help to understand why such a voracious opening bracket. 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?

 
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 on the background of really heavy calculations (even if performed every 1 or 5 minutes)?
Or maybe I've got it wrong again and 38.16% of Total CPU / 26.07% of Self CPU was occupied by the check itself (withoutTimeCurrent 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 is TotalCPU so high? Or it shows the load of all iTime (and other CopyXXX functions?) functions in the whole program?

Take any code from the standard delivery, proofread it and ask questions based on it, please. This will allow a reproducible assessment of the situation and provide accurate answers.

Otherwise it's no use answering small pieces of your code for profiler reports. There's an enormous amount of optimiser work behind the scenes, which turns all your code into a completely different jumbled and embedded representation.


For information: God forbid 1 out of 100 C++ programmers can use the profiler and understand its reports. It's the fault of the native code optimizer.

 
Alain Verleyen:

In any case. How to understand (from Andrew's example):

if(!simulated) taking 3.86% ?!?

Yes, without considering external function calls SelfCPU is not very informative. Only at the lowest level, where native MQL functions are used, you will see the real load.
But in this case it won't become clear from which places these functions are called more often (and consume more), and from which there are single calls! Well, what's the point for me to know that CopyXXX and OrderXXX functions consume the most time? I need to know from which chunks of my program they are called too often/inefficiently.

I guess that's what the mode is for, combined with TotalCPU. I'll be looking into it. But so far I see there even completely commented out lines (!).