Unexpected additional orders created/rejected



  • Hi All,

    Trying to port a simple volatility based strategy from Excel to Backtrader and I ran into some very unexpected behaviors regarding order creation/execution. Specifically, sometimes the orders are created twice in a given day with the first one executed and the second order cancelled/rejected?

    Here's the log output:

    2006-07-18, VIX: 17.74, VIX_VXV:1.03 SPY Order Canceled/Margin/Rejected, 96 shares
    Ref: 17069
    OrdType: 0
    OrdType: Buy
    Status: 7
    Status: Margin
    Size: 96
    Price: 98.75
    Price Limit: None
    TrailAmount: None
    TrailPercent: None
    ExecType: 0
    ExecType: Market
    CommInfo: None
    End of Session: 732509.9999999999
    Info: AutoOrderedDict()
    Broker: None
    Alive: False
    2007-05-17, VIX: 13.51, VIX_VXV:0.95 SPY SELL EXECUTED, -1 shares at 122.89
    2007-05-17, VIX: 13.51, VIX_VXV:0.95 SPY SELL EXECUTED, -1 shares at 122.89
    

    Here's the code

    
    class vix_ratio(bt.Strategy):
    
        def log(self, txt):
            print("%s, VIX: %.2f, VIX_VXV:%.2f %s" % (self.vix.datetime.date(0).isoformat(), self.vix.close[0], self.vix_ratio, txt))       
                  
        def __init__(self):
            self.vix_ratio = 0
            
            self.spy = self.data0
            self.agg = self.data1
            self.vix = self.data2
            self.vxv = self.data3
            return None
        
        def notify_order(self, order):
            if order.status in [order.Submitted, order.Accepted]:
                # Buy/Sell order submitted/accepted to/by broker - Nothing to do
                return
            
            # Check if an order has been completed
            # Attention: broker could reject order if not enougth cash
            if order.status in [order.Completed]:
                if order.isbuy():
                    self.log(order.data._name + ' BUY EXECUTED, %.0f shares at $%.2f' % (order.size, order.executed.price))
                elif order.issell():
                    self.log(order.data._name + ' SELL EXECUTED, %.0f shares at %.2f' % (order.size, order.executed.price))
    
                self.bar_executed = len(self)
    
            elif order.status in [order.Canceled, order.Margin, order.Rejected]:
                self.log(order.data._name + ' Order Canceled/Margin/Rejected, %.0f shares' % (order.size))#, order.price))
                print(order)
            # Write down: no pending order
            self.order = None
            
        def next(self):
            #print(self.sma1[0], self.sma2[0])
            self.vix_ratio = self.vix.close[0]/self.vxv.close[0]
            
            if self.vix_ratio > 1 and self.vix.close[0] > 20:
                self.order = self.order_target_percent(data=self.spy, target=0)
                self.order = self.order_target_percent(data=self.agg, target=0.99)
            else: 
                self.order = self.order_target_percent(data=self.agg, target=0)
                self.order = self.order_target_percent(data=self.spy, target=0.99)
                    
    def run_strat():
        start = datetime(2006,7,17)
        end = datetime(2017,4,21)   
        
        spy = btfeeds.YahooFinanceData(dataname="SPY", fromdate=start, todate=end)
        agg = btfeeds.YahooFinanceData(dataname="AGG", fromdate=start, todate=end)
        vix = bt.feeds.PandasData(dataname=web.DataReader("^VIX", 'yahoo', start, end), name='VIX')
        vxv = bt.feeds.PandasData(dataname=web.DataReader("^VXV", 'yahoo', start, end), name='VXV')
        
        cerebro = bt.Cerebro(runonce=False)
        
        cerebro.adddata(spy, name="SPY")
        cerebro.adddata(agg, name="AGG")
        cerebro.adddata(vix, name="VIX")
        cerebro.adddata(vxv, name="VXV")
        
        cerebro.addstrategy(vix_ratio)
        cerebro.broker.setcash(10000.0)
        cerebro.addanalyzer(bt.analyzers.PyFolio, _name='pyfolio')
        
        results = cerebro.run()
    

  • administrators

    Since you have 4 assets, the most probable reasons for the multiple order generation is that those assets are not aligned in time. That means that next is called and the assets which have not progressed in time, don't move.

    Since you have no sentinel in the form of checking the length of the data feed or if an order is pending on that asset, or if you are in the market with that asset, you issue the order again because the conditions are met.

    The rejection is probably due to the lack of cash.

    In any case it would also seem the log is really odd, because 2006-07-18 comes before 2007-05-17. It might be the web reader gives you the yahoo data in the wrong order.



  • @backtrader
    Okay. I changed the code to using the new cheat_on_open param and loaded the data using backtrader internal btfeeds. With the new cheat_on_open combined with order_target_percent, the model shouldn't be out of cash. And w/ import backtrader.feeds as btfeeds, it should take care of data alignment problem. I've also made sure I place order_target_percent(target = 0) ahead of order_target_percent(target = 1) so I never buy before I sell.

    With these above feature combined, I shouldn't be getting get order rejected/margin/etc errors. But I am still getting those, big time, throwing the whole backtest result off.

    But I am still getting a whole lot of errors on trade log errors. Here are the first several lines:

    2006-07-18, VIX: 17.74, VIX_VXV:1.03 SPY BUY EXECUTED, 100 shares at $99.04
    2007-07-26, VIX: 20.74, VIX_VXV:1.09 AGG Order Canceled/Margin/Rejected, 171 shares
    2007-07-26, VIX: 20.74, VIX_VXV:1.09 SPY SELL EXECUTED, -100 shares at 122.45
    2007-09-18, VIX: 20.35, VIX_VXV:0.99 SPY BUY EXECUTED, 99 shares at $121.34
    2007-10-22, VIX: 21.64, VIX_VXV:1.01 SPY SELL EXECUTED, -99 shares at 121.94
    2007-10-22, VIX: 21.64, VIX_VXV:1.01 AGG Order Canceled/Margin/Rejected, 166 shares
    2007-10-23, VIX: 20.41, VIX_VXV:0.97 SPY BUY EXECUTED, 99 shares at $124.07
    2007-11-01, VIX: 23.21, VIX_VXV:1.03 AGG Order Canceled/Margin/Rejected, 168 shares
    2007-11-01, VIX: 23.21, VIX_VXV:1.03 SPY SELL EXECUTED, -99 shares at 125.57
    2007-11-02, VIX: 23.01, VIX_VXV:0.99 SPY BUY EXECUTED, 101 shares at $124.13
    2007-11-05, VIX: 24.31, VIX_VXV:1.01 AGG Order Canceled/Margin/Rejected, 167 shares
    2007-11-05, VIX: 24.31, VIX_VXV:1.01 SPY SELL EXECUTED, -101 shares at 122.58
    2007-11-06, VIX: 21.39, VIX_VXV:0.96 SPY BUY EXECUTED, 99 shares at $123.58
    2007-11-07, VIX: 26.49, VIX_VXV:1.05 AGG Order Canceled/Margin/Rejected, 166 shares
    

    The full code is as follows, run on Jupyter Notebook.

    import backtrader as bt
    import backtrader.feeds as btfeeds
    from datetime import datetime
    import pandas_datareader.data as web
    import matplotlib.pylab as pylab
    pylab.rcParams['figure.figsize'] = 20, 10  # that's default image size for this interactive session
    pylab.rcParams["font.size"] = "20"
    
    class vix_ratio(bt.Strategy):
    
        def log(self, txt):
            print("%s, VIX: %.2f, VIX_VXV:%.2f %s" % (self.vix.datetime.date(0).isoformat(), self.vix.close[0], self.vix_ratio, txt))       
                  
        def __init__(self):
            self.spy = self.data0
            self.agg = self.data1
            self.vix = self.data2
            self.vxv = self.data3
            self.vix_ratio = 0
            self.flag = True
        
        def notify_order(self, order):
            if order.status in [order.Submitted, order.Accepted]:
                # Buy/Sell order submitted/accepted to/by broker - Nothing to do
                return
            
            # Check if an order has been completed
            # Attention: broker could reject order if not enougth cash
            if order.status in [order.Completed]:
                if order.isbuy():
                    self.log(order.data._name + ' BUY EXECUTED, %.0f shares at $%.2f' % (order.size, order.executed.price))
                elif order.issell():
                    self.log(order.data._name + ' SELL EXECUTED, %.0f shares at %.2f' % (order.size, order.executed.price))
    
                self.bar_executed = len(self)
    
            elif order.status in [order.Canceled, order.Margin, order.Rejected]:
                self.log(order.data._name + ' Order Canceled/Margin/Rejected, %.0f shares' % (order.size))
            # Write down: no pending order
            self.order = None
            
        def next_open(self): # Using cheat-on-open
            self.vix_ratio = self.vix.close[0]/self.vxv.close[0]
            
            if (self.vix_ratio <= 1 or self.vix.close[0] <= 20) and self.flag:
                self.flag = False
                self.order = self.order_target_percent(data=self.agg, target=0)
                self.order = self.order_target_percent(data=self.spy, target=1)
            elif (self.vix_ratio > 1 and self.vix.close[0] > 20) and not self.flag:
                self.flag = True
                self.order = self.order_target_percent(data=self.spy, target=0)
                self.order = self.order_target_percent(data=self.agg, target=1)
                
    def run_strat():
        start = datetime(2006,7,17)
        end = datetime(2017,4,21)   
        
        spy = btfeeds.YahooFinanceData(dataname="SPY", fromdate=start, todate=end)
        agg = btfeeds.YahooFinanceData(dataname="AGG", fromdate=start, todate=end)
        vix = btfeeds.YahooFinanceData(dataname="^VIX", fromdate=start, todate=end)
        vxv = btfeeds.YahooFinanceData(dataname="^VXV", fromdate=start, todate=end)
        
        cerebro = bt.Cerebro(cheat_on_open=True)
        
        cerebro.adddata(spy, name="SPY")
        cerebro.adddata(agg, name="AGG")
        cerebro.adddata(vix, name="VIX")
        cerebro.adddata(vxv, name="VXV")
        
        cerebro.addstrategy(vix_ratio)
        cerebro.broker.setcash(10000.0)
        
        results = cerebro.run()        
        cerebro.plot()
    
    if __name__ == '__main__':
        run_strat()
    

  • administrators

    You are still using the close price for the calculation of the stake, which may be significantly different of the open. If you don't specifically specify the opening price it will not be used for the calculation. The calculation of the percent doesn't know you are cheating and are able to act before the broker.



  • Here's the log if I print out the orders when they got canceled/margin/rejected.

    On 2006-07-18, it bought 100 shares of SPY at $99.04, for $9904, with $96 cash left.

    On 2007-07-26, it sold 100 shares of SPY at $122.45, account balance should be $12,245 + prior cash of $96, and broker.getcash() reports $12,341. So selling w/ order_target_percent had no problem to sell at open with cheat_on_open.

    But then the problem came. It turns around and buys 171 shares of AGG for $72.45 for $12,388.95, which is greater than $12,341 account value and got rejected. Thus the rejection. Which means, order_target_percent with cheat_on_open does not work for allocation trades.

    Two bugs here:

    1. Since the notify_order logged buying AGG before selling SPY, It could be that if we used order_target_percent sizer, the trade ordering will be mixed up and backtrader ends up placing buy before sell.

    2. On the other hand, the order_target_percent sizer also did not size AGG properly if we look at the account values alone. It seemed to be using prior close of SPY ($123.61) to calculate account value. Previous close is $123.61 x 100 shares + $91 cash = $12452 account value > $12388.95, which can buy at max 171 share of AGG at $72.45. But in reality, backtrader order_target_percent sizer with cheat_on_open needs to be and should only be calculating account size using Open only. Never previous close.

    2006-07-18, VIX: 17.74, VIX_VXV:1.03 SPY BUY EXECUTED, 100 shares at $99.04
    2007-07-26, VIX: 20.74, VIX_VXV:1.09 AGG Order Canceled/Margin/Rejected, 171 shares
    12341.0
    123.61
    Ref: 13711
    OrdType: 0
    OrdType: Buy
    Status: 7
    Status: Margin
    Size: 171
    Price: 72.47
    Price Limit: None
    TrailAmount: None
    TrailPercent: None
    ExecType: 0
    ExecType: Market
    CommInfo: None
    End of Session: 732883.9999999999
    Info: AutoOrderedDict()
    Broker: None
    Alive: False
    2007-07-26, VIX: 20.74, VIX_VXV:1.09 SPY SELL EXECUTED, -100 shares at 122.45
    2007-09-18, VIX: 20.35, VIX_VXV:0.99 SPY BUY EXECUTED, 99 shares at $121.34
    2007-10-22, VIX: 21.64, VIX_VXV:1.01 SPY SELL EXECUTED, -99 shares at 121.94
    2007-10-22, VIX: 21.64, VIX_VXV:1.01 AGG Order Canceled/Margin/Rejected, 166 shares
    12400.4
    Ref: 13714
    OrdType: 0
    OrdType: Buy
    Status: 7
    Status: Margin
    Size: 166
    Price: 74.8
    Price Limit: None
    TrailAmount: None
    TrailPercent: None
    ExecType: 0
    ExecType: Market
    CommInfo: None
    End of Session: 732971.9999999999
    Info: AutoOrderedDict()
    Broker: None
    Alive: False
    2007-10-23, VIX: 20.41, VIX_VXV:0.97 SPY BUY EXECUTED, 99 shares at $124.07
    2007-11-01, VIX: 23.21, VIX_VXV:1.03 AGG Order Canceled/Margin/Rejected, 168 shares
    12548.9
    Ref: 13717
    OrdType: 0
    OrdType: Buy
    Status: 7
    Status: Margin
    Size: 168
    Price: 74.92
    Price Limit: None
    TrailAmount: None
    TrailPercent: None
    ExecType: 0
    ExecType: Market
    CommInfo: None
    End of Session: 732981.9999999999
    Info: AutoOrderedDict()
    Broker: None
    Alive: False
    2007-11-01, VIX: 23.21, VIX_VXV:1.03 SPY SELL EXECUTED, -99 shares at 125.57
    2007-11-02, VIX: 23.01, VIX_VXV:0.99 SPY BUY EXECUTED, 101 shares at $124.13
    2007-11-05, VIX: 24.31, VIX_VXV:1.01 AGG Order Canceled/Margin/Rejected, 167 shares
    12392.35
    Ref: 13720
    OrdType: 0
    OrdType: Buy
    Status: 7
    Status: Margin
    Size: 167
    Price: 74.93
    Price Limit: None
    TrailAmount: None
    TrailPercent: None
    ExecType: 0
    ExecType: Market
    CommInfo: None
    End of Session: 732985.9999999999
    Info: AutoOrderedDict()
    Broker: None
    Alive: False
    2007-11-05, VIX: 24.31, VIX_VXV:1.01 SPY SELL EXECUTED, -101 shares at 122.58
    2007-11-06, VIX: 21.39, VIX_VXV:0.96 SPY BUY EXECUTED, 99 shares at $123.58
    2007-11-07, VIX: 26.49, VIX_VXV:1.05 AGG Order Canceled/Margin/Rejected, 166 shares
    12358.69
    Ref: 13723
    OrdType: 0
    OrdType: Buy
    Status: 7
    Status: Margin
    Size: 166
    Price: 74.85
    Price Limit: None
    TrailAmount: None
    TrailPercent: None
    ExecType: 0
    ExecType: Market
    CommInfo: None
    End of Session: 732987.9999999999
    Info: AutoOrderedDict()
    Broker: None
    Alive: False
    2007-11-07, VIX: 26.49, VIX_VXV:1.05 SPY SELL EXECUTED, -99 shares at 123.24
    2007-11-13, VIX: 24.10, VIX_VXV:0.98 SPY BUY EXECUTED, 101 shares at $119.08
    2007-11-14, VIX: 25.94, VIX_VXV:1.01 SPY SELL EXECUTED, -101 shares at 122.24
    

    Here's the code that produces these two bugs:

    import backtrader as bt
    import backtrader.feeds as btfeeds
    from datetime import datetime
    import pandas_datareader.data as web
    import matplotlib.pylab as pylab
    pylab.rcParams['figure.figsize'] = 20, 10  # that's default image size for this interactive session
    pylab.rcParams["font.size"] = "20"
    
    class vix_ratio(bt.Strategy):
    
        def log(self, txt):
            print("%s, VIX: %.2f, VIX_VXV:%.2f %s" % (self.vix.datetime.date(0).isoformat(), self.vix.close[0], self.vix_ratio, txt))       
                  
        def __init__(self):
            self.spy = self.data0
            self.agg = self.data1
            self.vix = self.data2
            self.vxv = self.data3
            self.vix_ratio = 0
            self.flag = True
        
        def notify_order(self, order):
            if order.status in [order.Submitted, order.Accepted]:
                # Buy/Sell order submitted/accepted to/by broker - Nothing to do
                return
            
            # Check if an order has been completed
            # Attention: broker could reject order if not enougth cash
            if order.status in [order.Completed]:
                if order.isbuy():
                    self.log(order.data._name + ' BUY EXECUTED, %.0f shares at $%.2f' % (order.size, order.executed.price))
                elif order.issell():
                    self.log(order.data._name + ' SELL EXECUTED, %.0f shares at %.2f' % (order.size, order.executed.price))
    
                self.bar_executed = len(self)
    
            elif order.status in [order.Canceled, order.Margin, order.Rejected]:
                self.log(order.data._name + ' Order Canceled/Margin/Rejected, %.0f shares' % (order.size))#, order.price))
                print(self.broker.getcash())
                print(self.spy[-1])
                print(order)
            # Write down: no pending order
            self.order = None
            
        def next_open(self): # Using cheat-on-open
            self.vix_ratio = self.vix.close[0]/self.vxv.close[0]
            
            if (self.vix_ratio <= 1 or self.vix.close[0] <= 20) and self.flag:
                self.flag = False
                self.order = self.order_target_percent(data=self.agg, target=0)
                self.order = self.order_target_percent(data=self.spy, target=1)
            elif (self.vix_ratio > 1 and self.vix.close[0] > 20) and not self.flag:
                self.flag = True
                self.order = self.order_target_percent(data=self.spy, target=0)
                self.order = self.order_target_percent(data=self.agg, target=1)
                
    def run_strat():
        start = datetime(2006,7,17)
        end = datetime(2017,4,21)   
        
        spy = btfeeds.YahooFinanceData(dataname="SPY", fromdate=start, todate=end)
        agg = btfeeds.YahooFinanceData(dataname="AGG", fromdate=start, todate=end)
        vix = btfeeds.YahooFinanceData(dataname="^VIX", fromdate=start, todate=end)
        vxv = btfeeds.YahooFinanceData(dataname="^VXV", fromdate=start, todate=end)
        #vix = bt.feeds.PandasData(dataname=web.DataReader("^VIX", 'yahoo', start, end), name='VIX')
        #vxv = bt.feeds.PandasData(dataname=web.DataReader("^VXV", 'yahoo', start, end), name='VXV')
        
        cerebro = bt.Cerebro(cheat_on_open=True)
        
        cerebro.adddata(spy, name="SPY")
        cerebro.adddata(agg, name="AGG")
        cerebro.adddata(vix, name="VIX")
        cerebro.adddata(vxv, name="VXV")
        
        cerebro.addstrategy(vix_ratio)
        cerebro.broker.setcash(10000.0)
        #cerebro.addanalyzer(bt.analyzers.PyFolio, _name='pyfolio')
        
        results = cerebro.run()
            
        cerebro.plot()
        """strat = results[0]
        pyfoliozer = strat.analyzers.getbyname('pyfolio')
        returns, positions, transactions, gross_lev = pyfoliozer.get_pf_items()
    
        return returns, positions, transactions
        """
    if __name__ == '__main__':
        #r, p, t = run_strat()
        run_strat()
    


  • @backtrader

    You are still using the close price for the calculation of the stake, which may be significantly different of the open. If you don't specifically specify the opening price it will not be used for the calculation. The calculation of the percent doesn't know you are cheating and are able to act before the broker

    So in other words, cheat_on_open doesn't really cheat on open for open_target_percent?


  • administrators

    From the Blog - Cheat On Open post documenting cheat_on_open

    Activates an extra cycle in the system which calls the methods in the strategy next_open, nextstart_open and prenext_open
    

    A lot more could be quoted, but in summary: The post doesn't say anything about order_target_percent. It says it gives you the chance to act before the broker has evaluated the orders and the indicators are recalculated That means it is really giving you an equivalent of acting during the open, before anything happens. You choose what to do.

    order_target_percent makes a calculation based on the latest available price unless it is told to use a different price. Because you specify no other price, the latest available price is used. You could also decide to use the high price if wished, but you probably want to use the opening price.

    In other words: you have to cheat, the method doesn't.



  • @backtrader

    Got it. Back to spaghetti code try except lookahead.

    In your mind, what would be the best way to structure the code for live trading for 100% invested allocation purposes, aside from leaving 1-1.5% cash to make sure everyhing fills?


  • administrators

    You only have to specify to order_target_percent which price has to be used for the calculation of the stake.

    Maybe someone has experience with all-in strategies.



  • @backtrader
    Again, order_target_percent does not work properly. It is always calculating position target value with the wrong basis using the previous close, regardless if you look-ahead or using the new cheat_on_open.

    If you look at broker.py line 365 def _get_value(), its very clear that the portfolio values is only calculated at close. order_target_percent thenh calculates account/position value with the current close (see line 1301, strategy.py, target *= self.broker.getvalue()).

    What should've happened, for cheat_on_open, is that broker.get_value() should return the value of the account at the current open for calculating sizing but instead it uses previous close for sizing.

    It is not obvious if you trade only a single security at 10% sizing but errors will show up all over the place if you trade more than one security with more than 95% of the portfolio invested.

    The intellectually lazy way to bypass this bug is to never allocate over 90-95% of the whole portfolio to prevent this problem from showing up. The downside of salvaging backtesting this way is that it is difficult to verify backtrader output verified against Excel or simple vectorized backtests.


  • administrators

    @cnimativ said in Unexpected additional orders created/rejected:

    What should've happened, for cheat_on_open, is that broker.get_value() should return the value of the account at the current open for calculating sizing but instead it uses previous close for sizing.

    Wrong assumption. With cheat_on_open you are given the chance to act before the market opens. But the broker cannot calculate the portfolio on prices which have yet to happen, but which are available to your for cheating, because you can already access the new open price.

    If the value were to be recalculated with the open price, which has not happened yet, you would actually be given free money (if moving in your direction) to trade with that same open price. That goes beyond to cheating by getting access to the opening price, because it introduces a wrong calculation in the system.

    You can still specify the opening price to order_target_percent and your orders will be sized accordingly, because a market order issued before the opening bell will be matched with the open price. But that seems to be the only thing which is not being done: price=self.data.open[0]



  • @backtrader
    ? I am already placing trade w/ price=self.data.open[0] and cheat_on_open. Backtrader will reject those orders internally due to reasons outlined above.

    On another thought, how do we place orders on margin? Adding those margin cash will be another way to solve this issue. Does backtrader keep track of gross exposure vs net exposure/unlevered? I can tolerate trading on a few points of margin to get fill in both live/simulation but need a wy to track gross/net exposure.


Log in to reply
 

Looks like your connection to Backtrader Community was lost, please wait while we try to reconnect.