Resampling multiple IB datas causes cerebro to grind to a halt

[shanehull]

This seems to be affected by the following two conditions:

1. Using cerebro.resampldata() to add the data to cerebro.
2. Using 2 or more datas

I've tried to trace it, but I don't have much experience tracing bugs like this where I can't pinpoint an appropriate pdb breakpoint, especially when I don't know the project well.

The full trace I captured using python3 -m trace --trace is here if anyone finds it useful: https://gist.github.com/shed909/09427c02944f5111822c767197d84cf7

And when I keyboard interrupt it:

^CTraceback (most recent call last):
  File "/Users/shane/tstrade/tstrade/main.py", line 446, in <module>
    runstrat()
  File "/Users/shane/tstrade/tstrade/main.py", line 269, in runstrat
    runs = cerebro.run(**cerebrokwargs)
  File "/Users/shane/tstrade/lib/python3.9/site-packages/backtrader/cerebro.py", line 1127, in run
    runstrat = self.runstrategies(iterstrat)
  File "/Users/shane/tstrade/lib/python3.9/site-packages/backtrader/cerebro.py", line 1298, in runstrategies
    self._runnext(runstrats)
  File "/Users/shane/tstrade/lib/python3.9/site-packages/backtrader/cerebro.py", line 1573, in _runnext
    if d.next(datamaster=dmaster, ticks=False):  # retry
  File "/Users/shane/tstrade/lib/python3.9/site-packages/backtrader/feed.py", line 407, in next
    ret = self.load()
  File "/Users/shane/tstrade/lib/python3.9/site-packages/backtrader/feed.py", line 479, in load
    _loadret = self._load()
  File "/Users/shane/tstrade/lib/python3.9/site-packages/backtrader/feeds/ibdata.py", line 573, in _load
    msg = self.qhist.get()
  File "/usr/local/Cellar/python@3.9/3.9.1_6/Frameworks/Python.framework/Versions/3.9/lib/python3.9/queue.py", line 171, in get
    self.not_empty.wait()
  File "/usr/local/Cellar/python@3.9/3.9.1_6/Frameworks/Python.framework/Versions/3.9/lib/python3.9/threading.py", line 312, in wait
    waiter.acquire()
KeyboardInterrupt

I have tested the following with successful results:

• Resampling 1 datas.

And the following with unsuccessful results:

• Using adddata() with many datas - no issues there.
• No (default) kw args (except for the fromdate and todate) when getting/resampling the datas (so when both datas are using the same timeframe and compression, the issue is still present).
• A combination of different args - nothing in terms on timeframe or compression seems to make a difference, so I stopped here.

Here is example of how I'm testing this:

    ibstore = bt.stores.IBStore(**ibstorekwargs)
    # Create getdata and adddata objects 
    getdata = ibstore.getdata
    # resampledata or adddata, we can switch between to test
    # adddata = cerebro.adddata
    adddata = cerebro.resampledata

    # Trade data
    tdata = 'IBAU200-CFD-SMART'

    trade_data = getdata(
            dataname=tdata,
            **tdatakwargs,
            )
    # Add the data to cerebro
    adddata(trade_data,
        name=tdata,
        **tdatarekwargs,
        )

    wdata = ['IBUS500-CFD-SMART']

    for i in range(len(wdata)):
        wdataname = wdata[i]
        # Get the data
        watch_data = getdata(
                dataname=wdataname,
                **wdatakwargs,
                )
        # Add the data to cerebro
        adddata(watch_data,
                name=wdata[i],
                **wdatarekwargs,
                )

The above includes the IB products/datas I used in the Python trace above. I've also tried many others, including the same instruments with the same timeframe and compression. I'm just testing month blocks of daily data at the moment, eg: -fd 2021-06-02 -td 2021-07-02

I'm sure someone can replicate this quite easily, or if anyone has any pointers on how to trace it further, I'd love to have a crack myself.

[shanehull]

It seems if I run a strategy that does absolutely nothing, it's fine.

class DoNothing(bt.Strategy):

    def next(self):
        pass

I'll write some tests that access different line items and report back with the results.

[shanehull]

I've done some tests using the following:

import backtrader as bt
from datetime import datetime

class Test(bt.Strategy):
    def next(self):
        #print(self.position)
        pass

def runstrat():
    fd = datetime(2021, 5, 1)
    td = datetime(2021, 6, 1)
    cerebro = bt.Cerebro()
    cerebro.addstrategy(Test)
    ibstore = bt.stores.IBStore(
        host='127.0.0.1',
        port=4002,
        _debug=True,
        )
    data0 = ibstore.getdata(
            dataname='IBAU200-CFD-SMART',
            timeframe=bt.TimeFrame.Days,
            historical=True,
            fromdate=fd,
            todate=td,
            )
    cerebro.resampledata(data0,
        timeframe=bt.TimeFrame.Days,
        compression=1,
        )

    data1 = ibstore.getdata(
            dataname='IBUS500-CFD-SMART',
            timeframe=bt.TimeFrame.Days,
            historical=True,
            fromdate=fd,
            todate=td,
            )
    cerebro.resampledata(data1,
            timeframe=bt.TimeFrame.Days,
            compression=1,
            )
    cerebro.run()

if __name__ == '__main__':
    runstrat()

Changing the fromdate and todate seems change the outcome, for example the following dates work:

    fd = datetime(2021, 5, 1)
    td = datetime(2021, 6, 2)

So it's clearly something with the way ibdata.py is requesting or handling the data from IB.

[neilsmurphy]

I'm unable to recreate this problem. I've copied your code above and I'm receiving results no problem. The only change is I used these currencies since I don't have your subscription.

['GBP.USD-CASH-IDEALPRO', 'EUR.USD-CASH-IDEALPRO']

Are you still having an issue with this?

[shanehull]

@neilsmurphy using those currencies works fine for me.

Still an issue with IBAU200-CFD-SMART and IBUS500-CFD-SMART.

I will test some more tonight.

[happydasch]

I did encounter this issue. This happens when tws does not send an date that starts with "finished-at-..." when requesting historical data. it just loops and waits for the data to come in.

This happened for me using stocks (SRNE) with granularity of 1 Day. When the todate is ommitted or date equals now (my explanation for this was, that the last period is not finished yet). I did not investigate the issue that much since i use yahoo for now to get the data.

[neilsmurphy]

@shed909 Any further luck with this?

[shanehull]

@neilsmurphy I've kind of put this on the back burner, but I just did a quick test and the last bar that I see in the debug output (before it stops) contains: 'date=finished-20210401' I guess I should attempt to find out what the proceeding bars date looked like.

<historicalData reqId=16777219, date=20210528, open=4212.54, high=4220.04, low=4204.0, close=4206.36, volume=-1, count=-1, WAP=-1.0, hasGaps=False>
<historicalData reqId=16777219, date=finished-20210401  09:00:00-20210601  09:00:00, open=-1, high=-1, low=-1, close=-1, volume=-1, count=-1, WAP=-1, hasGaps=False>

@happydasch's theory is looking likely.

I have a few things to finish before I dig any further.