Синхронный OrderSend сообщает об успешном выполнении быстрее, чем пинг до торгового сервера

Новый комментарий
 

Сабж на двух примерах. Пинг ~42 мс.


Пример 1.

2020.09.29 01:20:48.220 Trades  '': modify order #1326958 sell limit 0.01 AUDUSD at 0.70769 sl: 0.00000 tp: 0.70719 -> 0.70770, sl: 0.00000 tp: 0.70719
2020.09.29 01:20:48.266 Trades  '': accepted modify order #1326958 sell limit 0.01 AUDUSD at 0.70769 sl: 0.00000 tp: 0.70719 -> 0.70770, sl: 0.00000 tp: 0.70719
2020.09.29 01:20:48.266 Trades  '': modify #1326958 sell limit 0.01 AUDUSD -> price: 0.70770, sl: 0.00000, tp: 0.70719) done in 45.685 ms
2020.09.29 01:20:48.266 Trades  '': modify #1326952 buy 0.01 AUDUSD sl: 0.00000, tp: 0.70769 -> sl: 0.00000, tp: 0.70770
2020.09.29 01:20:48.312 Trades  '': accepted modify #1326952 buy 0.01 AUDUSD sl: 0.00000, tp: 0.70769 -> sl: 0.00000, tp: 0.70770
2020.09.29 01:20:48.314 Trades  '': modify #1326952 buy 0.01 AUDUSD -> sl: 0.00000, tp: 0.70770 done in 47.742 ms
2020.09.29 01:20:48.322 Trades  '': modify order #1326968 sell limit 0.01 AUDUSD at 0.70767 sl: 0.00000 tp: 0.70698 -> 0.70768, sl: 0.00000 tp: 0.70698
2020.09.29 01:20:48.325 Trades  '': modify order #1327441 sell limit 0.01 EURJPY at 123.117 sl: 0.000 tp: 123.072 -> 123.118, sl: 0.000 tp: 123.072
2020.09.29 01:20:48.358 Trades  '': modify #1327441 sell limit 0.01 EURJPY -> price: 123.118, sl: 0.000, tp: 123.072) done in 33.410 ms
2020.09.29 01:20:48.368 Trades  '': accepted modify order #1326968 sell limit 0.01 AUDUSD at 0.70767 sl: 0.00000 tp: 0.70698 -> 0.70768, sl: 0.00000 tp: 0.70698
2020.09.29 01:20:48.369 Trades  '': modify #1326968 sell limit 0.01 AUDUSD -> price: 0.70768, sl: 0.00000, tp: 0.70698) done in 46.938 ms
2020.09.29 01:20:48.369 Trades  '': modify #1326962 buy 0.01 AUDUSD sl: 0.00000, tp: 0.70767 -> sl: 0.00000, tp: 0.70768
2020.09.29 01:20:48.413 Trades  '': accepted modify #1326962 buy 0.01 AUDUSD sl: 0.00000, tp: 0.70767 -> sl: 0.00000, tp: 0.70768
2020.09.29 01:20:48.414 Trades  '': modify #1326962 buy 0.01 AUDUSD -> sl: 0.00000, tp: 0.70768 done in 45.468 ms


Пример 2.

2020.09.29 01:24:29.624 Trades  '': modify #1327265 sell 0.01 AUDCHF sl: 0.00000, tp: 0.65370 -> sl: 0.00000, tp: 0.65371
2020.09.29 01:24:29.645 Trades  '': accepted modify #1327159 buy 0.02 AUDCAD sl: 0.00000, tp: 0.94622 -> sl: 0.00000, tp: 0.94623
2020.09.29 01:24:29.646 Trades  '': modify #1327159 buy 0.02 AUDCAD -> sl: 0.00000, tp: 0.94623 done in 45.419 ms
2020.09.29 01:24:29.670 Trades  '': accepted modify #1327265 sell 0.01 AUDCHF sl: 0.00000, tp: 0.65370 -> sl: 0.00000, tp: 0.65371
2020.09.29 01:24:29.677 Trades  '': modify #1327265 sell 0.01 AUDCHF -> sl: 0.00000, tp: 0.65371 done in 52.777 ms
2020.09.29 01:24:38.968 Trades  '': modify order #1327383 buy limit 0.01 EURNZD at 1.77901 sl: 0.00000 tp: 1.78005 -> 1.77900, sl: 0.00000 tp: 1.78005
2020.09.29 01:24:39.012 Trades  '': accepted modify order #1327383 buy limit 0.01 EURNZD at 1.77901 sl: 0.00000 tp: 1.78005 -> 1.77900, sl: 0.00000 tp: 1.78005
2020.09.29 01:24:39.014 Trades  '': modify #1327383 buy limit 0.01 EURNZD -> price: 1.77900, sl: 0.00000, tp: 1.78005) done in 46.665 ms
2020.09.29 01:24:39.014 Trades  '': modify #1327333 sell 0.01 EURNZD sl: 0.00000, tp: 1.77901 -> sl: 0.00000, tp: 1.77900
2020.09.29 01:24:39.060 Trades  '': accepted modify #1327333 sell 0.01 EURNZD sl: 0.00000, tp: 1.77901 -> sl: 0.00000, tp: 1.77900
2020.09.29 01:24:39.060 Trades  '': modify #1327333 sell 0.01 EURNZD -> sl: 0.00000, tp: 1.77900 done in 46.231 ms
2020.09.29 01:24:56.913 Trades  '': modify order #1326974 sell limit 0.02 EURSEK at 10.55341 sl: 0.00000 tp: 10.54938 -> 10.55347, sl: 0.00000 tp: 10.54938
2020.09.29 01:24:56.927 Trades  '': modify #1326974 sell limit 0.02 EURSEK -> price: 10.55347, sl: 0.00000, tp: 10.54938) done in 13.748 ms


Произвожу проверку на валидациюкорректность многих действий в MT5. Поэтому есть возможность ловить такие баги и иногда понимать механизм их возникновения.


Ниже по каждому случаю покажу, как это происходило.

Ветка предназначена для разработчиков. Надеюсь, огромное количество времени, что потрачу на разборы в этой ветке, будет потрачено с пользой.

 

Форум по трейдингу, автоматическим торговым системам и тестированию торговых стратегий

Синхронный OrderSend сообщает об успешном выполнении быстрее, чем пинг до торгового сервера, - обманывает

fxsaber, 2020.09.29 07:51

Пример 1.

2020.09.29 01:20:48.220 Trades  '': modify order #1326958 sell limit 0.01 AUDUSD at 0.70769 sl: 0.00000 tp: 0.70719 -> 0.70770, sl: 0.00000 tp: 0.70719
2020.09.29 01:20:48.266 Trades  '': accepted modify order #1326958 sell limit 0.01 AUDUSD at 0.70769 sl: 0.00000 tp: 0.70719 -> 0.70770, sl: 0.00000 tp: 0.70719
2020.09.29 01:20:48.266 Trades  '': modify #1326958 sell limit 0.01 AUDUSD -> price: 0.70770, sl: 0.00000, tp: 0.70719) done in 45.685 ms
2020.09.29 01:20:48.266 Trades  '': modify #1326952 buy 0.01 AUDUSD sl: 0.00000, tp: 0.70769 -> sl: 0.00000, tp: 0.70770
2020.09.29 01:20:48.312 Trades  '': accepted modify #1326952 buy 0.01 AUDUSD sl: 0.00000, tp: 0.70769 -> sl: 0.00000, tp: 0.70770
2020.09.29 01:20:48.314 Trades  '': modify #1326952 buy 0.01 AUDUSD -> sl: 0.00000, tp: 0.70770 done in 47.742 ms
2020.09.29 01:20:48.322 Trades  '': modify order #1326968 sell limit 0.01 AUDUSD at 0.70767 sl: 0.00000 tp: 0.70698 -> 0.70768, sl: 0.00000 tp: 0.70698
2020.09.29 01:20:48.325 Trades  '': modify order #1327441 sell limit 0.01 EURJPY at 123.117 sl: 0.000 tp: 123.072 -> 123.118, sl: 0.000 tp: 123.072
2020.09.29 01:20:48.358 Trades  '': modify #1327441 sell limit 0.01 EURJPY -> price: 123.118, sl: 0.000, tp: 123.072) done in 33.410 ms
2020.09.29 01:20:48.368 Trades  '': accepted modify order #1326968 sell limit 0.01 AUDUSD at 0.70767 sl: 0.00000 tp: 0.70698 -> 0.70768, sl: 0.00000 tp: 0.70698
2020.09.29 01:20:48.369 Trades  '': modify #1326968 sell limit 0.01 AUDUSD -> price: 0.70768, sl: 0.00000, tp: 0.70698) done in 46.938 ms
2020.09.29 01:20:48.369 Trades  '': modify #1326962 buy 0.01 AUDUSD sl: 0.00000, tp: 0.70767 -> sl: 0.00000, tp: 0.70768
2020.09.29 01:20:48.413 Trades  '': accepted modify #1326962 buy 0.01 AUDUSD sl: 0.00000, tp: 0.70767 -> sl: 0.00000, tp: 0.70768
2020.09.29 01:20:48.414 Trades  '': modify #1326962 buy 0.01 AUDUSD -> sl: 0.00000, tp: 0.70768 done in 45.468 ms

В этом примере успешная модификация отложки произошла за 33 мс при пинге 42 мс. Понятно, что чисто физически этого не могло произойти, поэтому это баг.

Ниже служебная информация на момент возникновения бага из MT4Orders-библиотеки , полную расшифровку которой постараюсь дать после.

2020.09.29 01:20:48.373  (EURJPY,M1)    Alert: OrderSend(1327441) - BUG!
2020.09.29 01:20:48.373  (EURJPY,M1)    Alert: Please send the logs to the coauthor - https://www.mql5.com/en/users/fxsaber
2020.09.29 01:20:48.373  (EURJPY,M1)    Alert: C:\Program Files\MetaTrader 5\MQL5\Logs\20200929.log
2020.09.29 01:20:48.443  (EURJPY,M1)    MT4Orders.mqh
2020.09.29 01:20:48.443  (EURJPY,M1)    Version = 2020.09.24
2020.09.29 01:20:48.443  (EURJPY,M1)    __MQLBUILD__ = 2622
2020.09.29 01:20:48.443  (EURJPY,M1)    2020.09.28 = 2020.09.28 00:00:00
2020.09.29 01:20:48.443  (EURJPY,M1)    ::AccountInfoString(ACCOUNT_SERVER) = RannForex-Server
2020.09.29 01:20:48.443  (EURJPY,M1)    (ENUM_ACCOUNT_TRADE_MODE)::AccountInfoInteger(ACCOUNT_TRADE_MODE) = ACCOUNT_TRADE_MODE_REAL (2)
2020.09.29 01:20:48.443  (EURJPY,M1)    (bool)::TerminalInfoInteger(TERMINAL_CONNECTED) = true
2020.09.29 01:20:48.443  (EURJPY,M1)    ::TerminalInfoInteger(TERMINAL_PING_LAST) = 42576
2020.09.29 01:20:48.443  (EURJPY,M1)    ::TerminalInfoDouble(TERMINAL_RETRANSMISSION) = 0.0
2020.09.29 01:20:48.443  (EURJPY,M1)    ::TerminalInfoInteger(TERMINAL_BUILD) = 2622
2020.09.29 01:20:48.443  (EURJPY,M1)    (bool)::TerminalInfoInteger(TERMINAL_X64) = true
2020.09.29 01:20:48.443  (EURJPY,M1)    (bool)::TerminalInfoInteger(TERMINAL_VPS) = false
2020.09.29 01:20:48.443  (EURJPY,M1)    (ENUM_PROGRAM_TYPE)::MQLInfoInteger(MQL_PROGRAM_TYPE) = PROGRAM_EXPERT (2)
2020.09.29 01:20:48.443  (EURJPY,M1)    ::TimeCurrent() = 2020.09.29 01:22:21
2020.09.29 01:20:48.443  (EURJPY,M1)    ::TimeTradeServer() = 2020.09.29 01:20:48
2020.09.29 01:20:48.443  (EURJPY,M1)    MT4ORDERS::TimeToString(MT4ORDERS::GetTimeCurrent()) = 2020.09.29 01:22:21.763
2020.09.29 01:20:48.443  (EURJPY,M1)    MT4ORDERS::TimeToString(PrevTimeCurrent) = 2020.09.29 01:22:21.722
2020.09.29 01:20:48.443  (EURJPY,M1)    PrevTick = Symb = EURJPY time = 2020.09.29 01:22:21.722 bid = 123.118 ask = 123.119 last = 0.000 volume = 0 6 TICK_FLAG_BID TICK_FLAG_ASK
2020.09.29 01:20:48.443  (EURJPY,M1)    CurrentTick = ::SymbolInfoTick(Symb,Tick) = true Symb = EURJPY time = 2020.09.29 01:22:21.722 bid = 123.118 ask = 123.119 last = 0.000 volume = 0 0
2020.09.29 01:20:48.443  (EURJPY,M1)    ::SymbolInfoString(Request.symbol,SYMBOL_PATH) = RF\Forex\Minors\EURJPY
2020.09.29 01:20:48.443  (EURJPY,M1)    ::SymbolInfoString(Request.symbol,SYMBOL_DESCRIPTION) = Euro vs Japanese Yen
2020.09.29 01:20:48.443  (EURJPY,M1)    ::PositionsTotal() = 62
2020.09.29 01:20:48.443  (EURJPY,M1)    ::OrdersTotal() = 74
2020.09.29 01:20:48.443  (EURJPY,M1)    ::HistorySelect(0,INT_MAX) = true
2020.09.29 01:20:48.443  (EURJPY,M1)    ::HistoryDealsTotal() = 18082
2020.09.29 01:20:48.443  (EURJPY,M1)    ::HistoryOrdersTotal() = 24007
2020.09.29 01:20:48.443  (EURJPY,M1)    ::HistoryDealGetTicket(::HistoryDealsTotal()-1) = 682389
2020.09.29 01:20:48.443  (EURJPY,M1)    DEAL_TIME_MSC = 2020.09.29 01:20:52.633
2020.09.29 01:20:48.443  (EURJPY,M1)    ::HistoryOrderGetTicket(::HistoryOrdersTotal()-1) = 1327515
2020.09.29 01:20:48.443  (EURJPY,M1)    ORDER_TIME_DONE_MSC = 2020.09.29 01:22:21.743
2020.09.29 01:20:48.443  (EURJPY,M1)    ::TerminalInfoInteger(TERMINAL_MEMORY_AVAILABLE) = 30885
2020.09.29 01:20:48.443  (EURJPY,M1)    ::TerminalInfoInteger(TERMINAL_MEMORY_PHYSICAL) = 16301
2020.09.29 01:20:48.443  (EURJPY,M1)    ::TerminalInfoInteger(TERMINAL_MEMORY_TOTAL) = 32602
2020.09.29 01:20:48.443  (EURJPY,M1)    ::TerminalInfoInteger(TERMINAL_MEMORY_USED) = 1717
2020.09.29 01:20:48.443  (EURJPY,M1)    ::MQLInfoInteger(MQL_MEMORY_LIMIT) = 8388608
2020.09.29 01:20:48.443  (EURJPY,M1)    ::MQLInfoInteger(MQL_MEMORY_USED) = 5
2020.09.29 01:20:48.443  (EURJPY,M1)    MT4ORDERS::IsHedging = true
2020.09.29 01:20:48.443  (EURJPY,M1)    Res = true
2020.09.29 01:20:48.443  (EURJPY,M1)    MT4ORDERS::OrderSendBug = 33249
2020.09.29 01:20:48.443  (EURJPY,M1)    Request.action = TRADE_ACTION_MODIFY (7)
2020.09.29 01:20:48.443  (EURJPY,M1)    Request.magic = 0
2020.09.29 01:20:48.443  (EURJPY,M1)    Request.order = 1327441
2020.09.29 01:20:48.443  (EURJPY,M1)    Request.symbol = EURJPY
2020.09.29 01:20:48.443  (EURJPY,M1)    Request.volume = 0.0
2020.09.29 01:20:48.443  (EURJPY,M1)    Request.price = 123.118
2020.09.29 01:20:48.443  (EURJPY,M1)    Request.stoplimit = 0.0
2020.09.29 01:20:48.443  (EURJPY,M1)    Request.sl = 0.0
2020.09.29 01:20:48.443  (EURJPY,M1)    Request.tp = 123.072
2020.09.29 01:20:48.443  (EURJPY,M1)    Request.deviation = 0
2020.09.29 01:20:48.443  (EURJPY,M1)    Request.type = ORDER_TYPE_BUY (0)
2020.09.29 01:20:48.443  (EURJPY,M1)    Request.type_filling = ORDER_FILLING_FOK (0)
2020.09.29 01:20:48.443  (EURJPY,M1)    Request.type_time = ORDER_TIME_GTC (0)
2020.09.29 01:20:48.443  (EURJPY,M1)    Request.expiration = 1970.01.01 00:00:00
2020.09.29 01:20:48.443  (EURJPY,M1)    Request.comment = 
2020.09.29 01:20:48.444  (EURJPY,M1)    Request.position = 0
2020.09.29 01:20:48.444  (EURJPY,M1)    Request.position_by = 0
2020.09.29 01:20:48.444  (EURJPY,M1)    Result.retcode = 10009
2020.09.29 01:20:48.444  (EURJPY,M1)    Result.deal = 0
2020.09.29 01:20:48.444  (EURJPY,M1)    Result.order = 1327441
2020.09.29 01:20:48.444  (EURJPY,M1)    Result.volume = 0.01
2020.09.29 01:20:48.444  (EURJPY,M1)    Result.price = 123.117
2020.09.29 01:20:48.444  (EURJPY,M1)    Result.bid = 0.0
2020.09.29 01:20:48.444  (EURJPY,M1)    Result.ask = 0.0
2020.09.29 01:20:48.444  (EURJPY,M1)    Result.comment = Request executed 33.456 + 14.291 (33249) ms.
2020.09.29 01:20:48.444  (EURJPY,M1)    Result.request_id = 7049
2020.09.29 01:20:48.444  (EURJPY,M1)    Result.retcode_external = 0


Хронологическая расшифровка.

  1. Пинг 42 мс.
  2. Стоит SellLimit = 123.117.
  3. Приходит тик, у которого bid = 123.118. SellLimit, скорее всего, акцептировался в этот момент на торговом сервере, но не исполнился - реджект. К сожалению, такие вещи в Терминале не отражаются.
  4. Шлется торговый приказ (синхронный OrderSend) на модификацию, чтобы SellLimit сдвинулся на текущую bid-цену - 123.118.
  5. Через 33 мс OrderSend сообщает, что все отлично и модификация удалась. При этом в ответе Result.price = 123.117 - старая цена до модификации.
  6. Через 14 мс (33249 раз проверялось соответствие) в Терминал физически (про пинг не забываем) приходят данные, что у ордера, действительно, цена модифицировалась на 123.118.
Пункт 5 показывает сразу ошибку - Result.price не соответствует Request.price при удачной OrderSend. Причина бага, скорее всего, в пункте 3.
 

Форум по трейдингу, автоматическим торговым системам и тестированию торговых стратегий

Синхронный OrderSend сообщает об успешном выполнении быстрее, чем пинг до торгового сервера, - обманывает

fxsaber, 2020.09.29 07:51

Пример 2.

2020.09.29 01:24:29.624 Trades  '': modify #1327265 sell 0.01 AUDCHF sl: 0.00000, tp: 0.65370 -> sl: 0.00000, tp: 0.65371
2020.09.29 01:24:29.645 Trades  '': accepted modify #1327159 buy 0.02 AUDCAD sl: 0.00000, tp: 0.94622 -> sl: 0.00000, tp: 0.94623
2020.09.29 01:24:29.646 Trades  '': modify #1327159 buy 0.02 AUDCAD -> sl: 0.00000, tp: 0.94623 done in 45.419 ms
2020.09.29 01:24:29.670 Trades  '': accepted modify #1327265 sell 0.01 AUDCHF sl: 0.00000, tp: 0.65370 -> sl: 0.00000, tp: 0.65371
2020.09.29 01:24:29.677 Trades  '': modify #1327265 sell 0.01 AUDCHF -> sl: 0.00000, tp: 0.65371 done in 52.777 ms
2020.09.29 01:24:38.968 Trades  '': modify order #1327383 buy limit 0.01 EURNZD at 1.77901 sl: 0.00000 tp: 1.78005 -> 1.77900, sl: 0.00000 tp: 1.78005
2020.09.29 01:24:39.012 Trades  '': accepted modify order #1327383 buy limit 0.01 EURNZD at 1.77901 sl: 0.00000 tp: 1.78005 -> 1.77900, sl: 0.00000 tp: 1.78005
2020.09.29 01:24:39.014 Trades  '': modify #1327383 buy limit 0.01 EURNZD -> price: 1.77900, sl: 0.00000, tp: 1.78005) done in 46.665 ms
2020.09.29 01:24:39.014 Trades  '': modify #1327333 sell 0.01 EURNZD sl: 0.00000, tp: 1.77901 -> sl: 0.00000, tp: 1.77900
2020.09.29 01:24:39.060 Trades  '': accepted modify #1327333 sell 0.01 EURNZD sl: 0.00000, tp: 1.77901 -> sl: 0.00000, tp: 1.77900
2020.09.29 01:24:39.060 Trades  '': modify #1327333 sell 0.01 EURNZD -> sl: 0.00000, tp: 1.77900 done in 46.231 ms
2020.09.29 01:24:56.913 Trades  '': modify order #1326974 sell limit 0.02 EURSEK at 10.55341 sl: 0.00000 tp: 10.54938 -> 10.55347, sl: 0.00000 tp: 10.54938
2020.09.29 01:24:56.927 Trades  '': modify #1326974 sell limit 0.02 EURSEK -> price: 10.55347, sl: 0.00000, tp: 10.54938) done in 13.748 ms

В этом примере успешная модификация отложки произошла за 13 мс при пинге 42 мс. Понятно, что чисто физически этого не могло произойти, поэтому это баг.

Ниже служебная информация на момент возникновения бага из MT4Orders-библиотеки , полную расшифровку которой постараюсь дать после.

2020.09.29 01:24:56.959  (EURSEK,M1)    Alert: OrderSend(1326974) - BUG!
2020.09.29 01:24:56.959  (EURSEK,M1)    Alert: Please send the logs to the coauthor - https://www.mql5.com/en/users/fxsaber
2020.09.29 01:24:56.959  (EURSEK,M1)    Alert: C:\Program Files\MetaTrader 5\MQL5\Logs\20200929.log
2020.09.29 01:24:57.029  (EURSEK,M1)    MT4Orders.mqh
2020.09.29 01:24:57.029  (EURSEK,M1)    Version = 2020.09.24
2020.09.29 01:24:57.029  (EURSEK,M1)    __MQLBUILD__ = 2622
2020.09.29 01:24:57.029  (EURSEK,M1)    2020.09.28 = 2020.09.28 00:00:00
2020.09.29 01:24:57.029  (EURSEK,M1)    ::AccountInfoString(ACCOUNT_SERVER) = RannForex-Server
2020.09.29 01:24:57.029  (EURSEK,M1)    (ENUM_ACCOUNT_TRADE_MODE)::AccountInfoInteger(ACCOUNT_TRADE_MODE) = ACCOUNT_TRADE_MODE_REAL (2)
2020.09.29 01:24:57.029  (EURSEK,M1)    (bool)::TerminalInfoInteger(TERMINAL_CONNECTED) = true
2020.09.29 01:24:57.029  (EURSEK,M1)    ::TerminalInfoInteger(TERMINAL_PING_LAST) = 42576
2020.09.29 01:24:57.029  (EURSEK,M1)    ::TerminalInfoDouble(TERMINAL_RETRANSMISSION) = 0.0
2020.09.29 01:24:57.029  (EURSEK,M1)    ::TerminalInfoInteger(TERMINAL_BUILD) = 2622
2020.09.29 01:24:57.029  (EURSEK,M1)    (bool)::TerminalInfoInteger(TERMINAL_X64) = true
2020.09.29 01:24:57.029  (EURSEK,M1)    (bool)::TerminalInfoInteger(TERMINAL_VPS) = false
2020.09.29 01:24:57.029  (EURSEK,M1)    (ENUM_PROGRAM_TYPE)::MQLInfoInteger(MQL_PROGRAM_TYPE) = PROGRAM_EXPERT (2)
2020.09.29 01:24:57.029  (EURSEK,M1)    ::TimeCurrent() = 2020.09.29 01:26:30
2020.09.29 01:24:57.029  (EURSEK,M1)    ::TimeTradeServer() = 2020.09.29 01:24:56
2020.09.29 01:24:57.029  (EURSEK,M1)    MT4ORDERS::TimeToString(MT4ORDERS::GetTimeCurrent()) = 2020.09.29 01:26:30.337
2020.09.29 01:24:57.029  (EURSEK,M1)    MT4ORDERS::TimeToString(PrevTimeCurrent) = 2020.09.29 01:26:30.307
2020.09.29 01:24:57.029  (EURSEK,M1)    PrevTick = Symb = EURSEK time = 2020.09.29 01:26:30.307 bid = 10.55347 ask = 10.56422 last = 0.00000 volume = 0 6 TICK_FLAG_BID TICK_FLAG_ASK
2020.09.29 01:24:57.029  (EURSEK,M1)    CurrentTick = ::SymbolInfoTick(Symb,Tick) = true Symb = EURSEK time = 2020.09.29 01:26:30.307 bid = 10.55347 ask = 10.56422 last = 0.00000 volume = 0 0
2020.09.29 01:24:57.029  (EURSEK,M1)    ::SymbolInfoString(Request.symbol,SYMBOL_PATH) = RF\Forex\Exotics\EURSEK
2020.09.29 01:24:57.029  (EURSEK,M1)    ::SymbolInfoString(Request.symbol,SYMBOL_DESCRIPTION) = Euro vs Swedish Krone
2020.09.29 01:24:57.029  (EURSEK,M1)    ::PositionsTotal() = 62
2020.09.29 01:24:57.029  (EURSEK,M1)    ::OrdersTotal() = 74
2020.09.29 01:24:57.029  (EURSEK,M1)    ::HistorySelect(0,INT_MAX) = true
2020.09.29 01:24:57.029  (EURSEK,M1)    ::HistoryDealsTotal() = 18084
2020.09.29 01:24:57.029  (EURSEK,M1)    ::HistoryOrdersTotal() = 24009
2020.09.29 01:24:57.029  (EURSEK,M1)    ::HistoryDealGetTicket(::HistoryDealsTotal()-1) = 682391
2020.09.29 01:24:57.029  (EURSEK,M1)    DEAL_TIME_MSC = 2020.09.29 01:22:56.431
2020.09.29 01:24:57.029  (EURSEK,M1)    ::HistoryOrderGetTicket(::HistoryOrdersTotal()-1) = 1327516
2020.09.29 01:24:57.029  (EURSEK,M1)    ORDER_TIME_DONE_MSC = 2020.09.29 01:22:21.824
2020.09.29 01:24:57.029  (EURSEK,M1)    ::TerminalInfoInteger(TERMINAL_MEMORY_AVAILABLE) = 30884
2020.09.29 01:24:57.029  (EURSEK,M1)    ::TerminalInfoInteger(TERMINAL_MEMORY_PHYSICAL) = 16301
2020.09.29 01:24:57.029  (EURSEK,M1)    ::TerminalInfoInteger(TERMINAL_MEMORY_TOTAL) = 32602
2020.09.29 01:24:57.029  (EURSEK,M1)    ::TerminalInfoInteger(TERMINAL_MEMORY_USED) = 1718
2020.09.29 01:24:57.029  (EURSEK,M1)    ::MQLInfoInteger(MQL_MEMORY_LIMIT) = 8388608
2020.09.29 01:24:57.029  (EURSEK,M1)    ::MQLInfoInteger(MQL_MEMORY_USED) = 5
2020.09.29 01:24:57.029  (EURSEK,M1)    MT4ORDERS::IsHedging = true
2020.09.29 01:24:57.029  (EURSEK,M1)    Res = true
2020.09.29 01:24:57.029  (EURSEK,M1)    MT4ORDERS::OrderSendBug = 77457
2020.09.29 01:24:57.029  (EURSEK,M1)    Request.action = TRADE_ACTION_MODIFY (7)
2020.09.29 01:24:57.029  (EURSEK,M1)    Request.magic = 0
2020.09.29 01:24:57.029  (EURSEK,M1)    Request.order = 1326974
2020.09.29 01:24:57.029  (EURSEK,M1)    Request.symbol = EURSEK
2020.09.29 01:24:57.029  (EURSEK,M1)    Request.volume = 0.0
2020.09.29 01:24:57.029  (EURSEK,M1)    Request.price = 10.55347
2020.09.29 01:24:57.029  (EURSEK,M1)    Request.stoplimit = 0.0
2020.09.29 01:24:57.029  (EURSEK,M1)    Request.sl = 0.0
2020.09.29 01:24:57.029  (EURSEK,M1)    Request.tp = 10.54938
2020.09.29 01:24:57.029  (EURSEK,M1)    Request.deviation = 0
2020.09.29 01:24:57.029  (EURSEK,M1)    Request.type = ORDER_TYPE_BUY (0)
2020.09.29 01:24:57.029  (EURSEK,M1)    Request.type_filling = ORDER_FILLING_FOK (0)
2020.09.29 01:24:57.029  (EURSEK,M1)    Request.type_time = ORDER_TIME_GTC (0)
2020.09.29 01:24:57.029  (EURSEK,M1)    Request.expiration = 1970.01.01 00:00:00
2020.09.29 01:24:57.029  (EURSEK,M1)    Request.comment = 
2020.09.29 01:24:57.029  (EURSEK,M1)    Request.position = 0
2020.09.29 01:24:57.029  (EURSEK,M1)    Request.position_by = 0
2020.09.29 01:24:57.029  (EURSEK,M1)    Result.retcode = 10009
2020.09.29 01:24:57.029  (EURSEK,M1)    Result.deal = 0
2020.09.29 01:24:57.029  (EURSEK,M1)    Result.order = 1326974
2020.09.29 01:24:57.029  (EURSEK,M1)    Result.volume = 0.02
2020.09.29 01:24:57.029  (EURSEK,M1)    Result.price = 10.55341
2020.09.29 01:24:57.029  (EURSEK,M1)    Result.bid = 0.0
2020.09.29 01:24:57.029  (EURSEK,M1)    Result.ask = 0.0
2020.09.29 01:24:57.029  (EURSEK,M1)    Result.comment = Request executed 13.785 + 31.910 (77457) ms.
2020.09.29 01:24:57.029  (EURSEK,M1)    Result.request_id = 7102
2020.09.29 01:24:57.029  (EURSEK,M1)    Result.retcode_external = 0


Хронологическая расшифровка.

  1. Пинг 42 мс.
  2. Стоит SellLimit = 10.55341.
  3. Приходит тик, у которого bid = 10.55347. SellLimit, скорее всего, акцептировался в этот момент на торговом сервере, но не исполнился - реджект. К сожалению, такие вещи в Терминале не отражаются.
  4. Шлется торговый приказ (синхронный OrderSend) на модификацию, чтобы SellLimit сдвинулся на текущую bid-цену - 10.55347.
  5. Через 13 мс OrderSend сообщает, что все отлично и модификация удалась. При этом в ответе Result.price = 10.55341 - старая цена до модификации.
  6. Через 31 мс (77457 раз проверялось соответствие) в Терминал физически (про пинг не забываем) приходят данные, что у ордера, действительно, цена модифицировалась на 10.55347.
Пункт 5 показывает сразу ошибку - Result.price не соответствует Request.price при удачной OrderSend. Причина бага, скорее всего, в пункте 3.
 

Прошу разработчиков подтвердить, что исходные логи говорят о баге, и сообщить о билде с его исправлением.

Постарался дать максимальную информацию по теме, чтобы найти затык.

 
А почему в названии темы фигурирует слово "обманывает" (наводящее на соот.мысли), если далее Вы говорите о баге? 

Если имеется ввиду "баг обманывает", то ясно и вопросов нет, но следует подправить название темы во избежание двусмысленности. Имхо.
 
Реter Konow:
А почему в названии темы фигурирует слово "обманывает" (наводящее на соот.мысли), если далее, Вы говорите о баге? 

Замените на более подходящее слово. У меня плохо с русским языком.

 
fxsaber:

Замените на более подходящее слово. У меня плохо с русским языком.

Просто замените слово "обманывает" на слово "почему?". 
 

Добрый день,

1. У вас эксперты на этом счете торгуют и модифицируют ордера только с одного терминала? Или есть еще экземпляр терминала делающий тоже самое (модифицирующий те же ордера)?

2. Сколько экспертов/скриптов вы запускаете одновременно на терминале, которые занимаются модификацией?

То есть как в логах вы получаете:

2020.09.29 01:24:29.624 Trades  '': modify #1327265 sell 0.01 AUDCHF sl: 0.00000, tp: 0.65370 -> sl: 0.00000, tp: 0.65371
// тут не дождались результатов по AUDCHF
// зато начали получать результаты по AUDCAD
2020.09.29 01:24:29.645 Trades  '': accepted modify #1327159 buy 0.02 AUDCAD sl: 0.00000, tp: 0.94622 -> sl: 0.00000, tp: 0.94623
2020.09.29 01:24:29.646 Trades  '': modify #1327159 buy 0.02 AUDCAD -> sl: 0.00000, tp: 0.94623 done in 45.419 ms
// и только тут получили ответ по ордеру AUDCHF 
2020.09.29 01:24:29.670 Trades  '': accepted modify #1327265 sell 0.01 AUDCHF sl: 0.00000, tp: 0.65370 -> sl: 0.00000, tp: 0.65371
2020.09.29 01:24:29.677 Trades  '': modify #1327265 sell 0.01 AUDCHF -> sl: 0.00000, tp: 0.65371 done in 52.777 ms

выглядит будто запросы шлются параллельно (или через Async либо есть нескольких работающих экспертов/скриптов) и происходит такое смешивание в логах.

Опиши, что открыто и что запущенно на терминале, на котором у вас получаются такие результаты (с исполнением запросов за 13 мс).

3. Делается ли модификация одних и тех ордеров из разных экспертов/терминалов?



4. Посмотрите и напишите к какой точке доступа вы были подключены на момент 2020.09.29 01:20:48. Это можно найти в логах:
2020.09.29 14:04:00.160    Network    '': authorized on XXX through as.eu 5 (ping: 66.66 ms, build 2615)

5. Запустите рескан серверов из терминала (в правом нижнем углу терминала где пишется качество соединения и пинг):


6. Дождитесь результатов рескана (scanning network finished):

...
2020.09.29 14:06:56.482 Network '': scanning network finished

Приведите скриншот как выглядят точки доступа после рескана и какие у них пинги:

7. Сделайте еще один рескан (лучше несколько) и убедитесь что значения пингов сильно не скачут.

Интересует какой реально минимальный пинг будет до целевого сервера через вашу точку доступа (ту через которую вы были подключены).


8. Можете в личку приложить полный лог терминала за сегодня для разбора.

 
Anton:

1. У вас эксперты на этом счете торгуют и модифицируют ордера только с одного терминала? Или есть еще экземпляр терминала делающий тоже самое (модифицирующий те же ордера)?

С одного Терминала.

2. Сколько экспертов/скриптов вы запускаете одновременно на терминале, которые занимаются модификацией?

То есть как в логах вы получаете:

выглядит будто запросы шлются параллельно (или через Async либо есть нескольких работающих экспертов/скриптов) и происходит такое смешивание в логах.

Опиши, что открыто и что запущенно на терминале, на котором у вас получаются такие результаты (с исполнением запросов за 13 мс).

Было запущено 17 советников на M1-чартах разных символов с такими свойствами.

Всего торговалось 17 символов. Каждый советник обращается только к своему символу. Бары и индикаторы не используются. Подкачиваются свежие тики через CopyTicksRange с момента последнего вызова OnTick.

Сервисов своих и штатных (формульные символы) нет. Каждый советник работает только со своими ордерами (символ+набор мэджиков).


Здесь видно количество открытых позиций/ордеров и количество сделок/ордеров в истории.

Форум по трейдингу, автоматическим торговым системам и тестированию торговых стратегий

Синхронный OrderSend сообщает об успешном выполнении быстрее, чем пинг до торгового сервера

fxsaber, 2020.09.29 08:30

2020.09.29 01:24:57.029  (EURSEK,M1)    ::PositionsTotal() = 62
2020.09.29 01:24:57.029  (EURSEK,M1)    ::OrdersTotal() = 74
2020.09.29 01:24:57.029  (EURSEK,M1)    ::HistorySelect(0,INT_MAX) = true
2020.09.29 01:24:57.029  (EURSEK,M1)    ::HistoryDealsTotal() = 18084
2020.09.29 01:24:57.029  (EURSEK,M1)    ::HistoryOrdersTotal() = 24009

3. Делается ли модификация одних и тех ордеров из разных экспертов/терминалов?

Нет. Один Терминал. С каждым ордером может работать только один советник из этого же Терминала.

4. Посмотрите и напишите к какой точке доступа вы были подключены на момент 2020.09.29 01:20:48. Это можно найти в логах:

2020.09.28 21:36:57.503 Network '': authorized on RannForex-Server through as.eu 5 (ping: 47.79 ms, build 2615)
2020.09.29 09:26:24.511 Network '': authorized on RannForex-Server through as.eu 6 (ping: 55.19 ms, build 2615)

5. Запустите рескан серверов из терминала (в правом нижнем углу терминала где пишется качество соединения и пинг):

6. Дождитесь результатов рескана (scanning network finished):

Приведите скриншот как выглядят точки доступа после рескана и какие у них пинги:

7. Сделайте еще один рескан (лучше несколько) и убедитесь что значения пингов сильно не скачут.

Интересует какой реально минимальный пинг будет до целевого сервера через вашу точку доступа (ту через которую вы были подключены).

Изменяется в диапазоне 37-44 мс.

8. Можете в личку приложить полный лог терминала за сегодня для разбора.

Приложил.
 
Посмотрел случаи за другие дни. 
2020.09.21              
2020.09.21 22:16:56.366         Alert: OrderSend(1301649) - BUG!
2020.09.21 23:59:18.147         Alert: OrderSend(1301723) - BUG!
2020.09.22              
2020.09.22 00:34:55.918         Alert: OrderSend(1302249) - BUG!
2020.09.23              
2020.09.23 02:09:19.343         Alert: OrderSend(1308491) - BUG!
2020.09.23 22:57:53.519         Alert: OrderSend(1313168) - BUG!
2020.09.24              
2020.09.24 00:19:26.263         Alert: OrderSend(1313211) - BUG!
2020.09.24 00:21:18.232         Alert: OrderSend(1313211) - BUG!
2020.09.24 00:21:19.690         Alert: OrderSend(1313211) - BUG!
2020.09.24 00:21:26.208         Alert: OrderSend(1313214) - BUG!
2020.09.24 00:21:36.630         Alert: OrderSend(1313211) - BUG!
2020.09.24 00:21:42.205         Alert: OrderSend(1313211) - BUG!
2020.09.24 00:22:02.149         Alert: OrderSend(1313211) - BUG!
2020.09.24 03:32:07.900         Alert: OrderSend(1314362) - BUG!
2020.09.29              
2020.09.29 01:20:48.373         Alert: OrderSend(1327441) - BUG!
2020.09.29 01:24:56.959         Alert: OrderSend(1326974) - BUG!
Все, как под копирку:

Форум по трейдингу, автоматическим торговым системам и тестированию торговых стратегий

Синхронный OrderSend сообщает об успешном выполнении быстрее, чем пинг до торгового сервера

fxsaber, 2020.09.29 08:18

Хронологическая расшифровка.

  1. Пинг 42 мс.
  2. Стоит SellLimit = 123.117.
  3. Приходит тик, у которого bid = 123.118. SellLimit, скорее всего, акцептировался в этот момент на торговом сервере, но не исполнился - реджект. К сожалению, такие вещи в Терминале не отражаются.
  4. Шлется торговый приказ (синхронный OrderSend) на модификацию, чтобы SellLimit сдвинулся на текущую bid-цену - 123.118.
  5. Через 33 мс OrderSend сообщает, что все отлично и модификация удалась. При этом в ответе Result.price = 123.117 - старая цена до модификации.
  6. Через 14 мс (33249 раз проверялось соответствие) в Терминал физически (про пинг не забываем) приходят данные, что у ордера, действительно, цена модифицировалась на 123.118.
Пункт 5 показывает сразу ошибку - Result.price не соответствует Request.price при удачной OrderSend. Причина бага, скорее всего, в пункте 3.
Пинг в теме упомянул только для того, чтобы подчеркнуть наличие проблемы. Дело точно не в нем, а в ситуациях, которые выделил выше: пункт 5 является следствием пункта 3.
 
fxsaber:

С одного Терминала.

У вас 17 роботов модифицируют одни и те же тикеты. Не важно почему, но несколько тикетов оказываются под модификацией с разных роботов одновременно.

Хотя роботы вызывали сихронные версии функций, на самом деле все торговые операции асинхронные.


Два робота послали модификацию одного тикета (start_time1 и start_time2), первый из них асинхронно отработался и вернулся на терминал (end_time1), второй скорее все пропущен или тоже отработался. Терминал, так как было два запроса одного тикета, зарегистрировал его начальный тайминг по второму запросу (start_time2 и end_time1 вмест о start_time1 и end_time1).

В результате стартовое время было взято от второго запроса, а не от первого. Итогом дельта получилась меньше пинга.


Время исполнения операции пишет терминал сам, не зная какой робот его послал. Не надо модифицировать из разных роботов чужие ордеры, тем более в стресс-режиме прямо нарываясь на конфликт.

Ну и код стресс-тестов надо показывать вместе с объяснением "идет одновременная модификация массы ордеров с разных роботов".

12345
Новый комментарий