Skip to content
This repository has been archived by the owner on Mar 14, 2024. It is now read-only.

IB().connect() always fails the first time upon a fresh IBG/TWS start #303

Closed
reservoirinvest opened this issue Sep 29, 2020 · 22 comments
Closed

Comments

@reservoirinvest
Copy link

Noticed that IB().connect() always fails with asyncio.exceptions.TimeoutError the very first time it is called upon a fresh IBG/TWS start / re-start. The error occurs with and without providing timeout in connect.

The second time on it works without an issue.

Error traceback

Traceback (most recent call last):
  File "c:\Users\User\Documents\Business\Projects\learn\ib\main.py", line 142, in <module>
    all_base(MARKET, ip)
  File "c:\Users\User\Documents\Business\Projects\learn\ib\base.py", line 555, in all_base
    with IB().connect(HOST, PORT, CID, timeout=2) as ib:
  File "C:\Users\User\AppData\Local\Programs\Python\Python38-32\lib\site-packages\ib_insync\ib.py", line 260, in connect
    return self._run(self.connectAsync(
  File "C:\Users\User\AppData\Local\Programs\Python\Python38-32\lib\site-packages\ib_insync\ib.py", line 292, in _run
    return util.run(*awaitables, timeout=self.RequestTimeout)
  File "C:\Users\User\AppData\Local\Programs\Python\Python38-32\lib\site-packages\ib_insync\util.py", line 311, in run
    result = loop.run_until_complete(task)
  File "C:\Users\User\AppData\Local\Programs\Python\Python38-32\lib\asyncio\base_events.py", line 612, in run_until_complete
    return future.result()
  File "C:\Users\User\AppData\Local\Programs\Python\Python38-32\lib\site-packages\ib_insync\ib.py", line 1619, in connectAsync
    await asyncio.wait_for(connect(), timeout or None)
  File "C:\Users\User\AppData\Local\Programs\Python\Python38-32\lib\asyncio\tasks.py", line 490, in wait_for
    raise exceptions.TimeoutError()
asyncio.exceptions.TimeoutError

Probable causes:

Investigating the traceback:

  1. It looks like it is caused by _run in ib.py, which somehow misses the *awaitables in def run of util.py that gets into run_until_complete of base_events.py and falls through to line:612 (unreachable by pylance) to return future.result()

  2. ib.py seems to take this result forward to tasks.py to raise the exceptions.TimeoutError(). There is a comment in tasks.py pointing to a python bug, that seems to have been abandoned in May 2018. However, on August 27, there seems to have been some changes made in the code base to address fut.cancel.

Queries

  • Does this happen to others too?
  • Is there something that can be done to address this in ib_insync?
@briandpassa
Copy link

Starting today, I have a similar issue, in my case, I cannot open a second connection.

@reservoirinvest
Copy link
Author

If it is of any help, here is:

A sample code:

import asyncio

from ib_insync import *

HOST, PORT, CID = ('127.0.0.1', 1300, 0)

cts = [Stock(symbol='INTC', exchange='SMART', currency='USD'),
       Stock(symbol='CSCO', exchange='SMART', currency='USD')]


async def ohlcs(ib: IB, c, DURATION: int = 365, OHLC_DELAY: int = 0):
    ohlc = await ib.reqHistoricalDataAsync(
        contract=c,
        endDateTime="",
        durationStr=str(DURATION) + ' D',
        barSizeSetting="1 day",
        whatToShow="Trades",
        useRTH=True)

    await asyncio.sleep(OHLC_DELAY)

    df = util.df(ohlc)
    try:
        df.insert(0, 'symbol', c.symbol)
    except AttributeError:
        df = None

    return df

with IB().connect(HOST, PORT, CID) as ib:
    c = ib.qualifyContracts(*cts)[0]

with IB().connect(HOST, PORT, CID) as ib:
    ohlcs = ib.run(ohlcs(ib, c))

print(ohlcs)

Traceback from first time run:

...

  File "C:\Users\User\AppData\Local\Programs\Python\Python38-32\lib\asyncio\base_events.py", line 612, in run_until_complete
    return future.result()
  File "C:\Users\User\AppData\Local\Programs\Python\Python38-32\lib\site-packages\ib_insync\ib.py", line 1619, in connectAsync
    await asyncio.wait_for(connect(), timeout or None)
  File "C:\Users\User\AppData\Local\Programs\Python\Python38-32\lib\asyncio\tasks.py", line 490, in wait_for
    raise exceptions.TimeoutError()
asyncio.exceptions.TimeoutError

Successful outcome from later runs (after the first time error):

PS C:\Users\User\Documents\Business\Projects\learn\ib> & C:/Users/User/.virtualenvs/asyncib-k9pH4ETO/Scripts/Activate.ps1
(asyncib) PS C:\Users\User\Documents\Business\Projects\learn\ib> python -u "c:\Users\User\Documents\Business\Projects\learn\ib\test.py"
    symbol        date   open   high    low  close  volume  average  barCount
0     INTC  2019-04-23  58.89  58.98  58.50  58.78  126115  58.7775     60628
1     INTC  2019-04-24  58.57  59.29  58.14  58.72  135763  58.8800     59335
2     INTC  2019-04-25  58.26  58.38  57.23  57.61  191361  57.6670     99770
3     INTC  2019-04-26  52.75  53.09  51.52  52.43  621017  52.0675    266573
   ...

@drusakov778
Copy link

some (potentially) related discussion is here: https://groups.io/g/insync/topic/77079866
need to check that this issue still appears after a fix in commit 74ca552

@reservoirinvest
Copy link
Author

Commit 74ca552 now gives an additional peer closed connection error:

Peer closed connection
clientId 0 already in use?
API connection failed: TimeoutError()
Traceback (most recent call last):
  File "c:\Users\User\Documents\Business\Projects\learn\ib\test.py", line 33, in <module>
    with IB().connect(HOST, PORT, CID) as ib:
...

@achtsisn
Copy link

achtsisn commented Oct 2, 2020

I now don4't seem to be able to connect at all anymore, even with the abovementioned commit. I get the following error:

Traceback (most recent call last):
  File "G:/Python/eqdata/brokers/ibrk.py", line 31, in connect
    self.ib.connect(self.host, self.port, self.cId, readonly=self.readOnly, timeout=10)
  File "C:\Users\nicoa\AppData\Local\Programs\Python\Python37\lib\site-packages\ib_insync\ib.py", line 272, in connect
    host, port, clientId, timeout, readonly, account))
  File "C:\Users\nicoa\AppData\Local\Programs\Python\Python37\lib\site-packages\ib_insync\ib.py", line 310, in _run
    return util.run(*awaitables, timeout=self.RequestTimeout)
  File "C:\Users\nicoa\AppData\Local\Programs\Python\Python37\lib\site-packages\ib_insync\util.py", line 317, in run
    result = loop.run_until_complete(task)
  File "C:\Users\nicoa\AppData\Local\Programs\Python\Python37\lib\asyncio\base_events.py", line 584, in run_until_complete
    return future.result()
  File "C:\Users\nicoa\AppData\Local\Programs\Python\Python37\lib\site-packages\ib_insync\ib.py", line 1659, in connectAsync
    timeout or None)
  File "C:\Users\nicoa\AppData\Local\Programs\Python\Python37\lib\asyncio\tasks.py", line 423, in wait_for
    raise futures.TimeoutError()
concurrent.futures._base.TimeoutError
2020-10-02 17:10:59 -- ERROR    -- asyncio -- _GatheringFuture exception was never retrieved
future: <_GatheringFuture finished exception=CancelledError()>
concurrent.futures._base.CancelledError

The snippet:

from ib_insync import *

ib = IB()  
ib.connect(self.host, self.port, self.cId, readonly=self.readOnly, timeout=10)

Anyone else facing this issue as well?

@nahall
Copy link

nahall commented Oct 5, 2020

I'm having this same issue. Running ib_insync 0.9.62.

@nahall
Copy link

nahall commented Oct 6, 2020

This was failing for me the past few days even running the basic ib_insync examples. I checked and TWS had updated to 980.4l and I think that was when the problem started. I downgraded TWS to 978.2g and now everything works properly again. So it would seem that the latest version of TWS has changed something that broke how ib_insync connects.

@drusakov778
Copy link

drusakov778 commented Oct 7, 2020

Hi all,

I have not touched my IB gateway installation for months, and it appears to be version 972

$ ls ~/Jts/ibgateway/       
972/

the @reservoirinvest sample code from 5 days ago runs fine. So it does appear to be related to latest IB TWS/GW, which potentially may require some workaround/adaptation from ib_insync side

systems: IB Gateway on AWS Ubuntu, python client connecting from mac os

@erdewit
Copy link
Owner

erdewit commented Oct 7, 2020

I've tried the latest version of TWS and IB Gateway (980.4l) and can't reproduce the connect issue (this is on Linux).

If anyone with connect problems can post a debug log, that would show in more detail what happens. Before posting don't forget to remove any sensitive information!

@blazespinnaker
Copy link

blazespinnaker commented Oct 14, 2020

I am using latest as well (980.4n)

I see a hang on this call:

trades = ib.reqCompletedOrders(True)

Also, it always says "reqCompletedOrders timed out" on each startup.

@blazespinnaker
Copy link

blazespinnaker commented Oct 15, 2020

Hmm seeing the same issue now. Peer Closed connection .. File "/usr/lib/python3.8/asyncio/tasks.py", line 490, in wait_for raise exceptions.TimeoutError()

I get clientId 10 is alreay in use. Could be related to how the connection was not properly cleaned up.

@reservoirinvest
Copy link
Author

reservoirinvest commented Oct 16, 2020

I could resolve the issue by adding the following hack:

    ...

    return df

with IB().connect(HOST, PORT, CID) as ib:
    c = ib.qualifyContracts(*cts)[0]

    # --- HACK TO PREVENT FIRST-TIME DISCONNECT ---
    ib.disconnect()
    IB().waitOnUpdate(timeout=0.1)
    ## --------------- END HACK--------

with IB().connect(HOST, PORT, CID) as ib:
    ohlcs = ib.run(ohlcs(ib, c))

   ...

Additional Notes

  1. @erdewit - am running in Windows 10. Apologies, I don't know how to generate and send the debug.log.
  2. @blazespinnaker - I see the same reqCompletedOrders timed out message when processing a large number of ib.qualifyContracts(*cts) before proceeding to the next ohlcs step. However, the message is not being reflected in this sample code.
  3. The solution was inspired by @radekwlsk hack for issue #76
  4. The hack is needed only after the first ib.xx (or) ib.run() command in the program. Subsequent calls to ib is not affected.

@blazespinnaker
Copy link

Sadly there is a risk to using this library unless server side changes run regression tests with it. I will say the code is quite fantastic though. Maybe we could convince IKBR to get some consulting time from @erdewit .. that would be very very helpful for all of us python devs.

@jkleckner
Copy link
Contributor

jkleckner commented Oct 19, 2020

Probing versions on Windows 8.1, the error does not occur in TWS v980.4k but does occur in v980.4l and v980.4n.

The error logs are completely unremarkable:

ibdebug.txt

@blazespinnaker
Copy link

blazespinnaker commented Oct 20, 2020

Part of the problem here might be the nested way that asyncio is being used which contradicts guidance from the asyncio team. The custom run/sleep routines are non standard. So definitely is the patchAsyncio call in the code. See here - erdewit/nest_asyncio#36

The asyncio team is deprecating the loop parameter in many of the API calls, so I can imagine the situation will only get worse as further assumptions are made in the code.

What version of python/asycnio is everyone using? There have been some changes recently (3.8 and 3.9). I am using python 3.8.5 that has been certified with focal ubuntu.

I've been using the base TWS API + gevent with monkey patch, and so far so good. Though I do have some concerns about the magic of monkey patch.

@drusakov778
Copy link

re nested asyncio - I've been using ib_insync for the last half a year and always without patching the asyncio, i.e. by calling the ib....Async() function variants, so I doubt the connection problems described about amount to patching the asyncio. The 'patch' itself is a mere technicality allowing unexperienced users to run pseudo-sync functions and having async underneath.

Having said that it will be interesting to re-create and confirm/disprove the bug above in pure async setup.

@erdewit
Copy link
Owner

erdewit commented Oct 20, 2020

@jkleckner thanks for the debug log. What is remarkable about it is that IBKR is not sending back the accountDownloadEnd marker anymore. There should be a

<<< 54,1,...

line but there isn't. This leaves the reqAccountUpdates request hanging, which then times out. On the insync user group it is mentioned that specifying an account, as in ib.connect(account=XXXXXXX), fixes the issues. Could it be that the issue only manifests for advisor accounts?

What I can do is to not automatically request account updates when there are multiple accounts.

@drusakov778 that's 100% correct, even the regular ib.connect() method does not use nesting.

@blazespinnaker
Copy link

Hmm, perhaps, though the util run / sleep do seem a bit risky. fwiw however, the connect(account=) fixed the issue for me.

@jkleckner
Copy link
Contributor

jkleckner commented Oct 21, 2020

It is clearly introduced from 480.4k to 480.4l as it is the only thing changed so it seems likely that TWS is the cause of the problem. And reverting from l to k and back reliably demonstrates the problem.

Strangely, the account= method does work but only for 1 of 5 possible accounts and it is not completely reliable.

@erdewit If you have a patch I should test, I would be happy to try it.

@erdewit
Copy link
Owner

erdewit commented Oct 25, 2020

@jkleckner wrote:

Strangely, the account= method does work but only for 1 of 5 possible accounts and it is not completely reliable.

That's interesting, I would have expected all the U* accounts to work. It means the regression in TWS is bigger than I thought.

I will patch it in a way that bypasses all the issues.

erdewit added a commit that referenced this issue Oct 25, 2020
@jkleckner
Copy link
Contributor

jkleckner commented Oct 26, 2020

FYI, version 981.2b also fails with the original code.

It works with the new master branch!

Thanks!

@erdewit
Copy link
Owner

erdewit commented Oct 26, 2020

Thanks for confirming Jim.

This is now released as v0.9.63.

@erdewit erdewit closed this as completed Oct 26, 2020
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
None yet
Projects
None yet
Development

No branches or pull requests

8 participants