tslab.log20160808:12:15:00.56[37]DEBUG:Агент 'itsi-41':271523588:[ITINVEST]:Заявка 271523588 на продажу 12 лотов SiU6 по цене 65392 принята. Команда выполнена за 873 мс.
tslab.log20160808:12:15:00.56[37]INFO :200:Info:TradeScript:(Script:itsi-41):Агент 'itsi-41':271523588:[ITINVEST]:Заявка 271523588 на продажу 12 лотов SiU6 по цене 65392 принята. Команда выполнена за 873 мс.
tslab.log20160808:12:15:00.56[37]DEBUG:Агент 'itsi-41':271523588:[ITINVEST]:Заявка 271523588 исполнена. Продано 12 лотов SiU6 . Остаток 0 лота(ов).
tslab.log20160808:12:15:00.56[37]INFO :204:Info:TradeScript:(Script:itsi-41):Агент 'itsi-41':271523588:[ITINVEST]:Заявка 271523588 исполнена. Продано 12 лотов SiU6 . Остаток 0 лота(ов).

Отсутствие второй и третьей записи, как правило обозначают что у нас некие проблемы. То ли заявка не исполнилась, то ли одно из двух. Бывало, это споровождалось 'истекло время ожидания' и разъехавшейся позицией. За сегодня, три сделки из трех были выполнены, сообщение об исполнении заявки не пришло (про истечение времени ожидания тоже ни слова), при этом агенты корректно показывают количество позиций (т.е. виртуальная позиция не разъехалась с реальной) в связи с чем у меня возникла мысль, что наверное имеет смысл цепляться за что-то другое. Например свежак для заявки нумбер 271622251:

15:44:59.35[9]DEBUG:ITINVEST:1:BP2334-RF-01:DS:itinvest:A=True:B=False:SiU6:RTS_FUT:New order starting for id=271622251 buy=True price=66029 quantity=12 cnt=625
15:44:59.35[9]DEBUG:NewOrder:New order for po id=271622251 price=66029 cnt=625
15:44:59.54[MQ<OrderInfo>]DEBUG:[itinvest] Transaction is found for order 28154017942. TransId=1378115638. Comment=271622251#1#L#itsi-41.CloseShort$Close$271523588
15:44:59.54[MQ<OrderInfo>]DEBUG:[itinvest] Update order 28154017942:0:Forwarding:Limit:08/09/2016 15:45:00:66029:12:12 comment='271622251#1#L#itsi-41.CloseShort$Close$271523588'
15:44:59.54[MQ<OrderInfo>]DEBUG:New OrderInfo 28154017942(0:1378115638) comment=271622251#1#L#itsi-41.CloseShort$Close$271523588 parsed=True orderid=271622251 status=Forwarding
15:44:59.54[MQ<OrderInfo>]DEBUG:28154017942:itsi-41:PO=271622251:ITINVEST:itinvest:SiU6:08/09/2016 15:45:00:66029:Limit:None->Forwarding:a=False->True,ex=False,12,12:itsi-41.CloseShort$Close$271523588
15:44:59.54[MQ<OrderInfo>]DEBUG:Rtorder 271622251 updates. A:True, E:False, P:66029, OP:66029, Q:12, RQ:12 Date:08/09/2016 15:45:00
15:44:59.54[9]DEBUG:Агент 'itsi-41':271622251:[ITINVEST]:Заявка 271622251 на покупку 12 лотов SiU6 по цене 66029 принята. Команда выполнена за 192 мс.
15:44:59.54[9]INFO :200:Info:TradeScript:(Script:itsi-41):Агент 'itsi-41':271622251:[ITINVEST]:Заявка 271622251 на покупку 12 лотов SiU6 по цене 66029 принята. Команда выполнена за 192 мс.
15:44:59.64[MQ<OrderInfo>]DEBUG:[itinvest] Transaction is found for order 28154017942. TransId=1378115638. Comment=271622251#1#L#itsi-41.CloseShort$Close$271523588
15:44:59.64[MQ<OrderInfo>]DEBUG:[itinvest] Update order 28154017942:22378756525:Executed:Limit:08/09/2016 15:45:00:66029:12:0 comment='271622251#1#L#itsi-41.CloseShort$Close$271523588'
15:44:59.64[MQ<OrderInfo>]DEBUG:[itinvest] Update order 28154017942:22378756525:Executed:Limit:08/09/2016 15:45:00:66029:12:0 comment='271622251#1#L#itsi-41.CloseShort$Close$271523588'
15:44:59.64[MQ<OrderInfo>]DEBUG:New OrderInfo 28154017942(22378756525:1378115638) comment=271622251#1#L#itsi-41.CloseShort$Close$271523588 parsed=True orderid=271622251 status=Executed
15:44:59.64[MQ<OrderInfo>]DEBUG:28154017942:itsi-41:PO=271622251:ITINVEST:itinvest:SiU6:08/09/2016 15:45:00:66029:Limit:Forwarding->Executed:a=True->False,ex=False->True,12,0:itsi-41.CloseShort$Close$271523588

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

15:44:59.35[9]DEBUG:ITINVEST:1:BP2334-RF-01:DS:itinvest:A=True:B=False:SiU6:RTS_FUT:New order starting for id=271622251 buy=True price=66029 quantity=12 cnt=62

и

15:44:59.64[MQ<OrderInfo>]DEBUG:New OrderInfo 28154017942(22378756525:1378115638) comment=271622251#1#L#itsi-41.CloseShort$Close$271523588 parsed=True orderid=271622251 status=Executed