MT5 and speed in action - page 64

New comment
 

Anton:

Running your EA on Idle-CPU, RannForex-Server, 6 charts with different symbols. When I got back to my computer I saw a lot of these.

2020.10.30 13:50:21.852 Test9 (GBPUSD,H1)       SymbolInfoTick max bad time: 2.008 ms; avr bad time: 2.008 ms; bad iterations: 1 total iterations: 10000000
2020.10.30 13:50:22.142 Test9 (EURUSD,H1)       GetBid max bad time: 1.125 ms; avr bad time: 1.125 ms; bad iterations: 1 total iterations: 10000000
2020.10.30 13:50:23.072 Test9 (USDCHF,H1)       SymbolInfoTick max bad time: 2.245 ms; avr bad time: 2.245 ms; bad iterations: 1 total iterations: 10000000
2020.10.30 13:50:23.288 Test9 (USDCAD,H1)       GetBid max bad time: 1.298 ms; avr bad time: 1.182 ms; bad iterations: 2 total iterations: 10000000
2020.10.30 13:50:23.297 Test9 (AUDCAD,H1)       GetBid max bad time: 0.977 ms; avr bad time: 0 ms; bad iterations: 0 total iterations: 10000000
2020.10.30 13:50:24.393 Test9 (EURUSD,H1)       SymbolInfoTick max bad time: 3.400 ms; avr bad time: 2.862 ms; bad iterations: 2 total iterations: 10000000


I have a bad time condition like that.

      if(end>1000)
        {
         avr_time+=end;
         counter++;
        }


ZZY I attached the code for objectivity on the part of forum members.

Files:
Test9.mq5  6 kb
 
fxsaber:

Running your EA on Idle-CPU, RannForex-Server, 6 charts with different symbols. When I got back to my computer I saw a lot of this.

If I understood correctly, in this test there are 6 looped EAs running on 4 CPU cores, and each one is trying to load one core 100%. I.e. this is definitely a stress test, very far from normal operating conditions.

Under such conditions 1 or 2 ejections of 1-2ms for 10 million queries is an excellent result.

And once again, let me remind you: the greater the load, the more you test the efficiency of the OS task scheduler, not the terminal. Do not be fooled.

 
pivomoe:

I have a question about the relevance of the ticks given by SymbolInfoTick.

Situation:

1. We do TimeCurretn(); we get time 18:00:00

2. Do SymbolInfoTick on an unlabeled symbol. We get a tick with the time 17:58:00.

3. Sleep(1)

4. Add SymbolInfoTick for the non-left symbol. We get a tick with the time 17:59:00.


I.e., in the fourth item we have a new tick, which is one minute different than TimeCurretn().

Do you see a problem in this situation?

How to get into this situation more rarely?

Test EA.

// Проверочный советник на корректность последовательного прихода тиков в MT5.

#include <TypeToBytes.mqh> // https://www.mql5.com/ru/code/16280

string Symbols[];
MqlTick LastTicks[]; // Последние тики из Обзора рынка.

const int Size2 = ArrayResize(Symbols, SymbolsTotal(true));

int OnInit()
{
  for (int i = 0; i < Size2; i++)
    Symbols[i] = SymbolName(i, true);
  
  GetMarketWatch(LastTicks);
    
  return(!EventSetMillisecondTimer(1));
}

// Получает тики из Обзора рынка.
void GetMarketWatch( MqlTick &Ticks[] )
{
  for (int i = ArrayResize(Ticks, Size2) - 1; i >= 0; i--)
    SymbolInfoTick(Symbols[i], Ticks[i]);
}

// Возвращает индекс самого свежего тика.
int GetLastTick( const MqlTick &Ticks[] )
{
  long LastTime = 0;
  int Pos = 0;
  
  for (int i = 0; i < Size2; i++)
    if (Ticks[i].time_msc > LastTime)
    {
      LastTime = Ticks[i].time_msc;
      
      Pos = i;
    }
  
  return(Pos);
}

// Возвращает индекс измененного тика с наименьшим временем.
int GetFirstFreshTick( const MqlTick &PrevTicks[], const MqlTick &NewTicks[] )
{
  long LastTime = LONG_MAX;
  int Pos = -1;
  
  for (int i = 0; i < Size2; i++)
    if ((_R(PrevTicks[i]) != NewTicks[i]) && (NewTicks[i].time_msc < LastTime))
    {
      LastTime = NewTicks[i].time_msc;
      
      Pos = i;
    }
  
  return(Pos);
}

// Распечатка тика.
void PrintTick( const string Str, const MqlTick &Ticks[], const int Pos )
{
  Print(Str + " " + Symbols[Pos] + ":");
  ArrayPrint(Ticks, 5, NULL, Pos, 1);
}

void OnTimer()
{  
  MqlTick NewTicks[];
  
  GetMarketWatch(NewTicks); // Получили все тики из Обзора рынка
  
  const int FirstFreshPos = GetFirstFreshTick(LastTicks, NewTicks); // Взяли самый ранний тик из вновь пришедших.
  
  if (FirstFreshPos != -1) // Если пришедшие тики были.
  {
    const int LastPos = GetLastTick(LastTicks); // Взяли самый свежий тик с предыдущего запроса Обзора рынка.
    
    if (NewTicks[FirstFreshPos].time_msc < LastTicks[LastPos].time_msc) // Если нарушена временная последовательность.
    {
      Alert("BUG?"); // Сообщаем об этом.
      
      PrintTick("PrevTick", LastTicks, LastPos);
      PrintTick("NewTick", NewTicks, FirstFreshPos);
    }
     
    ArraySwap(LastTicks, NewTicks); // Запоминаем последний опрос Обзора рынка.
  }  
}


I don't have Alertite. Result (ran it on six charts).

2020.10.30 16:08:51.130 Test9 (GBPUSD,H1)       Alert: BUG?
2020.10.30 16:08:51.130 Test9 (GBPUSD,H1)       PrevTick EURAUD:
2020.10.30 16:08:51.130 Test9 (GBPUSD,H1)                        [time]   [bid]   [ask] [last] [volume]    [time_msc] [flags] [volume_real]
2020.10.30 16:08:51.130 Test9 (GBPUSD,H1)       [0] 2020.10.30 16:08:56 1.65631 1.65637 0.0000        0 1604074136152       6       0.00000
2020.10.30 16:08:51.130 Test9 (GBPUSD,H1)       NewTick EURSGD:
2020.10.30 16:08:51.130 Test9 (GBPUSD,H1)                        [time]   [bid]   [ask] [last] [volume]    [time_msc] [flags] [volume_real]
2020.10.30 16:08:51.130 Test9 (GBPUSD,H1)       [0] 2020.10.30 16:08:56 1.59391 1.59404 0.0000        0 1604074136149       4       0.00000
2020.10.30 16:09:14.707 Test9 (USDCHF,H1)       Alert: BUG?
2020.10.30 16:09:14.707 Test9 (USDCHF,H1)       PrevTick EURGBP:
2020.10.30 16:09:14.707 Test9 (USDCHF,H1)                        [time]   [bid]   [ask] [last] [volume]    [time_msc] [flags] [volume_real]
2020.10.30 16:09:14.707 Test9 (USDCHF,H1)       [0] 2020.10.30 16:09:19 0.90135 0.90138 0.0000        0 1604074159733       4       0.00000
2020.10.30 16:09:14.707 Test9 (USDCHF,H1)       NewTick XAUUSD:
2020.10.30 16:09:14.707 Test9 (USDCHF,H1)                        [time]      [bid]      [ask] [last] [volume]    [time_msc] [flags] [volume_real]
2020.10.30 16:09:14.707 Test9 (USDCHF,H1)       [0] 2020.10.30 16:09:19 1882.94000 1882.97000 0.0000        0 1604074159728       6       0.00000
2020.10.30 16:09:19.935 Test9 (GBPUSD,H1)       Alert: BUG?
2020.10.30 16:09:19.935 Test9 (GBPUSD,H1)       PrevTick AUDNZD:
2020.10.30 16:09:19.935 Test9 (GBPUSD,H1)                        [time]   [bid]   [ask] [last] [volume]    [time_msc] [flags] [volume_real]
2020.10.30 16:09:19.935 Test9 (GBPUSD,H1)       [0] 2020.10.30 16:09:24 1.06010 1.06012 0.0000        0 1604074164946       4       0.00000
2020.10.30 16:09:19.935 Test9 (GBPUSD,H1)       NewTick USDNOK:
2020.10.30 16:09:19.935 Test9 (GBPUSD,H1)                        [time]   [bid]   [ask] [last] [volume]    [time_msc] [flags] [volume_real]
2020.10.30 16:09:19.935 Test9 (GBPUSD,H1)       [0] 2020.10.30 16:09:24 9.50256 9.50288 0.0000        0 1604074164945       2       0.00000
2020.10.30 16:09:23.612 Test9 (USDJPY,H1)       Alert: BUG?
2020.10.30 16:09:23.612 Test9 (USDJPY,H1)       PrevTick USDCAD:
2020.10.30 16:09:23.612 Test9 (USDJPY,H1)                        [time]   [bid]   [ask] [last] [volume]    [time_msc] [flags] [volume_real]
2020.10.30 16:09:23.612 Test9 (USDJPY,H1)       [0] 2020.10.30 16:09:28 1.33050 1.33052 0.0000        0 1604074168639       2       0.00000
2020.10.30 16:09:23.612 Test9 (USDJPY,H1)       NewTick XAUUSD:
2020.10.30 16:09:23.612 Test9 (USDJPY,H1)                        [time]      [bid]      [ask] [last] [volume]    [time_msc] [flags] [volume_real]
2020.10.30 16:09:23.612 Test9 (USDJPY,H1)       [0] 2020.10.30 16:09:28 1883.11000 1883.18000 0.0000        0 1604074168634       4       0.00000


There is a problem. It's hard to say how serious it is.

 
Anton:

If I understand correctly, in this test there are 6 looped EAs running on 4 CPU cores, and each one is trying to load one core 100%. I.e. this is definitely a stress test, very far from normal operating conditions.

Is this EA a stress test? I'm asking you this because it's been measuring

#include <fxsaber\BenchMark\Benchmark.mqh> // https://www.mql5.com/ru/code/31279

void GetMarketWatch( MqlTick &Ticks[] )
{
  for (int i = ArrayResize(Ticks, Size2) - 1; i >= 0; i--)
    _B(SymbolInfoTick(Symbols[i], Ticks[i]), 100);
}

is giving out a sea of Alerts.

2020.10.30 16:18:53.713 Test9 (USDJPY,H1)       Alert: Bench_Stack = 0, 100 <= Time[Test9.mq5 107 in GetMarketWatch: SymbolInfoTick(Symbols[i],Ticks[i])] = 166 mcs.
2020.10.30 16:18:53.729 Test9 (USDJPY,H1)       Alert: Bench_Stack = 0, 100 <= Time[Test9.mq5 107 in GetMarketWatch: SymbolInfoTick(Symbols[i],Ticks[i])] = 120 mcs.
2020.10.30 16:18:53.901 Test9 (EURUSD,H1)       Alert: Bench_Stack = 0, 100 <= Time[Test9.mq5 107 in GetMarketWatch: SymbolInfoTick(Symbols[i],Ticks[i])] = 127 mcs.
2020.10.30 16:18:53.917 Test9 (EURUSD,H1)       Alert: Bench_Stack = 0, 100 <= Time[Test9.mq5 107 in GetMarketWatch: SymbolInfoTick(Symbols[i],Ticks[i])] = 131 mcs.
2020.10.30 16:18:55.141 Test9 (USDCHF,H1)       Alert: Bench_Stack = 0, 100 <= Time[Test9.mq5 107 in GetMarketWatch: SymbolInfoTick(Symbols[i],Ticks[i])] = 104 mcs.
2020.10.30 16:18:55.204 Test9 (EURUSD,H1)       Alert: Bench_Stack = 0, 100 <= Time[Test9.mq5 107 in GetMarketWatch: SymbolInfoTick(Symbols[i],Ticks[i])] = 107 mcs.
 

There is a bug in ArrayPrint's serial log output.

2020.10.30 16:26:05.320 Test9 (USDCAD,H1)       PrevTick AUDCAD:
2020.10.30 16:26:05.320 Test9 (GBPUSD,H1)       NewTick XAUEUR:
2020.10.30 16:26:05.320 Test9 (GBPUSD,H1)                        [time]      [bid]      [ask] [last] [volume]    [time_msc] [flags] [volume_real]
2020.10.30 16:26:05.320 Test9 (USDCAD,H1)                        [time]   [bid]   [ask] [last] [volume]    [time_msc] [flags] [volume_real]
2020.10.30 16:26:05.320 Test9 (GBPUSD,H1)       [0] 2020.10.30 16:26:10 1612.03000 1612.43000 0.0000        0 1604075170357       4       0.00000
2020.10.30 16:26:05.320 Test9 (USDCAD,H1)       [0] 2020.10.30 16:26:10 0.93785 0.93790 0.0000        0 1604075170359       4       0.00000

It is clear that this is an error, since this is the source code.

Forum on trading, automated trading systems and strategy testing

MT5 and Speed in Action

fxsaber, 2020.10.30 15:04

// Распечатка тика.
void PrintTick( const string Str, const MqlTick &Ticks[], const int Pos )
{
  Print(Str + " " + Symbols[Pos] + ":");
  ArrayPrint(Ticks, 5, NULL, Pos, 1);
}

      PrintTick("PrevTick", LastTicks, LastPos);
      PrintTick("NewTick", NewTicks, FirstFreshPos);
This is a fairly typical bug. The current implementation of ArrayPrint prints strings via consecutive calls to several Prints. You should first form one big string with all data and then print it through just one Print.
 

I have Alert triggered every second many times.

17:59:50.126    Temp (SILV-9.21,H1)                      [time]     [bid]     [ask]    [last] [volume]    [time_msc] [flags] [volume_real]
KD      0       17:59:50.126    Temp (SILV-9.21,H1)     [0] 2020.10.30 17:59:49 155.38000 155.39000 155.38000        3 1604080789146       0       3.00000
CH      0       17:59:50.141    Temp (SILV-9.21,H1)     Alert: BUG?
JO      0       17:59:50.141    Temp (SILV-9.21,H1)     PrevTick Si-12.20:
LE      0       17:59:50.141    Temp (SILV-9.21,H1)                      [time]       [bid]       [ask]      [last] [volume]    [time_msc] [flags] [volume_real]
OK      0       17:59:50.141    Temp (SILV-9.21,H1)     [0] 2020.10.30 17:59:49 79741.00000 79742.00000 79743.00000        1 1604080789200       0       1.00000
QF      0       17:59:50.141    Temp (SILV-9.21,H1)     NewTick ROSN:
FS      0       17:59:50.141    Temp (SILV-9.21,H1)                      [time]     [bid]     [ask]    [last] [volume]    [time_msc] [flags] [volume_real]
HR      0       17:59:50.141    Temp (SILV-9.21,H1)     [0] 2020.10.30 17:59:49 349.80000 349.95000 349.85000       57 1604080789179       0      57.00000
 
Was at the computer, did not do any calculations. Didn't load the CPU with anything. 
2020.11.03 16:04:01.137         Alert: Bench_Stack = 3, 100 <= Time[NewTicks.mqh 33 in NEWTICKS::GetMarketWatchTick: ::SymbolInfoTick(_Symbol,Tick)] = 48764 mcs.
2020.11.03 18:31:04.622         Alert: Bench_Stack = 3, 100 <= Time[NewTicks.mqh 33 in NEWTICKS::GetMarketWatchTick: ::SymbolInfoTick(_Symbol,Tick)] = 4143 mcs.
2020.11.03 19:00:34.117         Bench_Stack = 2, 100 <= Time[NewTicks.mqh 33 in NEWTICKS::GetMarketWatchTick: ::SymbolInfoTick(_Symbol,Tick)] = 1069 mcs.
2020.11.03 19:00:34.117         Bench_Stack = 2, 100 <= Time[NewTicks.mqh 33 in NEWTICKS::GetMarketWatchTick: ::SymbolInfoTick(_Symbol,Tick)] = 1100 mcs.
2020.11.03 19:01:49.199         Alert: Bench_Stack = 3, 100 <= Time[NewTicks.mqh 33 in NEWTICKS::GetMarketWatchTick: ::SymbolInfoTick(_Symbol,Tick)] = 19301 mcs.

19 ms and 48 ms for the execution of SymbolInfoTick. There were several dozens of cases where the duration was hundreds of microseconds. But I didn't cite them.


Apparently, in order to reproduce it, we need to run combat advisors for 24 hours, and then only watch. In my opinion, it is unrealistic to figure out what initiates such lags.

 

Looked at the Test9 code at the top of the page. Why 10 million times without any Sleep to request ticks from one symbol ? What does this test have to do with real trading?

I think the test should look like this: We request tick from each symbol in market review. We pause Sleep(1) and so on. Slightly rework your code:

int OnInit()
{
   string Symbols[];
   int    TotalSymbol= SymbolsTotal(true);
   
   ArrayResize(Symbols,TotalSymbol);
   for(int i=0;i<TotalSymbol;i++)
   Symbols[i]= SymbolName(i, true);
   
   
   MqlTick Tick;
//---
   double temp=0;
   ulong start,end,max_time=0,avr_time=0,counter=0;
   int   count=1 e4;
   
   for(int i=0; !IsStopped() && (i<count); i++)
     {
      Sleep(1);   
      for(int j=0;j<TotalSymbol;j++)
        {
         start=GetMicrosecondCount();   
         SymbolInfoTick(Symbols[j], Tick);
        // temp++;
         
         end=GetMicrosecondCount()-start;
      //---
         if(end>max_time)
         max_time=end;
         if(end>1000)
        {
         avr_time+=end;
         counter++;
        }
       } 
     }
   Comment("SymbolInfoTick max bad time: ",DoubleToString(max_time/1000.0,3)," ms; avr bad time: ",counter ? DoubleToString(avr_time/1000.0/counter,3):"0"," ms; bad iterations: ",counter," total iterations: ",count);
   Print("SymbolInfoTick max bad time: ",DoubleToString(max_time/1000.0,3)," ms; avr bad time: ",counter ? DoubleToString(avr_time/1000.0/counter,3):"0"," ms; bad iterations: ",counter," total iterations: ",count);
   return INIT_FAILED;
  }  

Test 55 symbols in the overview.

SymbolInfoTick max bad time: 0.212 ms; avr bad time: 0 ms; bad iterations: 0 total iterations: 10000

Now let's test temp++ instead of SymbolInfoTick;

SymbolInfoTick max bad time: 0.102 ms; avr bad time: 0 ms; bad iterations: 0 total iterations: 10000
 
pivomoe:

Looked at the Test9 code at the top of the page. Why 10 million times without any Sleep to request ticks from one character ?

Not at all. Read the branch for details.

 
fxsaber:

Not on a level playing field. Read the thread for details.

Aren't you confused by the fact that even temp++'s maximum execution time takes tens of microseconds, with this metering technique ?

1...575859606162636465666768697071...94
New comment