MT5 and speed in action - page 59

 
Anton:

How do you do that?

Just reproduced the brakes when 6/8 Agents were running.

2020.10.20 11:00:33.069 Test9 (GBPUSD,H1)       Alert: Bench_Stack = 0, 100 <= Time[Test9.mq5 7 in OnTick: SymbolInfoTick(_Symbol,Tick)] = 101 mcs.
2020.10.20 11:00:34.292 Test9 (NZDCAD,H1)       Alert: Bench_Stack = 0, 100 <= Time[Test9.mq5 7 in OnTick: SymbolInfoTick(_Symbol,Tick)] = 5848 mcs.
2020.10.20 11:00:34.486 Test9 (GBPCHF,H1)       Alert: Bench_Stack = 0, 100 <= Time[Test9.mq5 7 in OnTick: SymbolInfoTick(_Symbol,Tick)] = 6359 mcs.
2020.10.20 11:00:43.717 Test9 (AUDCHF,H1)       Alert: Bench_Stack = 0, 100 <= Time[Test9.mq5 7 in OnTick: SymbolInfoTick(_Symbol,Tick)] = 114 mcs.
2020.10.20 11:00:44.222 Test9 (EURJPY,H1)       Alert: Bench_Stack = 0, 100 <= Time[Test9.mq5 7 in OnTick: SymbolInfoTick(_Symbol,Tick)] = 661 mcs.
2020.10.20 11:00:55.232 Test9 (AUDUSD,H1)       Alert: Bench_Stack = 0, 100 <= Time[Test9.mq5 7 in OnTick: SymbolInfoTick(_Symbol,Tick)] = 828 mcs.
2020.10.20 11:00:57.579 Test9 (NZDCAD,H1)       Alert: Bench_Stack = 0, 100 <= Time[Test9.mq5 7 in OnTick: SymbolInfoTick(_Symbol,Tick)] = 151 mcs.
2020.10.20 11:01:07.398 Test9 (NZDCHF,H1)       Alert: Bench_Stack = 0, 100 <= Time[Test9.mq5 7 in OnTick: SymbolInfoTick(_Symbol,Tick)] = 435 mcs.
2020.10.20 11:01:20.046 Test9 (GBPCHF,H1)       Alert: Bench_Stack = 0, 100 <= Time[Test9.mq5 7 in OnTick: SymbolInfoTick(_Symbol,Tick)] = 108 mcs.
2020.10.20 11:01:37.749 Test9 (AUDJPY,H1)       Alert: Bench_Stack = 0, 100 <= Time[Test9.mq5 7 in OnTick: SymbolInfoTick(_Symbol,Tick)] = 159 mcs.
2020.10.20 11:01:37.751 Test9 (AUDCAD,H1)       Alert: Bench_Stack = 0, 100 <= Time[Test9.mq5 7 in OnTick: SymbolInfoTick(_Symbol,Tick)] = 865 mcs.
2020.10.20 11:01:40.787 Test9 (EURCHF,H1)       Alert: Bench_Stack = 0, 100 <= Time[Test9.mq5 7 in OnTick: SymbolInfoTick(_Symbol,Tick)] = 197 mcs.
2020.10.20 11:01:42.615 Test9 (GBPCHF,H1)       Alert: Bench_Stack = 0, 100 <= Time[Test9.mq5 7 in OnTick: SymbolInfoTick(_Symbol,Tick)] = 207 mcs.
2020.10.20 11:01:46.362 Test9 (AUDCAD,H1)       Alert: Bench_Stack = 0, 100 <= Time[Test9.mq5 7 in OnTick: SymbolInfoTick(_Symbol,Tick)] = 278 mcs.
2020.10.20 11:01:54.377 Test9 (AUDUSD,H1)       Alert: Bench_Stack = 0, 100 <= Time[Test9.mq5 7 in OnTick: SymbolInfoTick(_Symbol,Tick)] = 165 mcs.
2020.10.20 11:01:55.789 Test9 (GBPCAD,H1)       Alert: Bench_Stack = 0, 100 <= Time[Test9.mq5 7 in OnTick: SymbolInfoTick(_Symbol,Tick)] = 228 mcs.
2020.10.20 11:02:04.892 Test9 (USDCAD,H1)       Alert: Bench_Stack = 0, 100 <= Time[Test9.mq5 7 in OnTick: SymbolInfoTick(_Symbol,Tick)] = 357 mcs.
2020.10.20 11:02:10.776 Test9 (GBPCHF,H1)       Alert: Bench_Stack = 0, 100 <= Time[Test9.mq5 7 in OnTick: SymbolInfoTick(_Symbol,Tick)] = 173 mcs.
2020.10.20 11:02:13.468 Test9 (CADCHF,H1)       Alert: Bench_Stack = 0, 100 <= Time[Test9.mq5 7 in OnTick: SymbolInfoTick(_Symbol,Tick)] = 161 mcs.
2020.10.20 11:02:26.274 Test9 (NZDCAD,H1)       Alert: Bench_Stack = 0, 100 <= Time[Test9.mq5 7 in OnTick: SymbolInfoTick(_Symbol,Tick)] = 448 mcs.
2020.10.20 11:02:30.687 Test9 (GBPUSD,H1)       Alert: Bench_Stack = 0, 100 <= Time[Test9.mq5 7 in OnTick: SymbolInfoTick(_Symbol,Tick)] = 101 mcs.
2020.10.20 11:03:01.429 Test9 (CADCHF,H1)       Alert: Bench_Stack = 0, 100 <= Time[Test9.mq5 7 in OnTick: SymbolInfoTick(_Symbol,Tick)] = 159 mcs.
2020.10.20 11:03:04.566 Test9 (AUDCHF,H1)       Alert: Bench_Stack = 0, 100 <= Time[Test9.mq5 7 in OnTick: SymbolInfoTick(_Symbol,Tick)] = 1329 mcs.
2020.10.20 11:03:14.940 Test9 (GBPCHF,H1)       Alert: Bench_Stack = 0, 100 <= Time[Test9.mq5 7 in OnTick: SymbolInfoTick(_Symbol,Tick)] = 1444 mcs.
2020.10.20 11:03:57.781 Test9 (EURCAD,H1)       Alert: Bench_Stack = 0, 100 <= Time[Test9.mq5 7 in OnTick: SymbolInfoTick(_Symbol,Tick)] = 134 mcs.
2020.10.20 11:04:00.115 Test9 (AUDCHF,H1)       Alert: Bench_Stack = 0, 100 <= Time[Test9.mq5 7 in OnTick: SymbolInfoTick(_Symbol,Tick)] = 543 mcs.
2020.10.20 11:04:03.998 Test9 (EURCHF,H1)       Alert: Bench_Stack = 0, 100 <= Time[Test9.mq5 7 in OnTick: SymbolInfoTick(_Symbol,Tick)] = 102 mcs.
 
fxsaber:

Just reproduced the brakes when 6/8 Agents were running.

I.e. problem when CPU is loaded.

// Демонстрация тормозов SymbolInfoTick
#include <fxsaber\Benchmark\Benchmark.mqh> // https://www.mql5.com/ru/code/31279

void OnTick()
{
  MqlTick Tick;
  const uint StartTime = GetTickCount();
  
//  return;
  
  while (!IsStopped() && (GetTickCount() - StartTime < 10000))
  {
    _B(SymbolInfoTick(_Symbol, Tick), 500);
    
//    Sleep(0); // Специально убрал.
  }
}


MQ-Demo, 20 charts, b2656. Only Terminal is running on the machine, Tester is not running.

2020.10.20 11:14:18.615 Test9 (EURNZD,H1)       Alert: Bench_Stack = 0, 500 <= Time[Test9.mq5 13 in OnTick: SymbolInfoTick(_Symbol,Tick)] = 1111 mcs.
2020.10.20 11:14:18.615 Test9 (AUDCHF,H1)       Alert: Bench_Stack = 0, 500 <= Time[Test9.mq5 13 in OnTick: SymbolInfoTick(_Symbol,Tick)] = 660 mcs.
2020.10.20 11:14:18.615 Test9 (USDRUB,H1)       Alert: Bench_Stack = 0, 500 <= Time[Test9.mq5 13 in OnTick: SymbolInfoTick(_Symbol,Tick)] = 657 mcs.
2020.10.20 11:14:18.615 Test9 (EURCAD,H1)       Alert: Bench_Stack = 0, 500 <= Time[Test9.mq5 13 in OnTick: SymbolInfoTick(_Symbol,Tick)] = 1055 mcs.
2020.10.20 11:14:18.615 Test9 (AUDCAD,H1)       Alert: Bench_Stack = 0, 500 <= Time[Test9.mq5 13 in OnTick: SymbolInfoTick(_Symbol,Tick)] = 1052 mcs.
2020.10.20 11:14:18.615 Test9 (XAUUSD,H1)       Alert: Bench_Stack = 0, 500 <= Time[Test9.mq5 13 in OnTick: SymbolInfoTick(_Symbol,Tick)] = 1077 mcs.
2020.10.20 11:14:18.616 Test9 (USDSGD,H1)       Alert: Bench_Stack = 0, 500 <= Time[Test9.mq5 13 in OnTick: SymbolInfoTick(_Symbol,Tick)] = 1178 mcs.
2020.10.20 11:14:18.616 Test9 (USDJPY,H1)       Alert: Bench_Stack = 0, 500 <= Time[Test9.mq5 13 in OnTick: SymbolInfoTick(_Symbol,Tick)] = 1291 mcs.
2020.10.20 11:14:18.616 Test9 (GBPUSD,H1)       Alert: Bench_Stack = 0, 500 <= Time[Test9.mq5 13 in OnTick: SymbolInfoTick(_Symbol,Tick)] = 1209 mcs.
2020.10.20 11:14:18.616 Test9 (USDZAR,H1)       Alert: Bench_Stack = 0, 500 <= Time[Test9.mq5 13 in OnTick: SymbolInfoTick(_Symbol,Tick)] = 1244 mcs.
2020.10.20 11:14:18.646 Test9 (GBPUSD,H1)       Alert: Bench_Stack = 0, 500 <= Time[Test9.mq5 13 in OnTick: SymbolInfoTick(_Symbol,Tick)] = 623 mcs.
2020.10.20 11:14:18.646 Test9 (USDJPY,H1)       Alert: Bench_Stack = 0, 500 <= Time[Test9.mq5 13 in OnTick: SymbolInfoTick(_Symbol,Tick)] = 696 mcs.
2020.10.20 11:14:18.646 Test9 (NZDUSD,H1)       Alert: Bench_Stack = 0, 500 <= Time[Test9.mq5 13 in OnTick: SymbolInfoTick(_Symbol,Tick)] = 702 mcs.
2020.10.20 11:14:18.684 Test9 (USDTRY,H1)       Alert: Bench_Stack = 0, 500 <= Time[Test9.mq5 13 in OnTick: SymbolInfoTick(_Symbol,Tick)] = 502 mcs.
2020.10.20 11:14:18.684 Test9 (NZDUSD,H1)       Alert: Bench_Stack = 0, 500 <= Time[Test9.mq5 13 in OnTick: SymbolInfoTick(_Symbol,Tick)] = 664 mcs.
2020.10.20 11:14:18.684 Test9 (USDJPY,H1)       Alert: Bench_Stack = 0, 500 <= Time[Test9.mq5 13 in OnTick: SymbolInfoTick(_Symbol,Tick)] = 677 mcs.
2020.10.20 11:14:18.685 Test9 (USDSGD,H1)       Alert: Bench_Stack = 0, 500 <= Time[Test9.mq5 13 in OnTick: SymbolInfoTick(_Symbol,Tick)] = 1201 mcs.
2020.10.20 11:14:18.685 Test9 (AUDCAD,H1)       Alert: Bench_Stack = 0, 500 <= Time[Test9.mq5 13 in OnTick: SymbolInfoTick(_Symbol,Tick)] = 708 mcs.
2020.10.20 11:14:18.685 Test9 (GBPUSD,H1)       Alert: Bench_Stack = 0, 500 <= Time[Test9.mq5 13 in OnTick: SymbolInfoTick(_Symbol,Tick)] = 730 mcs.
2020.10.20 11:14:18.685 Test9 (XAUUSD,H1)       Alert: Bench_Stack = 0, 500 <= Time[Test9.mq5 13 in OnTick: SymbolInfoTick(_Symbol,Tick)] = 763 mcs.
2020.10.20 11:14:18.685 Test9 (USDZAR,H1)       Alert: Bench_Stack = 0, 500 <= Time[Test9.mq5 13 in OnTick: SymbolInfoTick(_Symbol,Tick)] = 773 mcs.
2020.10.20 11:14:18.685 Test9 (EURCAD,H1)       Alert: Bench_Stack = 0, 500 <= Time[Test9.mq5 13 in OnTick: SymbolInfoTick(_Symbol,Tick)] = 800 mcs.
2020.10.20 11:14:18.685 Test9 (EURNZD,H1)       Alert: Bench_Stack = 0, 500 <= Time[Test9.mq5 13 in OnTick: SymbolInfoTick(_Symbol,Tick)] = 808 mcs.
 
fxsaber:
fxsaber:

Just reproduced the brakes when 6/8 Agents were running.

I.e. the problem is when the CPU is loaded.

Is this new information for you?

 
Anton:

Is this new information for you?

I don't fully understand why it's impossible to get around these CPU load lags. Probably incompetent to do so.


However, below is a clean test that shows the problem of price data relevance in MT5. I have provided the code with comments. Briefly, the ticks are taken via SymbolInfoTick/stack and checked against each other. Particularly, to avoid gaps and large lags between identical ticks from different sources.

// Демонстрация лагов OnTick и OnBookEvent.

input uint inMinInterval = 1000; // Минимальное время (в мкс.) лага

// Структура тика, которую удобно будет выводить в ArrayPrint.
struct PRICE
{
  double bid;
  double ask;
  
  bool onTick; // true - источник OnTick+SymbolInfoTick, false - источник OnBookEvent+MarketBookGet
  
  ulong Interval; // Временной интервал между соседними записями.
  
  void Set( const double &dBid, const double &dAsk, const bool bTick )
  {
    static ulong PrevTime = ::GetMicrosecondCount();
    const ulong NewTime = ::GetMicrosecondCount();

    this.bid = dBid;
    this.ask = dAsk;
    
    this.onTick = bTick;
    
    this.Interval = NewTime - PrevTime;
    
    PrevTime = NewTime;    
  }
  
  // Записи одинаковые, если обе соответствующие цены совпадают.
  bool operator ==( const PRICE &Price ) const
  {
    return((this.bid == Price.bid) && (this.ask == Price.ask));
  }
};

PRICE Prices[1000]; // Массив для записи тиков из разных источников.
int Amount = 0;     // Количество записанных тиков

// Возвращает bid/ask-цены из стакана.
bool GetCurrentPrices( double &bid, double &ask )
{
  MqlBookInfo Bands[];

  const bool Res = MarketBookGet(_Symbol, Bands);

  if (Res)
    for (int i = ArraySize(Bands) - 2; i >= 0; i--)
      if (Bands[i].type == BOOK_TYPE_SELL)
      {
        ask = Bands[i].price;
        bid = Bands[i + 1].price;
        
        break;
      }
  
  return(Res);
}

// Если bid или ask стакана поменялся - записываем их.
bool SaveNewTick_Book()
{
  static double PrevBid = 0;
  static double PrevAsk = 0;
  
  double bid;
  double ask;
      
  const bool Res = !IsStopped() && GetCurrentPrices(bid, ask) && ((PrevBid != bid) || (PrevAsk != ask));
  
  if (Res)
  {
    PrevBid = bid;
    PrevAsk = ask;
    
    Prices[Amount++].Set(bid, ask, false);
    
    if (Amount == ArraySize(Prices)) // Если достигли конца массива - выходим.
      ExpertRemove();
  }
  
  return(Res);
}

// Записываем bid и ask
bool SaveNewTick_Tick()
{
  MqlTick Tick;
  
  const bool Res = !IsStopped() && SymbolInfoTick(_Symbol, Tick);
  
  if (Res)
  {
    Prices[Amount++].Set(Tick.bid, Tick.ask, true);
    
    if (Amount == ArraySize(Prices)) // Если достигли конца массива - выходим.
      ExpertRemove();
  }
  
  return(Res);
}

// Проверка на наличие багов и задержек.
void Check()
{    
  if (Amount > 3)
  {
    if ((Prices[Amount - 1].onTick == Prices[Amount - 2].onTick) && // Три подряд записи из одного источника - баг.
        (Prices[Amount - 2].onTick == Prices[Amount - 3].onTick))
      Alert("BUG!");
    else if ((Prices[Amount - 1] == Prices[Amount - 2]) &&  // Если цены подряд идущих записей совпадают
             (Prices[Amount - 1].Interval > inMinInterval)) // И временной интервал между ними большой - информируем.
    {
      Alert((Prices[Amount - 1].onTick ? "OnTick-lag! - " : "OnBook-lag! - ") + (string)Prices[Amount - 1].Interval + " mcs.");
      
      ArrayPrint(Prices, _Digits, NULL, Amount - 4, 4); // Выводим подробно проблему.
    }
  }
}

int OnInit()
{
  return(!MarketBookAdd(_Symbol)); // Подписались на стакан.
}

void OnBookEvent( const string &Symb )
{
  if ((Symb == _Symbol) && SaveNewTick_Book()) // Если записали новые цены из стакана,
    Check();                                   // проверяем.
}

void OnTick()
{
  if (SaveNewTick_Tick()) // Если записали цены тика,
    Check();              // проверяем.
}

void OnDeinit( const int )
{
  MarketBookRelease(_Symbol); // Отписались от стакана.
  
  ArrayPrint(Prices, _Digits, NULL, 0, Amount); // Вывод всех записей.
}


Result (only one MT5-b2656 running on the machine, CPU load around zero, one chart, Tester not used).

2020.10.20 12:26:19.680 Test9 (AUDCAD,H1)       Alert: OnTick-lag! - 9573 mcs.
2020.10.20 12:26:19.680 Test9 (AUDCAD,H1)             [bid]   [ask] [onTick] [Interval]
2020.10.20 12:26:19.680 Test9 (AUDCAD,H1)       [0] 0.92777 0.92780     true      76478
2020.10.20 12:26:19.680 Test9 (AUDCAD,H1)       [1] 0.92777 0.92780    false         64
2020.10.20 12:26:19.680 Test9 (AUDCAD,H1)       [2] 0.92777 0.92781    false      50552
2020.10.20 12:26:19.680 Test9 (AUDCAD,H1)       [3] 0.92777 0.92781     true       9573 // В OnTick пришел тик на 9 мс позже, чем он был в стакане.

...

2020.10.20 12:26:33.899 Test9 (AUDCAD,H1)       Alert: OnBook-lag! - 22153 mcs.
2020.10.20 12:26:33.899 Test9 (AUDCAD,H1)             [bid]   [ask] [onTick] [Interval]
2020.10.20 12:26:33.899 Test9 (AUDCAD,H1)       [0] 0.92776 0.92783     true     358403
2020.10.20 12:26:33.899 Test9 (AUDCAD,H1)       [1] 0.92776 0.92783    false       2361
2020.10.20 12:26:33.899 Test9 (AUDCAD,H1)       [2] 0.92776 0.92784     true    2215506
2020.10.20 12:26:33.899 Test9 (AUDCAD,H1)       [3] 0.92776 0.92784    false      22153 // В стакан пришел тик на 22 мс позже, чем он был в OnTick.


Please confirm the playback.

 

Intermediate total for a fast unloaded machine.

 

Question to the Developers.

Suppose SymbolInfoTick was executed for 5 ms. Will the tick correspond to the current time, or 5 ms before that?

 

The SymbolInfoTick brakes are closed. The upshot is this.

If the CPU is overloaded (like Optimize not even on all cores), SymbolInfoTick may take up to tens of milliseconds to complete. There is no answer why this most popular function in the Terminal doesn't snapshot regularly. If possible, make snapshots of it. And do not forget that even at zero CPU load the OnTick function may work tens of milliseconds later than a tick that comes to the Terminal.


All in all, rather sad, but it can't worry those who trade primitively.

 
fxsaber:

The SymbolInfoTick brakes are closed. The upshot is this.

If the CPU is overloaded (like Optimize not even on all cores), SymbolInfoTick may take up to tens of milliseconds to complete. There is no answer why this most popular function in the Terminal doesn't snapshot regularly. If possible, make snapshots of it. And do not forget that even at zero CPU load the OnTick function may work tens of milliseconds later than a tick that comes to the Terminal.


All in all, quite unfortunate, but it cannot bother those who trade primitively.

For those who trade "not primitive": the hardware has to be up to the task.

"not even on all cores" - are you talking about "6/8"? i.e. 6 processes, and each of them 100% loads one CPU core for the duration of the test? And there are only 4 physical cores? And sincerely surprised that on such background the test "lags"?

If this is indeed your level of understanding, then: "Learn, learn and learn again".

If you want to rape CPU with 16-20 threads - buy CPU with 20 physical cores at least.

 
Anton:

For those trading "not primitive": the hardware has to be up to the task.

"not even on all cores" - are you talking about "6/8"? I mean 6 processes, and each of them 100% loads one CPU core for the whole test time? And there are only 4 physical cores? And sincerely surprised that on such background the test "lags"?

If this is indeed your level of understanding, then: "Learn, learn and learn again".

If you want to rape CPU with 16-20 threads - buy CPU with 20 physical cores at least.

I'm sure I can prove that getting your current prices is very slow. The CPU load creates such sluggishness only because of incorrect implementation of the most important function in MQL5.

 
fxsaber:

I'm sure I can prove that your implementation of getting the current prices is very slow. The CPU load only creates such slows down due to incorrect implementation of the main function in MQL5.

Test code:

void OnTick()
  {
   MqlTick Tick;

   ulong gstart=GetMicrosecondCount();

   int   count=10000;
   for(int i=0; i<count; i++)
     {
      SymbolInfoTick(_Symbol, Tick);
     }

   ulong gend=GetMicrosecondCount()-gstart;
   Print(count," iterations, total time ", DoubleToString(gend/1000.0,3)," ms; avr time: ",DoubleToString(gend/1000.0/count,3)," ms");
  }
Prove it.