Speed

How fast is caterpillar?

• We recently indexed all of Wikipedia on an Amazon EC2 instance.
• Instance: c3.2xlarge - 8 cores,  16GiB RAM, 1 x 4000 IOPS SSD.
• There are ~15M English articles (in August),  ~14GB (only counting the raw text).
• Indexing all articles took ~12 hours. That means ~1GB per hour.

How does that compare?

• Apache Lucene claims ~200GB per hour. That's on a 24 core machine with 10 high end SSDs in RAID 0 (striped). Obviously that is VERY fast. So fast I am skeptical.
• Whoosh doesn't give any real statistics but we can test it....
• The Test: Add 2,640 articles in plain text format running on my local machine to an index.
• The Contestants: Whoosh, Lucene (PyLucene), Caterpillar.
• The Environment: My laptop.
  • MacBook Pro Retina Mid 2012 
  • 2.6 GHz Intel Core i7 (4 cores, 8 virtual cores)

  • 8 GB 1600 MHz DDR3

  • APPLE SSD SM512E - 14.1 MB/s Random 4k read/writes (benchmark)

Whoosh

from whoosh.fields import TEXT, Schema, ID
from whoosh.index import create_in, os

schema = Schema(
    title=TEXT(stored=True), 
    text=TEXT(stored=True)
)
ix = create_in(index, schema)  # Create index
writer = ix.writer()
for article in articles:
    writer.add_document(
        title=unicode(page[1], 'utf-8'), 
        text=unicode(page[4], 'utf-8')
    )
writer.commit()

The basic code

Actual Code: here.

Result - 18.160s

Lucene (PyLucene)

import lucene
from java.io import File
from org.apache.lucene.analysis.standard import StandardAnalyzer
from org.apache.lucene.document import Document, Field, FieldType
from org.apache.lucene.index import FieldInfo, IndexWriter, IndexWriterConfig
from org.apache.lucene.store import SimpleFSDirectory
from org.apache.lucene.util import Version

store = SimpleFSDirectory(File(index_dir))
analyzer = StandardAnalyzer(Version.LUCENE_CURRENT)
config = IndexWriterConfig(Version.LUCENE_CURRENT, analyzer)
config.setOpenMode(IndexWriterConfig.OpenMode.CREATE)
writer = IndexWriter(store, config)

title = FieldType()
title.setIndexed(True)
title.setStored(True)
title.setTokenized(False)
title.setIndexOptions(FieldInfo.IndexOptions.DOCS_AND_FREQS)

text = FieldType()
text.setIndexed(True)
text.setStored(True)
text.setTokenized(True)
text.setIndexOptions(FieldInfo.IndexOptions.DOCS_AND_FREQS_AND_POSITIONS)

for article in articles:
    doc = Document()
    doc.add(Field("title", page[1], title))
    doc.add(Field("text", page[2], text))
    writer.addDocument(doc)

The (not really) basic code

Actual Code: here.

Result - 1.666s

Caterpillar

from caterpillar.processing.index import IndexWriter, IndexConfig
from caterpillar.processing.schema import Schema, TEXT, CATEGORICAL_TEXT

config = IndexConfig(
    SqliteStorage, 
    Schema(
        title=TEXT(indexed=False, stored=True),
        text=TEXT(indexed=True, stored=True),
        url=CATEGORICAL_TEXT(stored=True)
    )
)
with IndexWriter('/tmp/cat-index', config) as writer:  # Create index
    for article in articles:
        writer.add_document(title=article[1], text=article[2])

The basic code

Actual Code: here.

Result - 15.655s

Damn...

BUT!!!

• Caterpillar breaks documents up into context blocks.
• By default, those context blocks are 2 sentences long.
• To do sentence tokenisation, it uses the Punkt tokenizer from NLTK. And that adds overhead....

Caterpillar - Reboot

Result - 10.183s

Remove sentence tokenisation.

Well then...

BUT!!!

• Lucene cheats!!!
• There is no such thing as a GIL in Java, and Lucene leverages this.
• So, how does caterpillar scale with more cores? Can we make this more parallel?
• Lets give it a go....

Caterpillar - Reboot (again)

Use 2 process to index the articles.

import begin
from concurrent import futures
from caterpillar.processing.index import IndexWriter, IndexConfig
from caterpillar.processing.schema import Schema, TEXT, CATEGORICAL_TEXT

def index(path, articles):
    # Same index code as before...omitted to save space

def chunks(l, n):
    """Yield successive n-sized chunks from l."""
    for i in xrange(0, len(l), n):
        yield l[i:i+n]

@begin.start
def run(articles):
    chunks = [articles[:len(articles)/2], articles[len(articles)/2:]]
    paths = [
        os.path.join('/tmp/wiki-index', 'index-{}'.format(i)) 
        for i in range(len(chunks)
    ]
    with futures.ProcessPoolExecutor() as pool:
        pool.map(index, paths, chunks)

Result - 6.299s

Taking Stock

• My competitive nature means I can't pretend to be happy about the time difference between Caterpillar and PyLucene.
• However, when I wiped away the tears, it wasn't all doom and gloom.
• Caterpillar is almost twice as quick as Whoosh even with the NLTK sentence tokenizer which brings added analytics possibilities.
• AFAIK it's that fastest pure python indexer available.
• However, it appears to be a clear demonstration of compiled vs interpreted.
• There is no denying the API is much nicer in both Whoosh and Caterpillar.

So, how did we get here?

• There are a number of simple things you can do to improve the speed of any Python 2 code you write. 
• I have some general tips that apply to Python 2. Maybe others can talk about Python 3.
• If you need to optimise your code, the first step will be profiling your code.
• Some (maybe most) of what I am about to say will be well known to some. I'm expecting (and hoping) people will tell me I'm wrong about some things.
• There are also specifics things inside Caterpillar that we did that have helped with speed and might be interesting.

General tips

Calling methods/functions is slow

>>> import timeit
>>> timeit.timeit('a = 5')
0.03456282615661621
>>> timeit.timeit('foo()', 'def foo(): a = 5')
0.14389896392822266

The practical implication of this for me is that sometimes you need to forgo a "sexier" API in favour of less nested calls. I was overly addicted to the neat APIs possible in Python because of the bitterness instilled in me by Java, so I've had to rein that in. Still more to do on that front in Caterpillar.

Avoid if..else on collections

positions = dict()

for token in tokens:
    if token in positions:
        positions[token].append((t.index, t.position,)]
    else:
        positions[token] = [(t.index, t.position,)]

Know the builtins!

You can think of map as a for moved into C code. The only restriction is that the "loop body" of map must be a function call. Besides the syntactic benefit of list comprehensions, they are often as fast or faster than equivalent use of map.

This can be extended to don't write something yourself if there is an equivalent builtin. Chances are, the builtin is written in C and much faster then your pure Python implementation.

https://wiki.python.org/moin/PythonSpeed/PerformanceTips#Loops

Know the Big O of basic operations on the builtin types

This can make a big difference to your everyday code.

>>> timeit.timeit('2 in my_list', 'my_list = [1,2,3,4,5]')
0.05846595764160156
>>> timeit.timeit('2 in my_set', 'my_set = set([1,2,3,4,5])')
0.04645490646362305

Also, don't forget about collections.deque!

Time Complexity article on the Python Wiki: here.

Lecture on Complexity of Python Operations: here.

And the list goes on..

• That's some general tips you should be able to help you out in almost every situation.
• In general, it boils down to know your tools and keep it simple stupid.
• But, if you are dumb enough to try and take on a compiled library from an interpreted environment or you have some other situation where execution time matters, you have to profile.

PythonSpeed article on the Wiki: here.

Profiling

• It really is dead simple. Nothing to be scared of.
• The basic idea is to start with profile / cProfile (from the stdlib).
• From there, there are other tools you can use to visualise the results.
• Or, you can just start at the terminal.
• I like pretty pictures personally.
• Finally, you can go a step further by using a line profiler or memory profiler.
• Dont forget, profiling can be fun....

...especially when you find that simple speed-up!

profile / cProfile

• Unless you have a very good reason not to (like extending the profile module), you will want to use cProfile. Its overheads are much smaller than its Python equivalent.
• It can be invoked as a script that takes another script (python -m) or in code.
• Generally, I always enact it from code because 99% of the time, I use another tool to visualise the output.
• By default, profile / cProfile will print out a table with information about all function calls.
• You can customise how the table is printed, interact programmatically with the statistic captured or save the output to a file (using the pstats module).

Sample output

      197 function calls (192 primitive calls) in 0.002 seconds

Ordered by: standard name

ncalls  tottime  percall  cumtime  percall filename:lineno(function)
     1    0.000    0.000    0.001    0.001 <string>:1(<module>)
     1    0.000    0.000    0.001    0.001 re.py:212(compile)
     1    0.000    0.000    0.001    0.001 re.py:268(_compile)
     1    0.000    0.000    0.000    0.000 sre_compile.py:172(_compile_charset)
     1    0.000    0.000    0.000    0.000 sre_compile.py:201(_optimize_charset)
     4    0.000    0.000    0.000    0.000 sre_compile.py:25(_identityfunction)
   3/1    0.000    0.000    0.000    0.000 sre_compile.py:33(_compile)

import cProfile
import re
cProfile.run('re.compile("foo|bar")')

Produces

https://docs.python.org/2/library/profile.html

snakeviz

• Using pstats.dump_stats() means you can use other tools to visualise the profile dump. My favourite is snakeviz.

def do_some_work_yo():
    print 'Some work'

pr = cProfile.Profile()
pr.runcall(do_some_work_yo)
ps = pstats.Stats(pr)
ps.dump_stats("storage_benchmark.profile")

Demo......

line_profiler

• If you are still having trouble tracking down the exact cause of slowness, line_profiler might be a good next step.
• The argument for line_profiler is that cProfile only details function calls and it isn't always enough to figure out which part of the function is actually slow. 
• In practice, I find that is rarely the case, but it is still a nice tool to have in your locker.
• You will typically only be interested in profiling one function (it literally prints out each line of code with profiling information so it is very verbose).
• Be aware that line_profiler adds significant overhead to runtime but it's consistent enough to give you meaningful results.

Typical line_profiler workflow

You need to tell it what functions to profile. Easiest way to start is via the kernprof script.

$ kernprof -l script_to_profile.py

kernprof inserts a LineProfiler instance into the __bultins__ namespace under the name profile. It can be used as a decorator. As adjust your code.

@profile
def slow_function(a, b, c):
    ...

kernprof saves to a file <script_name>.lprof. This is the out you run line_profiler on.

$ python -m line_profiler script_to_profile.py.lprof

And voilà

Pystone(1.1) time for 50000 passes = 2.48
This machine benchmarks at 20161.3 pystones/second
Wrote profile results to pystone.py.lprof
Timer unit: 1e-06 s

File: pystone.py
Function: Proc2 at line 149
Total time: 0.606656 s

Line #      Hits         Time  Per Hit   % Time  Line Contents
==============================================================
   149                                           @profile
   150                                           def Proc2(IntParIO):
   151     50000        82003      1.6     13.5      IntLoc = IntParIO + 10
   152     50000        63162      1.3     10.4      while 1:
   153     50000        69065      1.4     11.4          if Char1Glob == 'A':
   154     50000        66354      1.3     10.9              IntLoc = IntLoc - 1
   155     50000        67263      1.3     11.1              IntParIO = IntLoc - IntGlob
   156     50000        65494      1.3     10.8              EnumLoc = Ident1
   157     50000        68001      1.4     11.2          if EnumLoc == Ident1:
   158     50000        63739      1.3     10.5              break
   159     50000        61575      1.2     10.1      return IntParIO

Some resources

• profile on PyMOTW: here.
• A guide to analyzing Python Performance (including memory profiling): here.

Final word on profiling

• I hope I demonstrated that profiling really is easy.
• It really should be your first stop for optimising code.
• You will develop your own best practises based on your experience with profiling.

Specific notes on Caterpillar

• Remember I said I hated complexity? Well we started SIMPLE!
• There was lots of loops, really simple serialisation and no transactions, plus many other things.
• Profiling told us:
  • ​Using if..else when building the indexes was bad.
  • Using JSON serialisation was bad.
  • Trying to merge new data into large indexes was expensive.
  • Time spent writing to disk was excessive (transactions).
• Unfortunately, I think we have probably only scratched the surface. That's both exciting and soul crushing.