ФОРТС. Вопросы по исполнению - страница 86

 
fxsaber:
Моего случая нет. Есть логи терминала, одинаковые у всех пользователей.

Хорошо, логи одинаковые, но к сожалению, резудьтаты разные...

Вы упорно не видите разницы в 289 и 9 мс. 

Вот свеженькое (реал 1531)

2017.02.17 14:05:01.032 Trades  'xxxxx': buy limit 2.00 Eu-9.17 at 65030
2017.02.17 14:05:01.437 Trades  'xxxxx': accepted buy limit 2.00 Eu-9.17 at 65030
2017.02.17 14:05:01.444 Trades  'xxxxx': buy limit 2.00 Eu-9.17 at 65030 placed for execution in 412.406 ms (179.952 ms on server)
2017.02.17 14:05:01.449 Trades  'xxxxx': sell limit 1.00 BR-8.17 at 57.45
2017.02.17 14:05:01.603 Trades  'xxxxx': sell limit 1.00 LKOH-6.17 at 34098 placed for execution in 554.628 ms (195.343 ms on server)
2017.02.17 14:05:01.604 Trades  'xxxxx': accepted buy limit 3.00 MXI-6.17 at 2172.70
2017.02.17 14:05:01.604 Trades  'xxxxx': buy limit 3.00 MXI-6.17 at 2172.70 placed for execution in 537.273 ms (11.579 ms on server)
2017.02.17 14:05:01.608 Trades  'xxxxx': accepted sell limit 5.00 GBPU-6.17 at 1.2495
2017.02.17 14:05:02.012 Trades  'xxxxx': sell limit 5.00 GBPU-6.17 at 1.2495 placed for execution in 921.827 ms (1.396 ms on server)
2017.02.17 14:05:02.013 Trades  'xxxxx': accepted buy limit 5.00 HYDR-6.17 at 10779
2017.02.17 14:05:02.015 Trades  'xxxxx': accepted buy limit 2.00 MGNT-9.17 at 9611
2017.02.17 14:05:02.017 Trades  'xxxxx': accepted sell limit 2.00 MGNT-9.17 at 11001
2017.02.17 14:05:02.018 Trades  'xxxxx': accepted buy limit 1.00 ED-9.17 at 1.0601
2017.02.17 14:05:02.019 Trades  'xxxxx': buy limit 5.00 HYDR-6.17 at 10779 placed for execution in 929.618 ms (3.608 ms on server)
2017.02.17 14:05:02.022 Trades  'xxxxx': buy limit 2.00 MGNT-9.17 at 9611 placed for execution in 610.425 ms (3.848 ms on server)
2017.02.17 14:05:02.029 Trades  'xxxxx': sell limit 2.00 MGNT-9.17 at 11001 placed for execution in 616.804 ms (3.793 ms on server)
2017.02.17 14:05:02.030 Trades  'xxxxx': buy limit 1.00 ED-9.17 at 1.0601 placed for execution in 616.485 ms (3.712 ms on server)
2017.02.17 14:05:02.040 Trades  'xxxxx': cancel order #52607654 sell limit 1.00 LKOH-6.17 at 34098
2017.02.17 14:05:02.042 Trades  'xxxxx': accepted sell limit 1.00 ED-9.17 at 1.0849
2017.02.17 14:05:02.043 Trades  'xxxxx': sell limit 1.00 ED-9.17 at 1.0849 placed for execution in 629.309 ms (2.119 ms on server)
2017.02.17 14:05:02.215 Trades  'xxxxx': accepted buy limit 2.00 AUDU-6.17 at 0.7586
2017.02.17 14:05:02.216 Trades  'xxxxx': accepted buy limit 5.00 TATN-6.17 at 37027
2017.02.17 14:05:02.217 Trades  'xxxxx': accepted sell limit 5.00 AUDU-6.17 at 0.8025
2017.02.17 14:05:02.217 Trades  'xxxxx': buy limit 2.00 AUDU-6.17 at 0.7586 placed for execution in 793.001 ms (5.415 ms on server)
2017.02.17 14:05:02.519 Trades  'xxxxx': buy limit 5.00 TATN-6.17 at 37027 placed for execution in 1094.281 ms (5.535 ms on server)
2017.02.17 14:05:02.521 Trades  'xxxxx': sell limit 5.00 AUDU-6.17 at 0.8025 placed for execution in 1096.137 ms (5.514 ms on server)
2017.02.17 14:05:02.533 Trades  'xxxxx': accepted sell limit 5.00 TATN-6.17 at 42028
2017.02.17 14:05:02.533 Trades  'xxxxx': sell limit 5.00 TATN-6.17 at 42028 placed for execution in 1108.871 ms (1.341 ms on server)


 

 
prostotrader:

так, наверное, понятней будет

лог эксперта

2017.02.17 13:45:27.132 trader (RTS-3.17,M1)      COrder::Place: Order sent to server...
2017.02.17 13:45:27.141 trader (RTS-3.17,M1)      OnTradeTransaction: TRADE_TRANSACTION_REQUEST --> Order got ticket.
2017.02.17 13:45:27.421 trader (RTS-3.17,M1)      OnTradeTransaction: TRADE_TRANSACTION_ORDER_UPDATE--> ORDER_STATE_PLACED -- > Order place done.

289 мс. 

Лог терминала

2017.02.17 13:45:27.132 Trades  '1007932': buy limit 2.00 RTS-6.17 at 115190
2017.02.17 13:45:27.141 Trades  '1007932': accepted buy limit 2.00 RTS-6.17 at 115190
2017.02.17 13:45:27.141 Trades  '1007932': buy limit 2.00 RTS-6.17 at 115190 placed for execution in 8.526 ms

9 мс. 

Одним цветом обозначил одинаковые события. По какой-то причине в логе терминала обе строчки имеют 27.141.

В логе эксперта - 27.141 и аж 27.421. Похоже, OnTradeTransaction еще тормозит - событие в терминал пришло, а только через >200 мс оно отправилось в OnTradeTransaction. Возможно, что советник эти 200 мс что-то делал, поэтому такая задержка. Без исходника не скажу. 

 
fxsaber:

Одним цветом обозначил одинаковые события. По какой-то причине в логе терминала обе строчки имеют 27.141.

В логе эксперта - 27.141 и аж 27.421. Похоже, OnTradeTransaction еще тормозит - событие в терминал пришло, а только через >200 мс оно отправилось в OnTradeTransaction. Возможно, что советник эти 200 мс что-то делал, поэтому такая задержка. Без исходника не скажу. 

Вы попробуйте на демо открывашки это

//+------------------------------------------------------------------+
//|                                                   Test_delay.mq5 |
//|                        Copyright 2016, MetaQuotes Software Corp. |
//|                                             https://www.mql5.com |
//+------------------------------------------------------------------+
#property copyright "Copyright 2016, MetaQuotes Software Corp."
#property link      "https://www.mql5.com"
#property version   "1.00"

ulong order_ticket;
ulong Magic=1234567890;
ulong order_id;

//+------------------------------------------------------------------+
//| Expert initialization function                                   |
//+------------------------------------------------------------------+
int OnInit()
  {
   SetOrder();
   return(INIT_SUCCEEDED);
  }

//+------------------------------------------------------------------+
//| TradeTransaction function                                        |
//+------------------------------------------------------------------+
void OnTradeTransaction(const MqlTradeTransaction &trans,
                        const MqlTradeRequest &request,
                        const MqlTradeResult &result)
  {
   switch(trans.type)
     {
      case TRADE_TRANSACTION_REQUEST: if((order_id!=0) && (result.request_id==order_id))
        {
         order_ticket=result.order;
         Print(__FUNCTION__, ": TRADE_TRANSACTION_REQUEST --> Order got ticket.");
         order_id=0;
        }
      break;
      case TRADE_TRANSACTION_ORDER_UPDATE:  if((order_ticket!=0) && (trans.order==order_ticket))
        {
          switch(trans.order_state)
         {
          case ORDER_STATE_PLACED:
            Print(__FUNCTION__, ": TRADE_TRANSACTION_ORDER_UPDATE --> ORDER_STATE_PLACED --> Order place done.");
          break;
         }
        }
      break;
     }
  }
//+------------------------------------------------------------------+
//|                                                                  |
//+------------------------------------------------------------------+
void SetOrder()
  {
   MqlTradeRequest request={0};
   MqlTradeResult  result={0};
   order_id=0;
   order_ticket=0;
   request.magic=Magic;
   request.symbol=Symbol();
   request.volume=1;
   request.type_filling=ORDER_FILLING_RETURN;
   request.type_time=ORDER_TIME_DAY;
   request.action=TRADE_ACTION_PENDING;
   request.type=ORDER_TYPE_SELL_LIMIT;
   request.comment="";
   request.price=SymbolInfoDouble(Symbol(),SYMBOL_SESSION_PRICE_LIMIT_MAX);
   if(OrderSendAsync(request,result))
     {
      if((result.retcode==TRADE_RETCODE_PLACED) || (result.retcode==TRADE_RETCODE_DONE))
        {
         order_id=result.request_id;
         Print(__FUNCTION__, ": Order send to server.");
        }
     }
   else
     {Print("Order not send.");}
  }
//+------------------------------------------------------------------+

 

Лог теминала

2017.02.17 14:48:33.361 Trades  '1007932': sell limit 1.00 RTS-3.17 at 121900
2017.02.17 14:48:33.368 Trades  '1007932': accepted sell limit 1.00 RTS-3.17 at 121900
2017.02.17 14:48:33.369 Trades  '1007932': sell limit 1.00 RTS-3.17 at 121900 placed for execution in 8.077 ms

8 мс.

Лог эксперта

2017.02.17 14:48:33.361 Test_delay (RTS-3.17,M1)        SetOrder: Order send to server.
2017.02.17 14:48:33.369 Test_delay (RTS-3.17,M1)        OnTradeTransaction: TRADE_TRANSACTION_REQUEST --> Order got ticket.
2017.02.17 14:48:33.377 Test_delay (RTS-3.17,M1)        OnTradeTransaction: TRADE_TRANSACTION_ORDER_UPDATE --> ORDER_STATE_PLACED --> Order place done.

16 мс.

ГДЕ "ТОРМОЗИТ" эксперт???
 

 

А теперь усложним задачу, добавим синхронную установку ордера

//+------------------------------------------------------------------+
//|                                                   Test_delay.mq5 |
//|                        Copyright 2016, MetaQuotes Software Corp. |
//|                                             https://www.mql5.com |
//+------------------------------------------------------------------+
#property copyright "Copyright 2016, MetaQuotes Software Corp."
#property link      "https://www.mql5.com"
#property version   "1.00"

ulong order_ticket;
ulong sync_order;
ulong Magic=1234567890;
ulong order_id;

//+------------------------------------------------------------------+
//| Expert initialization function                                   |
//+------------------------------------------------------------------+
int OnInit()
  {
   SetOrder();
   return(INIT_SUCCEEDED);
  }

//+------------------------------------------------------------------+
//| TradeTransaction function                                        |
//+------------------------------------------------------------------+
void OnTradeTransaction(const MqlTradeTransaction &trans,
                        const MqlTradeRequest &request,
                        const MqlTradeResult &result)
  {
   switch(trans.type)
     {
      case TRADE_TRANSACTION_REQUEST: if((order_id!=0) && (result.request_id==order_id))
        {
         order_ticket=result.order;
         Print(__FUNCTION__, ": TRADE_TRANSACTION_REQUEST --> Order got ticket.");
         order_id=0;
        }
      break;
      case TRADE_TRANSACTION_ORDER_UPDATE:  if((order_ticket>0) && (trans.order==order_ticket))
        {
          switch(trans.order_state)
         {
          case ORDER_STATE_PLACED:
            Print(__FUNCTION__, ": TRADE_TRANSACTION_ORDER_UPDATE --> ORDER_STATE_PLACED --> Async Order place done.");
            SetSyncOrder();
          break;
         }
        }
        else
        if((sync_order>0) && (trans.order==sync_order))
          {
             switch(trans.order_state)
           {
            case ORDER_STATE_PLACED:
              Print(__FUNCTION__, ": TRADE_TRANSACTION_ORDER_UPDATE --> ORDER_STATE_PLACED --> Sync order place done. And found in terminal.");
            break;
           }
          }
        
      break;
     }
  }
//+------------------------------------------------------------------+
//|                                                                  |
//+------------------------------------------------------------------+
void SetSyncOrder()
  {
   MqlTradeRequest request={0};
   MqlTradeResult  result={0};
   order_id=0;
   sync_order=0;
   request.magic=Magic;
   request.symbol=Symbol();
   request.volume=1;
   request.type_filling=ORDER_FILLING_RETURN;
   request.type_time=ORDER_TIME_DAY;
   request.action=TRADE_ACTION_PENDING;
   request.type=ORDER_TYPE_SELL_LIMIT;
   request.comment="";
   request.price=SymbolInfoDouble(Symbol(),SYMBOL_SESSION_PRICE_LIMIT_MAX);
   Print(__FUNCTION__, ": Sync Order send to server...");
   if(OrderSend(request,result))
     {
      if((result.retcode==TRADE_RETCODE_PLACED) || (result.retcode==TRADE_RETCODE_DONE))
        {
         sync_order=result.order;
         Print(__FUNCTION__, ": Sync Order place done? but nof found in terminal.");
        }
     }
   else
     {Print("Order not send.");}
  }
  //---------------------
  void SetOrder()
  {
   MqlTradeRequest request={0};
   MqlTradeResult  result={0};
   order_id=0;
   order_ticket=0;
   request.magic=Magic;
   request.symbol=Symbol();
   request.volume=1;
   request.type_filling=ORDER_FILLING_RETURN;
   request.type_time=ORDER_TIME_DAY;
   request.action=TRADE_ACTION_PENDING;
   request.type=ORDER_TYPE_SELL_LIMIT;
   request.comment="";
   request.price=SymbolInfoDouble(Symbol(),SYMBOL_SESSION_PRICE_LIMIT_MAX);
   Print(__FUNCTION__, ": Async Order send to server...");
   if(OrderSendAsync(request,result))
     {
      if((result.retcode==TRADE_RETCODE_PLACED) || (result.retcode==TRADE_RETCODE_DONE))
        {
         order_id=result.request_id;
         Print(__FUNCTION__, ": Async Order got request ID.");
        }
     }
   else
     {Print("Order not send.");}
  }
//+------------------------------------------------------------------+

Лог терминала

2017.02.17 15:17:15.279 Trades  '1007932': sell limit 1.00 RTS-3.17 at 121900
2017.02.17 15:17:15.292 Trades  '1007932': accepted sell limit 1.00 RTS-3.17 at 121900
2017.02.17 15:17:15.292 Trades  '1007932': sell limit 1.00 RTS-3.17 at 121900 placed for execution in 13.559 ms
2017.02.17 15:17:15.297 Trades  '1007932': sell limit 1.00 RTS-3.17 at 121900
2017.02.17 15:17:15.308 Trades  '1007932': accepted sell limit 1.00 RTS-3.17 at 121900
2017.02.17 15:17:15.310 Trades  '1007932': sell limit 1.00 RTS-3.17 at 121900 placed for execution
2017.02.17 15:17:15.317 Trades  '1007932': order #54040029 sell limit 1.00 / 1.00 RTS-3.17 at 121900 done in 19.853 ms

Ассинхронный режим - 13 мс. (placed for execution)

Синхронный - 20 мс.
 

 Лог эксперта


2017.02.17 15:17:15.277 Test_delay (RTS-3.17,M1)        SetOrder: Async Order send to server...
2017.02.17 15:17:15.279 Test_delay (RTS-3.17,M1)        SetOrder: Async Order got request ID.
2017.02.17 15:17:15.292 Test_delay (RTS-3.17,M1)        OnTradeTransaction: TRADE_TRANSACTION_REQUEST --> Order got ticket.
2017.02.17 15:17:15.297 Test_delay (RTS-3.17,M1)        OnTradeTransaction: TRADE_TRANSACTION_ORDER_UPDATE --> ORDER_STATE_PLACED --> Async Order place done.
2017.02.17 15:17:15.297 Test_delay (RTS-3.17,M1)        SetSyncOrder: Sync Order send to server...
2017.02.17 15:17:15.317 Test_delay (RTS-3.17,M1)        SetSyncOrder: Sync Order place done? but nof found in terminal.
2017.02.17 15:17:15.317 Test_delay (RTS-3.17,M1)        OnTradeTransaction: TRADE_TRANSACTION_ORDER_UPDATE --> ORDER_STATE_PLACED --> Sync order place done. And found in terminal.

 Ассинхронный режим - 20 мс. (Куда терминал 7 мс дел ????)

Синхронный - 20 мс.

 

Никогда мы сами не сможем разобраться в причине задержек,

потому что связка для ФОРТС следующая:

Терминал --> Интернет --> Сеть брокера --> Сервер МТ5 --> Сеть брокера --> Интернет - Терминал

Если разработчики сами не захотят разобраться с задержкми, то так всё и будет.

 
prostotrader:

А теперь усложним задачу, добавим синхронную установку ордера

CI      0       14:59:53.943    Trades  '5122740': sell limit 1.00 MIX-3.17 at 225925
KL      0       14:59:53.997    Trades  '5122740': accepted sell limit 1.00 MIX-3.17 at 225925
OH      0       14:59:54.025    Trades  '5122740': order #134542376 sell limit 1.00 / 1.00 MIX-3.17 at market done in 82.884 ms
JF      0       14:59:54.026    Trades  '5122740': sell limit 1.00 MIX-3.17 at 225925
KM      0       14:59:54.082    Trades  '5122740': accepted sell limit 1.00 MIX-3.17 at 225925
PI      0       14:59:54.082    Trades  '5122740': order #134542377 sell limit 1.00 / 1.00 MIX-3.17 at market done in 57.025 ms
EN      0       14:59:53.942    Test (MIX-3.17,M1)      SetOrder: Async Order send to server...
PP      0       14:59:53.943    Test (MIX-3.17,M1)      SetOrder: Async Order got request ID.
JF      0       14:59:54.025    Test (MIX-3.17,M1)      OnTradeTransaction: TRADE_TRANSACTION_REQUEST --> Order got ticket.
GP      0       14:59:54.026    Test (MIX-3.17,M1)      OnTradeTransaction: TRADE_TRANSACTION_ORDER_UPDATE --> ORDER_STATE_PLACED --> Async Order place done.
KD      0       14:59:54.026    Test (MIX-3.17,M1)      SetSyncOrder: Sync Order send to server...
JM      0       14:59:54.082    Test (MIX-3.17,M1)      SetSyncOrder: Sync Order place done? but nof found in terminal.
DE      0       14:59:54.082    Test (MIX-3.17,M1)      OnTradeTransaction: TRADE_TRANSACTION_ORDER_UPDATE --> ORDER_STATE_PLACED --> Sync order place done. And found in terminal.

MQ-Demo.

 
prostotrader:

Никогда мы сами не сможем разобраться в причине задержек,

потому что связка для ФОРТС следующая:

Терминал --> Интернет --> Сеть брокера --> Сервер МТ5 --> Сеть брокера --> Интернет - Терминал

Если разработчики сами не захотят разобраться с задержкми, то так всё и будет.

Ну тормоза на MQ-Demo есть, поэтому устранят. И 100% тормозов на других серверах станет меньше.
 
fxsaber:

CI      0       14:59:53.943    Trades  '5122740': sell limit 1.00 MIX-3.17 at 225925
KL      0       14:59:53.997    Trades  '5122740': accepted sell limit 1.00 MIX-3.17 at 225925
OH      0       14:59:54.025    Trades  '5122740': order #134542376 sell limit 1.00 / 1.00 MIX-3.17 at market done in 82.884 ms
JF      0       14:59:54.026    Trades  '5122740': sell limit 1.00 MIX-3.17 at 225925
KM      0       14:59:54.082    Trades  '5122740': accepted sell limit 1.00 MIX-3.17 at 225925
PI      0       14:59:54.082    Trades  '5122740': order #134542377 sell limit 1.00 / 1.00 MIX-3.17 at market done in 57.025 ms
EN      0       14:59:53.942    Test (MIX-3.17,M1)      SetOrder: Async Order send to server...
PP      0       14:59:53.943    Test (MIX-3.17,M1)      SetOrder: Async Order got request ID.
JF      0       14:59:54.025    Test (MIX-3.17,M1)      OnTradeTransaction: TRADE_TRANSACTION_REQUEST --> Order got ticket.
GP      0       14:59:54.026    Test (MIX-3.17,M1)      OnTradeTransaction: TRADE_TRANSACTION_ORDER_UPDATE --> ORDER_STATE_PLACED --> Async Order place done.
KD      0       14:59:54.026    Test (MIX-3.17,M1)      SetSyncOrder: Sync Order send to server...
JM      0       14:59:54.082    Test (MIX-3.17,M1)      SetSyncOrder: Sync Order place done? but nof found in terminal.
DE      0       14:59:54.082    Test (MIX-3.17,M1)      OnTradeTransaction: TRADE_TRANSACTION_ORDER_UPDATE --> ORDER_STATE_PLACED --> Sync order place done. And found in terminal.

MQ-Demo.

А вот это не вызывает сомнения?

JF      0       14:59:54.025    Test (MIX-3.17,M1)      OnTradeTransaction: TRADE_TRANSACTION_REQUEST --> Order got ticket.
GP      0       14:59:54.026    Test (MIX-3.17,M1)      OnTradeTransaction: TRADE_TRANSACTION_ORDER_UPDATE --> ORDER_STATE_PLACED --> Async Order place done.

1 мс - НЕ МОЖЕТ БЫТЬ!

Проверьте ещё раз.

Добавлено

Я тестировал на 1525 билде
 

 
prostotrader:

А вот это не вызывает сомнения?

JF      0       14:59:54.025    Test (MIX-3.17,M1)      OnTradeTransaction: TRADE_TRANSACTION_REQUEST --> Order got ticket.
GP      0       14:59:54.026    Test (MIX-3.17,M1)      OnTradeTransaction: TRADE_TRANSACTION_ORDER_UPDATE --> ORDER_STATE_PLACED --> Async Order place done.

1 мс - НЕ МОЖЕТ БЫТЬ!

У меня сомнения вызывает только время, что прописывает сам терминал в лог.

Поэтому сделал так

//+------------------------------------------------------------------+
//|                                                   Test_delay.mq5 |
//|                        Copyright 2016, MetaQuotes Software Corp. |
//|                                             https://www.mql5.com |
//+------------------------------------------------------------------+
#property copyright "Copyright 2016, MetaQuotes Software Corp."
#property link      "https://www.mql5.com"
#property version   "1.00"

ulong order_ticket;
ulong sync_order;
ulong Magic=1234567890;
ulong order_id;

ulong StartTime;

//+------------------------------------------------------------------+
//| Expert initialization function                                   |
//+------------------------------------------------------------------+
int OnInit()
  {
   StartTime = GetMicrosecondCount();
  
   SetOrder();
   return(INIT_SUCCEEDED);
  }

//+------------------------------------------------------------------+
//| TradeTransaction function                                        |
//+------------------------------------------------------------------+
void OnTradeTransaction(const MqlTradeTransaction &trans,
                        const MqlTradeRequest &request,
                        const MqlTradeResult &result)
  {
   switch(trans.type)
     {
      case TRADE_TRANSACTION_REQUEST: if((order_id!=0) && (result.request_id==order_id))
        {
         Print(DoubleToString((GetMicrosecondCount() - StartTime) / 1000.0, 3));
         order_ticket=result.order;
         Print(__FUNCTION__, ": TRADE_TRANSACTION_REQUEST --> Order got ticket.");
         order_id=0;
        }
      break;
      case TRADE_TRANSACTION_ORDER_UPDATE:  if((order_ticket>0) && (trans.order==order_ticket))
        {
          switch(trans.order_state)
         {
          case ORDER_STATE_PLACED:
            Print(DoubleToString((GetMicrosecondCount() - StartTime) / 1000.0, 3));
            
            Print(__FUNCTION__, ": TRADE_TRANSACTION_ORDER_UPDATE --> ORDER_STATE_PLACED --> Async Order place done.");
            
            SetSyncOrder();
          break;
         }
        }
        else
        if((sync_order>0) && (trans.order==sync_order))
          {
             switch(trans.order_state)
           {
            case ORDER_STATE_PLACED:
              Print(DoubleToString((GetMicrosecondCount() - StartTime) / 1000.0, 3));            
              
              Print(__FUNCTION__, ": TRADE_TRANSACTION_ORDER_UPDATE --> ORDER_STATE_PLACED --> Sync order place done. And found in terminal.");
            break;
           }
          }
        
      break;
     }
  }
//+------------------------------------------------------------------+
//|                                                                  |
//+------------------------------------------------------------------+
void SetSyncOrder()
  {
   MqlTradeRequest request={0};
   MqlTradeResult  result={0};
   order_id=0;
   sync_order=0;
   request.magic=Magic;
   request.symbol=Symbol();
   request.volume=1;
   request.type_filling=ORDER_FILLING_RETURN;
   request.type_time=ORDER_TIME_DAY;
   request.action=TRADE_ACTION_PENDING;
   request.type=ORDER_TYPE_SELL_LIMIT;
   request.comment="";
   request.price=SymbolInfoDouble(Symbol(),SYMBOL_SESSION_PRICE_LIMIT_MAX);
   Print(__FUNCTION__, ": Sync Order send to server...");

   StartTime = GetMicrosecondCount();
  
   if(OrderSend(request,result))
     {
      if((result.retcode==TRADE_RETCODE_PLACED) || (result.retcode==TRADE_RETCODE_DONE))
        {
         sync_order=result.order;
         Print(__FUNCTION__, ": Sync Order place done? but nof found in terminal.");
        }
     }
   else
     {Print("Order not send.");}
  }
  //---------------------
  void SetOrder()
  {
   MqlTradeRequest request={0};
   MqlTradeResult  result={0};
   order_id=0;
   order_ticket=0;
   request.magic=Magic;
   request.symbol=Symbol();
   request.volume=1;
   request.type_filling=ORDER_FILLING_RETURN;
   request.type_time=ORDER_TIME_DAY;
   request.action=TRADE_ACTION_PENDING;
   request.type=ORDER_TYPE_SELL_LIMIT;
   request.comment="";
   request.price=SymbolInfoDouble(Symbol(),SYMBOL_SESSION_PRICE_LIMIT_MAX);
   Print(__FUNCTION__, ": Async Order send to server...");

   StartTime = GetMicrosecondCount();
  
   if(OrderSendAsync(request,result))
     {
      if((result.retcode==TRADE_RETCODE_PLACED) || (result.retcode==TRADE_RETCODE_DONE))
        {
         order_id=result.request_id;
         Print(__FUNCTION__, ": Async Order got request ID.");
        }
     }
   else
     {Print("Order not send.");}
  }
//+------------------------------------------------------------------+

Что у Вас выдает?
 

 
fxsaber:

Что у Вас выдает?

 

2017.02.17 16:20:47.292 Trades  '1007932': sell limit 1.00 RTS-3.17 at 121520
2017.02.17 16:20:47.299 Trades  '1007932': accepted sell limit 1.00 RTS-3.17 at 121520
2017.02.17 16:20:47.300 Trades  '1007932': sell limit 1.00 RTS-3.17 at 121520 placed for execution in 8.287 ms
2017.02.17 16:20:47.307 Trades  '1007932': sell limit 1.00 RTS-3.17 at 121520
2017.02.17 16:20:47.315 Trades  '1007932': accepted sell limit 1.00 RTS-3.17 at 121520
2017.02.17 16:20:47.316 Trades  '1007932': sell limit 1.00 RTS-3.17 at 121520 placed for execution
2017.02.17 16:20:47.323 Trades  '1007932': order #54042531 sell limit 1.00 / 1.00 RTS-3.17 at 121520 done in 15.978 ms


 

2017.02.17 16:17:57.121 Test_delay (RTS-3.17,M1)        SetOrder: Async Order send to server...
2017.02.17 16:17:57.122 Test_delay (RTS-3.17,M1)        SetOrder: Async Order got request ID.
2017.02.17 16:17:57.132 Test_delay (RTS-3.17,M1)        OnTradeTransaction: TRADE_TRANSACTION_REQUEST --> Order got ticket.
2017.02.17 16:17:57.146 Test_delay (RTS-3.17,M1)        OnTradeTransaction: TRADE_TRANSACTION_ORDER_UPDATE --> ORDER_STATE_PLACED --> Async Order place done.
2017.02.17 16:17:57.146 Test_delay (RTS-3.17,M1)        SetSyncOrder: Sync Order send to server...
2017.02.17 16:17:57.161 Test_delay (RTS-3.17,M1)        SetSyncOrder: Sync Order place done, but not found in terminal.
2017.02.17 16:17:57.161 Test_delay (RTS-3.17,M1)        OnTradeTransaction: TRADE_TRANSACTION_ORDER_UPDATE --> ORDER_STATE_PLACED --> Sync order place done and found in terminal.
2017.02.17 16:20:47.291 Test_delay (RTS-3.17,M1)        SetOrder: Async Order send to server...
2017.02.17 16:20:47.292 Test_delay (RTS-3.17,M1)        SetOrder: Async Order got request ID.
2017.02.17 16:20:47.300 Test_delay (RTS-3.17,M1)        8.305
2017.02.17 16:20:47.300 Test_delay (RTS-3.17,M1)        OnTradeTransaction: TRADE_TRANSACTION_REQUEST --> Order got ticket.
2017.02.17 16:20:47.307 Test_delay (RTS-3.17,M1)        15.644
2017.02.17 16:20:47.307 Test_delay (RTS-3.17,M1)        OnTradeTransaction: TRADE_TRANSACTION_ORDER_UPDATE --> ORDER_STATE_PLACED --> Async Order place done.
2017.02.17 16:20:47.307 Test_delay (RTS-3.17,M1)        SetSyncOrder: Sync Order send to server...
2017.02.17 16:20:47.323 Test_delay (RTS-3.17,M1)        SetSyncOrder: Sync Order place done? but nof found in terminal.
2017.02.17 16:20:47.323 Test_delay (RTS-3.17,M1)        16.033
2017.02.17 16:20:47.323 Test_delay (RTS-3.17,M1)        OnTradeTransaction: TRADE_TRANSACTION_ORDER_UPDATE --> ORDER_STATE_PLACED --> Sync order place done. And found in terminal.

Билд 1533

:):):) бредятина какя-то.... 

Добавлено

Какой смысл доаолнительно засекать время, тогда как на таком маленьком отрезке времени локальное время точное?