Running speed tests

An automated version of this test for Amara 2.x is in version control under $amara/sandbox/parsebench.py . Use "--markup" to get output formatted for this wiki page.

See the bottom of this page for the basic command line commands from which parsebench.py derived

Using the Python profiler

See Amara/Developer_notes#Profiling

e.g.

echo "from amara.bindery import parse; from itertools import chain" > /tmp/foo.py
echo "parse(''.join(chain(['<a>'], [ '<b c=\'%i\'/>'%i for i in xrange($N) ], ['</a>'])))" >> /tmp/foo.py
python -m cProfile -o /tmp/foo.stats.txt /tmp/foo.py
python -m pstats /tmp/foo.stats.txt

Observations and comparisons

Please keep it to 4Suite-family comparisons on this page (4Suite, Amara, 4DOM, minidom [which was specialized from 4DOM]). We want to be careful with benchmarks comparing products. They're often more marketing mumbo-jumbo than anything useful.

parsebench outcomes

MacBook Pro 17" 2.66 GHz Intel Core 2 Duo 4GB, Snow Leopard

$ python ~/dev/amara/sandbox/parsebench.py
Parse and select timings for Amara 2.0a2
Started on 2010-03-04. Reporting best of 3 tries
                                              core tree     bindery
Parse once (no attributes)                :     4.79 ms     51.49 ms
 descendant-or-self, many results         :    33.86 ms     34.39 ms
 descendant-or-self, no results           :     0.78 ms      0.87 ms
Parse once (with attributes)              :    21.35 ms     94.43 ms
 descendant-or-self w/ attribute, 1 result:    34.92 ms     35.81 ms

$ python ~/dev/amara/sandbox/parsebench.py --profile bindery_parse4
Thu Mar  4 07:45:35 2010    profile.out

         135143 function calls in 1.621 CPU seconds

   Ordered by: standard name

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        3    0.000    0.000    0.000    0.000 :0(StringIO)
        6    0.000    0.000    0.000    0.000 :0(__new__)
        6    0.000    0.000    0.000    0.000 :0(add)
        2    0.000    0.000    0.000    0.000 :0(append)
        3    0.000    0.000    0.000    0.000 :0(count)
        3    0.000    0.000    0.000    0.000 :0(encode)
        3    0.000    0.000    0.000    0.000 :0(hasattr)
    15012    0.063    0.000    0.063    0.000 :0(isinstance)
        3    0.001    0.000    0.001    0.000 :0(isxml)
        3    0.000    0.000    0.000    0.000 :0(len)
        3    0.000    0.000    0.000    0.000 :0(map)
        1    0.004    0.004    0.004    0.004 :0(min)
        3    0.000    0.000    0.000    0.000 :0(range)
        9    0.000    0.000    0.000    0.000 :0(setattr)
        1    0.000    0.000    0.000    0.000 :0(setprofile)
    15003    0.076    0.000    0.076    0.000 :0(splitqname)
        3    0.000    0.000    0.000    0.000 :0(sub)
        6    0.000    0.000    0.000    0.000 :0(time)
        1    0.000    0.000    1.621    1.621 <string>:1(<module>)
        3    0.000    0.000    1.612    0.537 __init__.py:12(parse)
        9    0.000    0.000    0.000    0.000 __init__.py:127(__init__)
        3    0.000    0.000    0.000    0.000 __init__.py:44(create_string_buffer)
        3    0.000    0.000    0.002    0.001 _inputsource.py:37(__new__)
        3    0.000    0.000    0.000    0.000 _inputsource.py:92(__init__)
        6    0.000    0.000    0.000    0.000 nodes.py:113(__init__)
        3    0.000    0.000    0.000    0.000 nodes.py:148(__init__)
    30003    0.220    0.000    0.221    0.000 nodes.py:225(xml_new_pname_mapping)
    15003    0.213    0.000    0.385    0.000 nodes.py:266(xml_child_inserted)
    15003    0.080    0.000    0.080    0.000 nodes.py:469(__init__)
    15000    0.152    0.000    0.264    0.000 nodes.py:476(xml_attribute_added)
        3    0.000    0.000    0.000    0.000 nodes.py:545(__new__)
        3    0.000    0.000    0.000    0.000 nodes.py:553(__init__)
    15003    0.091    0.000    0.091    0.000 nodes.py:575(xml_pyname)
    15003    0.380    0.000    0.628    0.000 nodes.py:616(xml_element_factory)
        1    0.005    0.005    1.621    1.621 parsebench.py:14(timeit)
        1    0.000    0.000    1.621    1.621 parsebench.py:88(bindery_parse4)
        1    0.000    0.000    1.621    1.621 profile:0(bindery_parse4())
        0    0.000             0.000          profile:0(profiler)
        3    0.333    0.111    1.612    0.537 tree.py:26(parse)
        3    0.000    0.000    0.000    0.000 uuid.py:101(__init__)
        3    0.000    0.000    0.000    0.000 uuid.py:197(__str__)
        3    0.000    0.000    0.000    0.000 uuid.py:270(get_urn)
        3    0.000    0.000    0.001    0.000 uuid.py:515(uuid4)

Other experiments

Any advantage to pre-parsing XPath expressions?

(MacBook Pro / Mac Snow Leopard / System Python 2.6.2 on 17 Feb 2010)

python -m timeit -s "from itertools import chain" -s "import amara; from amara.xpath import context, parser" -s "cached = parser.parse(u'self::b')" -s "doc = amara.parse(''.join(chain(['<a>'], [ '<b/>' for i in xrange(1000) ], ['</a>'])))" "map(lambda node: len(cached.evaluate(context(node))), doc.xml_children[0].xml_children)"

Result: 100 loops, best of 3: 14.4 msec per loop

Note: A variant to check that the XPath expression etc is correct:

python -m timeit -s "from itertools import chain" -s "import amara; from amara.xpath import context, parser" -s "cached = parser.parse(u'self::b')" -s "doc = amara.parse(''.join(chain(['<a>'], [ '<b/>' for i in xrange(1000) ], ['</a>'])))" "print sum(map(lambda node: len(cached.evaluate(context(node))), doc.xml_children[0].xml_children))"

So now check without pre-parsing:

python -m timeit -s "from itertools import chain" -s "import amara" -s "doc = amara.parse(''.join(chain(['<a>'], [ '<b/>' for i in xrange(1000) ], ['</a>'])))" "map(lambda node: len(node.xml_select(u'self::b')), doc.xml_children[0].xml_children)"

10 loops, best of 3: 300 msec per loop

Conclusion: Significant difference

Python timings command line background

export N=5000

Amara core tree:

#EXERCISE 1: Testing speed of parse
python -m timeit -s "import amara" -s "from itertools import chain" "amara.parse(''.join(chain(['<a>'], [ '<b/>' for i in xrange($N) ], ['</a>'])))"
#EXERCISE 2: Parse once and test speed of XPath using descendant-or-self, with large result
python -m timeit -s "import amara" -s "from itertools import chain" -s "doc = amara.parse(''.join(chain(['<a>'], [ '<b/>' for i in xrange($N) ], ['</a>'])))" "doc.xml_select(u'//b')"
#EXERCISE 3: Parse once and test speed of XPath using descendant-or-self, with empty result
python -m timeit -s "import amara" -s "from itertools import chain" -s "doc = amara.parse(''.join(chain(['<a>'], [ '<b/>' for i in xrange($N) ], ['</a>'])))" "doc.xml_select(u'//c')"
#EXERCISE 4: Testing speed of parse, part 2
python -m timeit -s "import amara" -s "from itertools import chain" "amara.parse(''.join(chain(['<a>'], [ '<b c=\'%i\'/>'%i for i in xrange($N) ], ['</a>'])))"
#EXERCISE 5: Parse once and test speed of XPath using descendant-or-self with attribute predicate (small result)
python -m timeit -s "import amara" -s "from itertools import chain" -s "doc = amara.parse(''.join(chain(['<a>'], [ '<b c=\'%i\'/>'%i for i in xrange($N) ], ['</a>'])))" "doc.xml_select(u'//b[@c=\'10\']')"

Amara bindery:

#EXERCISE 1: Testing speed of parse
python -m timeit -s "from amara.bindery import parse" -s "from itertools import chain" "parse(''.join(chain(['<a>'], [ '<b/>' for i in xrange($N) ], ['</a>'])))"
#EXERCISE 2: Parse once and test speed of XPath using descendant-or-self, with large result
python -m timeit -s "from amara.bindery import parse" -s "from itertools import chain" -s "doc = parse(''.join(chain(['<a>'], [ '<b/>' for i in xrange($N) ], ['</a>'])))" "doc.xml_select(u'//b')"
#EXERCISE 3: Parse once and test speed of XPath using descendant-or-self, with empty result
python -m timeit -s "from amara.bindery import parse" -s "from itertools import chain" -s "doc = parse(''.join(chain(['<a>'], [ '<b/>' for i in xrange($N) ], ['</a>'])))" "doc.xml_select(u'//c')"
#EXERCISE 4: Testing speed of parse, part 2
python -m timeit -n 3 -s "from amara.bindery import parse" "from itertools import chain" "parse(''.join(chain(['<a>'], [ '<b c=\'%i\'/>'%i for i in xrange($N) ], ['</a>'])))"
#EXERCISE 5: Parse once and test speed of XPath using descendant-or-self with attribute predicate (small result)
python -m timeit -s "from amara.bindery import parse" -s "from itertools import chain" -s "doc = parse(''.join(chain(['<a>'], [ '<b c=\'%i\'/>'%i for i in xrange($N) ], ['</a>'])))" "doc.xml_select(u'//b[@c=\'10\']')"

See also:

Code translations

This is as near as possible an apples-to-apples translations from the exercises defined above to Amara 1.x and 4Suite API

Amara 1.x bindery:

#EXERCISE 1
python -m timeit -n 10 -s "import amara" -s "from itertools import chain" "amara.parse(''.join(chain(['<a>'], [ '<b/>' for i in xrange($N) ], ['</a>'])))"
#EXERCISE 2
python -m timeit -s "import amara" -s "from itertools import chain" -s "doc = amara.parse(''.join(chain(['<a>'], [ '<b/>' for i in xrange($N) ], ['</a>'])))" "doc.xml_xpath(u'//b')"
#EXERCISE 3
python -m timeit -s "import amara" -s "from itertools import chain" -s "doc = amara.parse(''.join(chain(['<a>'], [ '<b/>' for i in xrange($N) ], ['</a>'])))" "doc.xml_xpath(u'//c')"
#EXERCISE 4
python -m timeit -n 3 -s "import amara" -s "from itertools import chain" "doc = amara.parse(''.join(chain(['<a>'], [ '<b c=\'%i\'/>'%i for i in xrange($N) ], ['</a>'])))"
#EXERCISE 5
python -m timeit -s "import amara" -s "from itertools import chain" -s "doc = amara.parse(''.join(chain(['<a>'], [ '<b c=\'%i\'/>'%i for i in xrange($N) ], ['</a>'])))" "doc.xml_xpath(u'//b[@c=\'10\']')"

4Suite 1.x Domlette:

#EXERCISE 1
python -m timeit -s "from Ft.Xml import Parse" -s "from itertools import chain" "Parse(''.join(chain(['<a>'], [ '<b/>' for i in xrange($N) ], ['</a>'])))"
#EXERCISE 2
python -m timeit -s "from Ft.Xml import Parse" -s "from itertools import chain" -s "doc = Parse(''.join(chain(['<a>'], [ '<b/>' for i in xrange($N) ], ['</a>'])))" "doc.xpath(u'//b')"
#EXERCISE 3
python -m timeit -s "from Ft.Xml import Parse" -s "from itertools import chain" -s "doc = Parse(''.join(chain(['<a>'], [ '<b/>' for i in xrange($N) ], ['</a>'])))" "doc.xpath(u'//c')"
#EXERCISE 4
python -m timeit -s "from Ft.Xml import Parse" -s "from itertools import chain" "doc = Parse(''.join(chain(['<a>'], [ '<b c=\'%i\'/>'%i for i in xrange($N) ], ['</a>'])))"
#EXERCISE 5
python -m timeit -s "from Ft.Xml import Parse" -s "from itertools import chain" -s "doc = Parse(''.join(chain(['<a>'], [ '<b c=\'%i\'/>'%i for i in xrange($N) ], ['</a>'])))" "doc.xpath(u'//b[@c=\'10\']')"

Amara 2.0a2 on 2010-03-03 on a 2.53GHz MacBook Pro

Exercise

N

Amara 2.x core tree

Amara 2.x bindery

1

5000

8.50 msec

74.37 msec

2

5000

46.48 msec

45.87 msec

3

5000

1.32 msec

1.45 msec

4

5000

26.75 msec

123.26 msec

5

5000

49.25 msec

48.97 msec

versus 4Suite and Amara 1.2 on Webfaction, around 2009-02-12

Exercise

N

Amara 1.x

4Suite 1.x

Amara 2.x core tree

Amara 2.x bindery

1

5000

11400 msec

3.7 msec

3.9 msec

297 msec

2

5000

217 msec

376 msec

32.9 msec

33.5 msec

3

5000

87.6 msec

21.6 msec

1.35 msec

1.4 msec

4

5000

11800 msec

31.3 msec

22.7 msec

366 msec

5

5000

289 msec

141 msec

63.6 msec

65 msec

MacBookPro 17" plugged in, around 2009-02-12

Exercise

N

Amara 1.x

4Suite 1.x

Amara 2.x core tree

Amara 2.x bindery

1

5000

(untested)

5.53 msec

6 msec

581 msec

2

5000

(untested)

817 msec

71.8 msec

72.7 msec

3

5000

(untested)

27.2 msec

1.38 msec

1.7 msec

4

5000

(untested)

43.3 msec

22.8 msec

65000 msec

5

5000

(untested)

156 msec

67 msec

68.3 msec

MacBookPro 17" unplugged, around 2009-02-12

Exercise

N

Amara 1.x

4Suite 1.x

Amara 2.x core tree

Amara 2.x bindery

1

5000

(untested)

5.33 msec

5.99 msec

578 msec

2

5000

(untested)

790 msec

69.6 msec

73.7 msec

3

5000

(untested)

25.7 msec

1.4 msec

1.69 msec

Amara/Performance (last edited 2010-12-03 17:56:24 by LmMorillas)