Back to Community
Extraordinary Popular Delusions and the Madness of Crowds.

That is the title of a book by Charles Mackay written in 1841 as a compendium of the history of financial manias of the recent Western variety: Tulipomania, The Mississippi Scheme, and the South Sea Company are the first parts of the book to my recollection.

I write this to illustrate the financial mania of our time: that of ever decreasing volatility due to Central Bank omnipotence.

This backtest involves shorting VXX, and if there is margin available, shorting some more at the end of the day, with a stop out put in at the beginning of each day, monitored minute by minute. Although the algorithm does not accurately model volume impact and/or slippage, since it only involves a maximum of one trade per day, those costs should not add to anything to impact the order of magnitude of the result over time.

To understand what is going on here, know that the VXX ETF was contrived (in 2009) by a big bank so that their prop trading desk and their clients prop trading desks could offload their long volatility trades that made them @$$loads of money going into the financial crisis onto unsuspecting retail investors coming out of it. The ETF was marketed to everyday people as a way to play volatility, as it was on the rise at the time (and reaching the apex).

People that don't understand futures and forwards curves, contango, roll risk, and what volatility actually is have lost a lot of money "investing" in this stock/ETF/asset.

The return since inception of shorting this stock with minimal exit and re-entry points is 2500% over the last 5 years. The cash flow works, you can check it. If you were a human being doing this, all you would have had to do was avoid reentering prematurely during the aftermath of the flash crash of 2010, the government shutdown of 2011, and Ebola/Ukraine of 2014 and the return could be well north of 4000%.

This strategy is probably still profitable today, but in a limited fashion, which is why I've decided to share it. IB only has 100,000 shares available to short, which is amazing considering there are a reported 50MM shares sold short whereas there are only 30MM shares in existence as of this writing (hmmm.....). There is probably a way of doing this better with options instead of outright selling the shares, but seriously, if you don't understand forwards curves, contango, and roll risk, do not attempt anything that resembles a trade anywhere near anything claiming to have anything to do with the volatility index.

Clone Algorithm
74
Loading...
Backtest from to with initial capital
Total Returns
--
Alpha
--
Beta
--
Sharpe
--
Sortino
--
Max Drawdown
--
Benchmark Returns
--
Volatility
--
Returns 1 Month 3 Month 6 Month 12 Month
Alpha 1 Month 3 Month 6 Month 12 Month
Beta 1 Month 3 Month 6 Month 12 Month
Sharpe 1 Month 3 Month 6 Month 12 Month
Sortino 1 Month 3 Month 6 Month 12 Month
Volatility 1 Month 3 Month 6 Month 12 Month
Max Drawdown 1 Month 3 Month 6 Month 12 Month
from datetime import date

def initialize(context):
    set_commission(commission.PerShare(cost=.006, min_trade_cost=None))
    set_slippage(slippage.FixedSlippage(spread=0.00))
    context.security = symbol('VXX')
    context.mmstop = 20
    context.dma = 10
    context.stopout = 10000
    context.stoporder = None
    context.pstop = 0

    schedule_function(
        openfunction,
        date_rule=date_rules.every_day(),
        time_rule=time_rules.market_open(minutes=1)
    )

    schedule_function(
        closefunction,
        date_rule=date_rules.every_day(),
        time_rule=time_rules.market_close(minutes=2),
        half_days=True
    )
    
    schedule_function(
        cancelall,
        date_rule=date_rules.every_day(),
        time_rule=time_rules.market_close(minutes=1),
        half_days=True
    )
    pass
    
def cancelall(context,data):
    all_open_orders = get_open_orders(context.security)
    if all_open_orders:
        for oo in all_open_orders:
            cancel_order(oo)
    pass

def openfunction(context,data):
    if context.shares != 0:
        context.stoporder = order_target_value(context.security,0, style=StopOrder(context.pstop))
    else:
        context.stoporder = None
    pass
                           
def closefunction(context,data): 
    if get_order(context.stoporder) == None:
        context.test = True
    else:
        context.test = not get_order(context.stoporder).stop_reached
        if get_order(context.stoporder).stop_reached:
            context.stopout = context.pstop 
    if context.test:
        if context.imargin > context.curprice:
            if context.curprice < context.stopout:
                order_target_value(context.security,-context.value)
            else:
                if context.curprice < context.avgprice:
                    order_target_value(context.security,-context.value)                      
    pass
    
def handle_data(context, data):
    #do portfolio calculations
    context.avgprice = data[context.security].mavg(context.dma)
    context.curprice = data[context.security].price 
    context.pcash = context.portfolio.cash
    context.shares = context.portfolio.positions[context.security].amount
    context.buyback = context.shares * context.curprice    
    context.value = context.pcash + context.buyback
    context.imargin = context.value + context.buyback
    context.mmargin = context.portfolio.portfolio_value + context.buyback * 0.5
    context.mmp = context.mmargin / context.value * 100
    if context.shares != 0:
        context.pstop = -0.75 * context.pcash / 1.25 / context.shares
    record(MMP=context.mmp)
There was a runtime error.
4 responses

Volatility trading is really interesting to me, I almost prefer to play volatility over equities because I feel like there is a little bit more predictability, it just moves soo fast. I would argue that we don't have ever-decreasing volatility though, the decline of VXX has more to do with contango than an actual decrease in volatility. This might be worth a read, it explains the rebalancing methodology of VXX. http://www.thelongtailoffinance.com/SA/Dissecting_the_VXX.pdf

David

I worked with that algo when posted and learned a thing or two about short-selling.

In the spirit of history, here's some audio about the first short seller selling short the first stock surely, aired this week on NPR: http://www.npr.org/blogs/money/2015/01/23/379416223/episode-598-the-very-first-short ... with an intro added by some other guys on their silly failed effort to "short the entire stock market".
After they lost since America didn't drop, today they put out another version more cynical now: http://www.npr.org/2015/01/29/382326996/why-don-t-more-people-short-stocks-its-a-great-way-to-lose-lots-of-money Somewhere they even include a phone call to eTrade. Lots of overlap.

I'm neutral, no dog in this hunt.
Meanwhile I think the concept by A.R. is educational and thank you for posting it.

I am familiar with the mechanics of VIX futures and the associated exchange traded notes such as VXX and SVXY.

I noticed when testing this code it seems it has borrowed almost 100% of the amount of cash in the portfolio. This would violate Regulation T as well as the fact that most brokerages have more stringent margin requirements than Regulation T requires, especially with a security such as VXX.

Does anyone know a way in which to reflect these limitations when backtesting?

Cash is always positive (charted). This also has a track_orders option turned on (log window) that I used to understand better, worth checking out.

Can you make use of context.account.regt_margin ?

True, risky. When run over only the last year, lots of up/down with over 50% drawdown of portfolio value.

Clone Algorithm
15
Loading...
Backtest from to with initial capital
Total Returns
--
Alpha
--
Beta
--
Sharpe
--
Sortino
--
Max Drawdown
--
Benchmark Returns
--
Volatility
--
Returns 1 Month 3 Month 6 Month 12 Month
Alpha 1 Month 3 Month 6 Month 12 Month
Beta 1 Month 3 Month 6 Month 12 Month
Sharpe 1 Month 3 Month 6 Month 12 Month
Sortino 1 Month 3 Month 6 Month 12 Month
Volatility 1 Month 3 Month 6 Month 12 Month
Max Drawdown 1 Month 3 Month 6 Month 12 Month
from datetime import date

def initialize(context):
    set_commission(commission.PerShare(cost=.006, min_trade_cost=None))
    set_slippage(slippage.FixedSlippage(spread=0.00))
    context.security  = symbol('VXX')
    context.dma       = 10
    context.mmstop    = 20
    context.pstop     = 0
    context.stopout   = 10000
    context.stoporder = None

    schedule_function(
        openfunction,
        date_rule=date_rules.every_day(),
        time_rule=time_rules.market_open(minutes=1)
    )

    schedule_function(
        closefunction,
        date_rule=date_rules.every_day(),
        time_rule=time_rules.market_close(minutes=2),
    )

    schedule_function(
        cancelall,
        date_rule=date_rules.every_day(),
        time_rule=time_rules.market_close(minutes=1),
    )

def cancelall(context,data):
    all_open_orders = get_open_orders(context.security)
    if all_open_orders:
        for oo in all_open_orders:
            cancel_order(oo)
        summary(context, data)

def openfunction(context,data):
    if context.shares != 0:
        context.stoporder = order_target_value(
            context.security,0, style=StopOrder(context.pstop))
    else:
        context.stoporder = None
    summary(context, data)

def closefunction(context,data):
    if get_order(context.stoporder) == None:
        context.test = True
    else:
        context.test = not get_order(context.stoporder).stop_reached
        if get_order(context.stoporder).stop_reached:
            context.stopout = context.pstop
    if context.test:
        if context.imargin > context.curprice:
            if context.curprice < context.stopout:
                order_target_value(context.security,-context.value)
            else:
                if context.curprice < context.avgprice:
                    order_target_value(
                        context.security,-context.value)
    summary(context, data)

def handle_data(context, data):
    #do portfolio calculations
    context.avgprice = data[context.security].mavg(context.dma)
    context.curprice = data[context.security].price
    context.pcash    = context.portfolio.cash
    context.shares   = context.portfolio.positions[context.security].amount
    context.buyback  = context.shares * context.curprice
    context.value    = context.pcash + context.buyback
    context.imargin  = context.value + context.buyback
    context.mmargin  = context.portfolio.portfolio_value + context.buyback * 0.5
    context.mmp      = context.mmargin / context.value * 100
    if context.shares != 0:
        context.pstop = -0.75 * context.pcash / 1.25 / context.shares
    record(MMP=context.mmp)


def summary(context, data):
    '''
        Summary processing

        https://www.quantopian.com/posts/run-summary
    '''
    #  - - - - - - - -  Options  - - - - - - - -
    track_orders    = 1  # Log order placements and fills.
    percent_results = 0  # Express results like 218% instead of x2.18
    filter_zeros    = 0  # 0 or 1 to filter out those with no buy and no sell.
                         # In get_fundamentals for example there can be over
                         #   a thousand stocks processed with many not traded.
                         #
    #  Custom chart only accepts 5 items so watch for that.
    chart_cash      = 1  # Custom chart of cash usage.
    chart_maxspent  = 0  # Custom chart returns based on profit/maxspent.
                         #  At 1/2015 Q returns are profit/init_cash.
    chart_stability = 0  # Custom chart stability calc, a metric Q uses.
                         #   Know the chart can only accept five items.
    margin_alert    = 1  # Log new lowest cash points reached.
    cancel_partials = 1  # Cancel orders after being partially filled.
    daily_live      = 1  # Log summary at end of each day when live.

    ''' ToDo:
            Fix Multiplication factor
            'aborting'
            Shorting.
            Few day low trades.
            '-'s like x-0.01
            Change filter_zeros to threshold above any value.
            Option to chart when transactions occur.
            bug in single syms, all neg:
                Cloned from "Reply to: Quantopian Tutorial with Sample
                    Momentum Algorithm - Lesson 1: The basics of the IDE"
            xinf
             Relativ Buy| By|Sl By|Sl Price Max Cash Shrs Shrs `
             Symbol Ratio Hold Count Evnts Strt|Now Spnt Now Now Value `
             EDAP xinf 0 513329|513329 23|29 3|3 -99467 -8189 0 0`
             Note to use summary(context, data) after each order.
    '''
    import datetime as _dt
    import pytz as _pytz   # underscore since has to be unique to not collide.
    import time as _time
    if 'books' not in context:
        '''
            Preparation. Initialize one time.
        '''
        cash = context.portfolio.starting_cash
        context.books = {   # Starting cash value from GUI or live restart...
            'cash_low'      : cash,
            'shares'        : 0,       # Overall number of shares owned.
            'count_buy'     : 0,       # Overall buy count, number of shares.
            'count_sell'    : 0,       # Overall sell count.
            'cnt_buy_evnts' : 0,       # Overall buy events count.
            'cnt_sel_evnts' : 0,
            'summary_print' : 0,       # Use to force print when you like.
            'commissions'   : 0,       # Commissions.
            'elapsed_start' : 0,       # For run elapsed time.
            'stability'     : 0,       # A metric Q uses.
            's_timeseries'  : [],      #   For stability calc.
            'sids_seen'     : [],      # For set_universe since dynamic.
            'orders'        : {},      # Orders for accounting not fully filled yet.
            'leverage'      : {        # Maximum leverage and its date.
                'max' : 0,
                'date': '',
            },
        }
        b = context.books
        b['my_tz'] = 'US/Eastern'      # You can change to your own timezone
        b['elapsed_start'] = _time.time()

        # Environment   First/last dates and
        #   Arena: backtest or live.  Mode: daily or minute.
        env = get_environment('*')
        b['first_trading_date'] = str(env['start'].date())
        b['last_trading_date']  = str(env['end']  .date())
        b['last_trading_time']  = str(env['end']  .time())
        b['arena'] = env['arena']
        b['mode']  = env['data_frequency']

        if b['arena'] == 'live':
            b['arena'] = 'paper'
        elif b['arena'] != 'backtest': # ie like 'IB'
            b['arena'] = 'live'

        # Show environment at the beginning of the run
        prep_prnt = ' {}         {} {}\n  {}  {} to {}  {}  {}\n'.format(
            b['arena'],
            _dt.datetime.now(
                _pytz.timezone(b['my_tz'])
            ).strftime("%Y-%m-%d %H:%M"),
            b['my_tz'],
            b['mode'],
            b['first_trading_date'],
            b['last_trading_date'],
            '   $' + '%.0f' % context.portfolio.starting_cash,
            '  First bar stocks ({}) ...'.format(len(data)),
        )

        # Show current universe once
        for sec in data:
            if isinstance(sec, basestring):
                continue   # Skip any injected fetcher string keys.
            prep_prnt += (sec.symbol + ' ')
        log.info(prep_prnt)

    b = context.books   # For brevity.
    '''
        Prepare individual securities dictionaries
          with dynamic set_universe, fetcher, IPO's appearing etc.
    '''
    for sec in data:
        if isinstance(sec, basestring):
            continue   # Skip any injected fetcher string keys.
        sym = sec.symbol
        if sym in b and 'price' in b[sym]:
            continue
        if sec not in b['sids_seen']:
            # Scenarios with price missing ...
            price = data[sec].price if 'price' in data[sec] else 0
            b['sids_seen'].append(sec)
            b[sym] = {
                'init_price'    : price,  # Save for summary.
                'price'         : price,  # Most recent price.
                'cash_low'      : 0,      # Lowest level of cash.
                'balance'       : 0,      # For individual 'x' return.
                'shares'        : 0,
                'count_buy'     : 0,      # Individual buy number of shares.
                'count_sell'    : 0,
                'cnt_buy_evnts' : 0,      # Individual buy events count.
                'cnt_sel_evnts' : 0,
                'return'        : 0,      # Return calculated.
                'analog'        : 0,      # Analog relative return ratio.
            }
    cash_now = context.portfolio.cash
    if cash_now < b['cash_low']:
        b['cash_low'] = cash_now
        # An alert for negative cash unless you like "leverage" (margin)
        if margin_alert and cash_now < 0.:
            log.info('        cash low ' + str(b['cash_low']))
    '''
        Custom chart of cash usage.
    '''
    if chart_cash:
        record(cash = context.portfolio.cash)
    '''
        Custom chart of maximum spent returns, profit/maxspent.
    '''
    if chart_maxspent:
        cash_now  = context.portfolio.cash
        cash_strt = context.portfolio.starting_cash
        portfolio = context.portfolio.portfolio_value
        maxspent  = cash_strt - b['cash_low']
        profit    = portfolio - cash_strt
        dreturns  = 0 if not maxspent else profit / maxspent
        qreturns  = profit / cash_strt    # Can be useful for easy visual compare,
        record(QReturn = 100 * qreturns)  #   overlay, same as standard chart.
        record(MaxSpentReturn = 100 * dreturns)
    '''
        Stability calculation (and custom chart option), r-squared.
            quantopian.com/posts/fund-selection-criteria-returns-stability-calculation
            Stability of returns > 0.5 is a baseline for fund consideration.
    '''
    import statsmodels.api as s_m # has to be distinct to avoid collision.
    import numpy as n_p
    b['s_timeseries'].append(context.portfolio.portfolio_value)
    ts = n_p.array(b['s_timeseries'])
    if ts.size < 2:
        b['stability'] = n_p.nan
    else:
        X = s_m.add_constant(range(0, ts.size))
        b['stability'] = (s_m.OLS( ts, X ).fit()).rsquared
        if chart_stability and not n_p.isinf(b['stability']):
            record(stability = b['stability'])
    '''
        Maximum leverage seen.
    '''
    if context.account.leverage > b['leverage']['max']:
        b['leverage']['max']  = context.account.leverage
        b['leverage']['date'] = str(get_datetime().date())

    '''
        Accounting. Update the numbers, manage orders if any.
    '''
    accounting = {}  # Local, any orders ready to be counted.

    # Read open orders
    for security, oo_for_sid in get_open_orders().iteritems():
        for order_obj in oo_for_sid:
            o = order_obj
            # If an order not seen before, add for tracking
            if o.id not in b['orders']:
                b['orders'][order_obj.id] = order_obj.filled

                if track_orders:    # Log new orders and type.
                    price = data[security].price
                    sym   = security.symbol
                    trade = 'Buy' if o.amount > 0 else 'Sell'
                    if o.limit and o.stop:  # Stop-Limit order
                        log.info('    {} {} {} now {} limit {} limit {}\n'.format(
                            trade, o.amount, sym, price, o.limit, o.stop))
                    elif o.limit:           # Limit order
                        log.info('    {} {} {} now {} limit {}\n'.format(
                            trade, o.amount, sym, price, o.limit))
                    elif o.stop:            # Stop order
                        log.info('    {} {} {} now {} stop {}\n'.format(
                            trade, o.amount, sym, price, o.stop))
                    else:                   # Market order
                        log.info('    {} {} {} at {}\n'.format(
                            trade, o.amount, sym, price))

    for id in b['orders']:  # Take a look at current orders saved.
        o = get_order(id)   # Current order, might have been updated.

        # If filled is not zero, account for it
        if o.filled != 0:
            accounting[id] = o    # Set to account for filled.

            # On partial fills, a new order is automatically
            #   generated for the remainder.
            # Bugbug: The only way I could make sense of things so far ...
            # If filled is not amount (shares), that's a partial fill,
            #   cancelling remainder to simplify life. Unsure.
            if cancel_partials and o.filled != o.amount:
                cancel_order(id)

    for id in accounting:    # Do any accounting, into books{}.
        sec = accounting[id]['sid']
        sym = sec.symbol
        if sec in data and 'price' in data[sec]: # Update price if available.
            b[sym]['price'] = data[sec].price
        commission          = accounting[id]['commission']
        filled              = accounting[id]['filled']  # Number filled, sell neg.
        # ToDo: Don't know the official actual fill prices.
        transaction         = filled * b[sym]['price']  # Last known price.
        b[sym]['shares']   += filled      # The transaction on sell is negative
        b[sym]['balance']  -= transaction #   so this line adds to balance then.
        b[sym]['balance']  -= commission
        b['commissions']   += commission

        if filled > 0:                          # Buy
            b[sym]['cnt_buy_evnts'] += 1
            b[sym]['count_buy']     += filled
        elif filled < 0:                        # Sell
            b[sym]['cnt_sel_evnts'] += 1
            b[sym]['count_sell']    += abs(filled)

        if track_orders:
            if filled != 0:    # Log fills.
                trade = 'Bot' if accounting[id]['amount'] > 0 else 'Sold'
                log.info('       {} {} {} at {}\n'.format(
                    trade, filled, sym, b[sym]['price']))
            if accounting[id]['status'] == 2:      # Cancelled
                log.info('       Cancelled {} {} order\n'.format(
                    accounting[id]['amount'], sym))

        del b['orders'][id]    # Remove from the list, accounting done.

        # Keep track of lowest cash per symbol
        b[sym]['cash_low'] = min(b[sym]['balance'], b[sym]['cash_low'])
    '''
        Show summary if last bar
    '''
    last_bar_now = 0
    if not b['summary_print']:
        if context.books['arena'] in ['paper', 'live'] and daily_live:
            # When paper or live log summary every day end of day.
            # Assumes schedule is set to every_day().
            last_bar_now = 1
        elif context.books['arena'] == 'backtest':
            # Flag for summary output if last bar now
            bar = get_datetime()
            if b['last_trading_date'] == str(bar.date()):
                if b['mode'] == 'daily':
                    last_bar_now = 1
                elif b['mode'] == 'minute':
                    # Not ideal.
                    # How to print in minute mode only on last bar simply?
                    log.info('Algo time: ' + str(bar.time()))
                    last_bar_now = 1
    '''
        Summary output to the logging window
    '''
    if last_bar_now or b['summary_print']:
        # Independent copy of context.books using dict() in case summary print
        #   is set to happen more than once in a run, due to concats below (+=)
        b    = dict(context.books)
        done = {}   # Protect against any listed twice.

        # Some overall values by adding individual values
        for sec in b['sids_seen']:
            if sec in done:
                continue

            # There's a problem with a dynamic run where a security can have
            #   dropped out of the picture, all sold, not in current universe,
            #   and its price is no longer accessible. Need help from Q.
            if sec in data and 'price' in data[sec]:
                b[sec.symbol]['price'] = data[sec].price
            sym = sec.symbol
            b['count_buy']     += b[sym]['count_buy']
            b['count_sell']    += b[sym]['count_sell']
            b['cnt_buy_evnts'] += b[sym]['cnt_buy_evnts']
            b['cnt_sel_evnts'] += b[sym]['cnt_sel_evnts']
            b['shares']        += b[sym]['shares']
            done[sec] = 1

        portfolio    = context.portfolio.portfolio_value
        init_cash    = context.portfolio.starting_cash
        cash_now     = context.portfolio.cash
        cash_low     = b['cash_low']
        cash_profit  = cash_now - init_cash
        shares_value = portfolio - cash_now
        spent        = 0
        if init_cash > cash_low:
            spent    = init_cash - cash_low
        else:
            spent    = cash_now - init_cash  # ??  case of short-selling
        spent_prcnt  = ' ({}%)'.format(int(100 * (spent / init_cash)))
        tot_profit   = cash_profit + shares_value
        qntpian_rtrn = (portfolio - init_cash) / init_cash
        maxspnt_rtrn = 0.
        if b['count_buy'] or b['count_sell']:   # If there were trades
            maxspnt_rtrn = tot_profit / spent
        maxspnt_float = maxspnt_rtrn
        rel_word      = ' Prcnt' if percent_results else ' Ratio'
        if percent_results:
            if qntpian_rtrn < 10.:
                qntpian_rtrn  = '{}%'.format(float('%.3f' % (100 * qntpian_rtrn)))
                maxspnt_rtrn  = '{}%'.format(float('%.3f' % (100 * maxspnt_rtrn)))
                maxspnt_float = float('%.3f' % (100 * maxspnt_float))
            elif qntpian_rtrn < 100.:
                qntpian_rtrn  = '{}%'.format(float('%.2f' % (100 * qntpian_rtrn)))
                maxspnt_rtrn  = '{}%'.format(float('%.2f' % (100 * maxspnt_rtrn)))
                maxspnt_float = float('%.1f' % (100 * maxspnt_float))
            else:
                qntpian_rtrn  = '{}%'.format(int(100 * qntpian_rtrn))
                maxspnt_rtrn  = '{}%'.format(int(100 * maxspnt_rtrn))
                maxspnt_float = int(100 * maxspnt_float)
        else:
            if qntpian_rtrn < 10.:
                qntpian_rtrn = 'x' + '%.3f' % qntpian_rtrn
                maxspnt_rtrn = 'x' + '%.3f' % maxspnt_rtrn
            elif qntpian_rtrn < 100.:
                qntpian_rtrn = 'x' + '%.2f' % qntpian_rtrn
                maxspnt_rtrn = 'x' + '%.2f' % maxspnt_rtrn
            else:
                qntpian_rtrn = 'x' + '%.0f' % qntpian_rtrn
                maxspnt_rtrn = 'x' + '%.0f' % maxspnt_rtrn
        if qntpian_rtrn == '0.00%' or qntpian_rtrn == 'x0.00':
            qntpian_rtrn = '0'
        if maxspnt_rtrn == '0.00%' or maxspnt_rtrn == 'x0.00':
            maxspnt_rtrn = '0'

        v1 = {  # values
            'pflo': '%.0f' % portfolio,
            'icsh': str(int(init_cash)),
            'untd': '0' if int(cash_low) <= 0 else str(int(cash_low)),
            'ncsh': '0' if int(cash_low) >= 0 else str(int(cash_low)),
            'down': str(int(spent)),
            'cshp': str(int(cash_profit)),
            'totp': '%.0f' % tot_profit,
            'qret': qntpian_rtrn,
            'dret': maxspnt_rtrn,
        }
        v2 = {
            'cbuy': str(b['count_buy']),
            'csel': str(b['count_sell']),
            'shnw': str(b['shares']),
            'shvl': '%.0f' % shares_value,
            'cmsn': '%.0f' % b['commissions'],
            'cshn': '%.0f' % cash_now,
            'stbl': '%.4f' % b['stability'],
            'lvrg': '%.2f' % b['leverage']['max'],
        }
        # Widths of the longest for columns
        w1 = 0; w2 = 0
        for v in v1:
            len_v_str = len(str(v1[v]))
            if len_v_str > w1:
                w1 = len_v_str
        for v in v2:
            len_v_str = len(str(v2[v]))
            if len_v_str > w2:
                w2 = len_v_str
        for v in v1:  # Padding
            v1[v] = v1[v].rjust(w1)
        for v in v2:
            v2[v] = v2[v].rjust(w2)
        '''
          Portfolio: 342690                     Stability: 0.5228                        `
       Initial Cash:   1000                          Buys: 217225 (147 trades)           `
        Unused Cash:      0                         Sells: 77559 (11 trades)             `
           Neg Cash:    -21                   Commissions: 1523                          `
           MaxSpent:   1021 (102%)             Shares Now: 139666                        `
        Cash Profit:   -991                    Shares Val: 342681                        `
       Total Profit: 341690  w/ shares           Cash Now: 9                             `
            QReturn:   x342  Profit/InitCash      MaxLvrg: 0.98  2014-08-24              `
             Return:   x335  Profit/MaxSpent                                             `
      2015-01-02 summary:616 INFO             200 average initial cash, 5 securities     `
             Relativ   Buy|    By|Sl     By|Sl    Price     Max    Cash    Shrs   Shrs   `
       Symbol  Ratio   Hold    Count     Evnts   Strt|Now  Spnt     Now     Now   Value  `
         RDNT   x32.0   2.2 16849|16849   20|2     3|9     -39502   39768       0       0`
         NVAX   x9.71   2.0 23042|23009   18|3     2|6     -34756   10439      33     190`
         EDAP   x21.2   0.5 143855|4419   34|1     2|2    -205336 -205336  139436  341618`
         ACHN   x61.8   0.6 22133|22133   38|2     8|13    -49470   96132       0       0`
         HGSH   x1548  10.8 11346|11149   37|3     0|4      -1019   58273     197     872`
        '''
        pflo   = '{m1:>15} {m2:<29}{m3}'.format(
            m1 = 'Portfolio:',     m2 = v1['pflo'],
            m3 = 'Stability: ' + v2['stbl'] )
        icsh   = '{m1:>15} {m2:<34}{m3}{m4}'.format(
            m1 = 'Initial Cash:',  m2 = v1['icsh'],
            m3 = 'Buys: ' + v2['cbuy'],
            m4 = ' (' + str(b['cnt_buy_evnts']) + ' trades)' )
        ucsh   = '{m1:>15} {m2:<33}{m3}{m4}'.format(
            m1 = 'Unused Cash:',   m2 = v1['untd'],
            m3 = 'Sells: ' + v2['csel'],
            m4 = ' (' + str(b['cnt_sel_evnts']) + ' trades)' )
        ncsh   = '{m1:>15} {m2:<27}{m3}'.format(
            m1 = 'Neg Cash:',      m2 = v1['ncsh'],
            m3 = 'Commissions: ' + v2['cmsn'] )
        dcsh   = '{m1:>15} {m2:<28}{m3}'.format(
            m1 = 'MaxSpent:',      m2 = v1['down'] + spent_prcnt,
            m3 = 'Shares Now: ' + v2['shnw'] )
        pcsh   = '{m1:>15} {m2:<28}{m3}'.format(
            m1 = 'Cash Profit:',   m2 = v1['cshp'],
            m3 = 'Shares Val: ' + v2['shvl'] )
        ttlp   = '{m1:>15} {m2:<30}{m3}'.format(
            m1 = 'Total Profit:',  m2 = v1['totp'] + '   w/ shares',
            m3 = 'Cash Now: ' + v2['cshn'] )
        qret   = '{m1:>15} {m2:<31}{m3}'.format(
            m1 = 'QReturn:', m2 = v1['qret'] + '   Profit/InitCash',
            m3 = 'MaxLvrg: ' + v2['lvrg'] + '  ' + b['leverage']['date'] )
        dret   = '{m1:>15} {m2}'.format(            # max spent return
            m1 = 'Return:',
            m2 = v1['dret'] + '   Profit/MaxSpent')
        outs        = [pflo, icsh, ucsh, ncsh, dcsh, pcsh, ttlp, qret, dret]
        out_summary = '_\r\n'
        line_len    = 80      # Length
        for o in outs:
            out_summary += (o + ' ' * (line_len - len(o)) + '`\r\n')

        # -------------------------------
        # Individual securities detail
        # -------------------------------
        out_content_collections = []
        count_sids    = len(b['sids_seen'])
        avg_init_cash = init_cash / len(b['sids_seen'])
        sec_word      = ' security' if count_sids == 1 else ' securities'
        sec_strng     = '  ' + '%.0f' % int(avg_init_cash) \
                             + ' average initial cash, ' + str(count_sids) + sec_word
        out_content   = (sec_strng + '    `\r\n').rjust(line_len - 26)
        lines_out     = 11    # Log in clumps to stay under logging limits.
        count_lines   = 0
        if filter_zeros:
            count_lines += 1
            out_content += '.\r\n\tZero buy/sell filtered out `\r\n.\r\n'
        header1 = [
        '',     'Relativ','Buy|','By|Sl','By|Sl','Price',   ' Max','Cash','Shrs','Shrs ']
        header2 = [
        'Symbol',rel_word,'Hold','Count','Evnts','Strt|Now','Spnt',' Now',' Now','Value']
        contents_list = [header1, header2]    # To be lines per sym as a list of lists.

        # The list to process
        sids_to_process = []
        sids_sorted     = {}
        for s in b['sids_seen']:
            sids_sorted[s.symbol] = s
        for sym in sids_sorted:
            if filter_zeros and not b[sym]['count_buy'] and not b[sym]['count_sell']:
                continue
            sids_to_process.append(sids_sorted[sym])

        # Individual return
        return_list = []
        for sec in sids_to_process:
            sym = sec.symbol
            # There's a problem with balance, it is tracked based on
            #   last known price, and when filled, no current way to obtain
            #   the actual fill price.
            # For that reason, there can be discrepancies, sometimes major.
            # To Q, request made to provide us with fill_price in the object id.
            cash_now   = b[sym]['balance']      # Balance started at zero
            cash_low   = b[sym]['cash_low']     # Maximum expended
            shares_val = b[sym]['shares'] * b[sym]['price']
            outputs    = shares_val + cash_now
            cash_pnl   = 0   # Cash profit and loss
            if avg_init_cash > cash_low:             # Typical trading
                cash_pnl = avg_init_cash - cash_low
            else:
                cash_pnl = cash_now - avg_init_cash  # ?? Case of short-selling, unsure
            if (b[sym]['count_buy'] or b[sym]['count_sell']) and avg_init_cash:
                b[sym]['return'] = outputs / cash_pnl
            return_list.append(b[sym]['return'])

        if not return_list:
            if not avg_init_cash:
                log.info('Odd, no avg_init_cash, aborting summary')
            else:
                schedule = '        ' + \
                'schedule_function( \n\t\tsummary, date_rules.every_day()'
                minute_note = ',\n    especially when in minute mode, '
                if b['mode'] == 'daily':
                    schedule   += '\n        )'
                    minute_note = '.\n    '
                else:
                    schedule += ', time_rules.market_close()\n        )'
                log.info(
                    '.\n  No buys and no sells. If unexpected, check placement' + \
                    ' of calls to summary,\n    after any orders and before any' + \
                    ' returns and/or the scheduling for it' + \
                    minute_note + 'like summary(context, data) or\n' + \
                    schedule    + '\n\tAborting summary()'
                )
            return

        # Shift (not entirely sure of this, needs scrutiny)
        shift       = 0    # Up/dn to move value to line up with overall.
        avg_of_list = 0    # Taking avg as an analog of max spent return.
        avg_of_list = sum(return_list) / len(return_list)
        shift       = maxspnt_float - avg_of_list

        # Normalize x values proportionally compared to overall x value
        for sec in sids_to_process:
            sym    = sec.symbol
            analog = 0.
            value  = b[sym]['return'] + shift
            if value == 0:   # like 0.00
                analog = '0'
                continue
            if percent_results:
                if value < 10.:
                    analog = '{}%'.format(float('%.2f' % value))
                elif value < 100.:
                    analog = '{}%'.format(float('%.1f' % value))
                else:
                    analog = '{}%'.format(int(value))
            else:
                if value < 10.:
                    analog = 'x' + '%.2f' % value
                elif value < 100.:
                    analog = 'x' + '%.1f' % value
                else:
                    analog = 'x' + '%.0f' % value

            b[sym]['analog'] = analog

        # Set values
        for sec in sids_to_process:
            sym = sec.symbol
            init_price = b[sym]['init_price']
            if init_price:
                buy_hold = '%.1f' % ((b[sym]['price'] - init_price) / init_price)
                if buy_hold == '-0.0' or buy_hold == '0.0':
                    buy_hold = '0'
            content = [
                sym,
                ' ' + str(b[sym]['analog']),
                buy_hold,
                str(b[sym]['count_buy']) + '|' \
                    + str(b[sym]['count_sell']),
                str(b[sym]['cnt_buy_evnts']) + '|' \
                    + str(b[sym]['cnt_sel_evnts']),
                '%.0f' % init_price + '|' + '%.0f' % b[sym]['price'],
                int(b[sym]['cash_low']),
                int(b[sym]['balance']),
                b[sym]['shares'],
                int(b[sym]['shares'] * b[sym]['price'])
            ]
            # Collect lines per sym as a list of lists
            contents_list.append(content)

        # Set widths
        col_widths = {}
        for i in range(len(contents_list[0])):
            col_widths[i + 1] = 7       # Defaults
        col_widths[1] = 6               # Symbol
        col_widths[3] = 6               # Buy|Hold
        for line_list in contents_list:
            ec = 1  # element count
            for element in line_list:
                if len(str(element)) > col_widths[ec]:
                    col_widths[ec] = len(str(element)) # Set width to largest seen.
                ec += 1

        # Piece together the output lines formatted.
        line_c = 0
        for line in contents_list:
            out_line = ''
            line_c  += 1  # Line count
            cc       = 1  # Column count
            for column in line:
                if cc in [4, 5, 6] or line_c in [1, 2]:
                    out_line += str(column).center(col_widths[cc] + 1)
                else:
                    column = str(column) + ' ' if cc == 3 else column
                    out_line += str(column).rjust(col_widths[cc] + 1)
                cc += 1

            out_content += (out_line + ' ' * (line_len- len(out_line)) + '`\r\n')
            count_lines += 1

            # Backticks at the end of line are for replace-all in an editor
            #   later after copy/paste, since new lines are gone at least on Windows.
            #   Unfortunate to not be able to copy and paste results easily.

            # Decide when to tuck a group away for later and start a new group,
            #   due to logging limits, using modulus (remainder).
            if count_lines % lines_out == 0:
                out_content_collections.append(out_content)
                out_content = '_\r\n'       # Restart a group.

        if count_lines % lines_out != 0:    # A few remaining lines.
            out_content_collections.append(out_content)

        # Log output
        log.info(out_summary)   # The top, general overall output first

        # Log stored groups
        for occ in out_content_collections:
            log.info(occ)

        out_content = '(symbol ratios adjusted proportionally to overall)'.rjust(20)

        hours_elapsed = (_time.time() - b['elapsed_start']) / 3600
        out_content += '\nRuntime hours: {}    End: {} {}'.format(
            '%.2f' % hours_elapsed,
            _dt.datetime.now(      # Change my_tz to your own timezone above
                _pytz.timezone(b['my_tz'])
            ).strftime("%Y-%m-%d %H:%M"),
            b['my_tz']
        )

        # Add any other content you want ---------------------------
        #out_content += '_\n' # Underscore to a new line for left alignment,
                              #   '\n' by itself would be ignored/dropped.
        # Some variables or whatever you might want to add ...
        out_content += ''

        log.info(out_content)

There was a runtime error.