search

erdewit / ib_insync

Python sync/async framework for Interactive Brokers API
BSD 2-Clause "Simplified" License
2.85k stars 774 forks source link

in_sync.wrapper hangs up #126

Closed PaluchowskiMatthew closed 5 years ago

PaluchowskiMatthew commented 5 years ago

I experienced a strange behaviour where ib_insync.wrapper hung up in undefined state without throwing any error nor valuable information in the logs.

ib_insync_hangup_logs.txt

The execution should have been terminated by 16:00 however for undisclosed reason it reported as late as 01:02 on the next day.

It doesn't seem to be a gateway connectivity issue. As it logged normally:

IB_GATEWAY_LOGS.txt

Could you advise on how to proceed with backtracking this issue and debugging it? Any idea what might have caused it? Did you encounter anything like it?

erdewit commented 5 years ago

It seems there are two connects going on at the same time, neither are successful in synchronizing with gateway. You can try with one client and go from there.

akbindal commented 5 years ago

There seems to be a problem with communication between IB gateway and Ib_insync api. The wrapper implemented using ib_insync had a problem in submitting orders, the discrepancy we found is in the logs of IB gateway:

Following are the ib gateway log messages at the time of incident:

2019-01-09 15:57:04.053 [GI] INFO [JTS-EServerSocket-4142] - Successfully ?: true sent request: FixAccountRequest id=AR.151 account=U2657918A. subscricbe=true lw=false 2019-01-09 15:57:17.285 [GI] INFO [JTS-Cleaner-32] - market data wrapper, cleaning maps 2019-01-09 15:58:04.113 [GI] INFO [JTS-CCPPingS124-3096] - Resetting long time mode 2019-01-09 15:58:12.056 [GI] INFO [JTS-DeadlockMonitor-2] - Memory:total=759,296KB free=39,756KB HeapUsage: Max=759,296KB used=719,539KB committed=759,296KB NonHeapUsage: Max=0KB used=128,163KB committed=130,688KB 2019-01-09 15:58:13.058 [GI] INFO [JTS-DeadlockMonitor-2] - CPU:cur=0.01% avg=0.03% 30 min avg=0.17% 5 min avg=0.26% 1 min avg=0.01% GC:called=1015 times CPU used=0.00% Finalizer:cur=0.00% avg=0.00% 30 min avg=0.00% 5 min avg=0.00% 1 min avg=0.00% Threads Count:curr live=54 curr daemon=27

Wrapper tried to send orders immediately after 2019-01-09 15:57:04.053, though couldn't send it and only discrepancy we see in the IB gateway log at 2019-01-09 15:58:04.113 about resetting long time mode. Probably we are not catching this scenario at warning or error level in ib_insync. @erdewit Does this explain why was ib_insync not able to communicate with IB gateway? Is there a way to catch this specific scenario in ib_insync ?