cProfile output

Generate graph

gprof2dot -f pstats $profile_file | dot -Tpng -o $profile_graph
gnome-open $profile_graph

Profile output

         7925972 function calls (7360861 primitive calls) in 34.886 seconds

   Ordered by: internal time
   List reduced from 3516 to 25 due to restriction <25>

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
   166512    2.976    0.000   10.872    0.000 redbaron.py:792(_attribute_match_query)
   840415    2.745    0.000    3.928    0.000 redbaron.py:812(<genexpr>)
160557/24432    2.028    0.000   18.087    0.001 redbaron.py:636(find)
   942917    1.824    0.000    1.890    0.000 {built-in method isinstance}
   167913    1.802    0.000    5.739    0.000 {built-in method any}
   166512    1.747    0.000   13.625    0.000 redbaron.py:768(_node_match_query)
   584978    1.213    0.000    1.213    0.000 {method 'startswith' of 'str' objects}
   673903    1.183    0.000    1.183    0.000 redbaron.py:808(<lambda>)
    25972    1.154    0.000    4.512    0.000 <frozen importlib._bootstrap>:1993(find_spec)
        1    1.067    1.067    1.067    1.067 conftest.py:13(pytest_configure)
    89466    0.820    0.000    0.820    0.000 {built-in method stat}
   130170    0.796    0.000    2.310    0.000 <frozen importlib._bootstrap>:50(_path_join)
   130170    0.774    0.000    1.251    0.000 <frozen importlib._bootstrap>:52(<listcomp>)
   154286    0.725    0.000    1.065    0.000 _collections_abc.py:616(__iter__)
    76525    0.624    0.000    1.366    0.000 posixpath.py:71(join)
35492/11239    0.596    0.000   14.866    0.001 redbaron.py:661(<genexpr>)
280471/176433    0.584    0.000    9.586    0.000 {built-in method hasattr}
252633/58923    0.548    0.000   20.721    0.000 {built-in method getattr}
   261364    0.478    0.000    0.478    0.000 {method 'rstrip' of 'str' objects}
   167080    0.380    0.000    0.380    0.000 redbaron.py:964(_render)
       46    0.361    0.008    2.544    0.055 imp.py:255(find_module)
   154292    0.341    0.000    0.341    0.000 __init__.py:943(__getitem__)
   175182    0.320    0.000    0.320    0.000 {method 'lower' of 'str' objects}
    60717    0.316    0.000    0.874    0.000 genericpath.py:27(isfile)
    49231    0.313    0.000    0.577    0.000 redbaron.py:699(__len__)


   Ordered by: internal time
   List reduced from 3516 to 25 due to restriction <25>

Function                                       was called by...
                                                   ncalls  tottime  cumtime
redbaron.py:792(_attribute_match_query)        <-  166512    2.976   10.872  redbaron.py:768(_node_match_query)
redbaron.py:812(<genexpr>)                     <-     225    0.000    0.000  redbaron.py:792(_attribute_match_query)
                                                   840190    2.745    3.928  {built-in method any}
redbaron.py:636(find)                          <- 25511/24432    0.334   18.087  redbaron.py:306(find)
                                                47744/24963    0.554   10.431  redbaron.py:636(find)
                                                87302/37828    1.140   14.284  redbaron.py:661(<genexpr>)
{built-in method isinstance}                   <-     319    0.001    0.001  <frozen importlib._bootstrap>:654(_compile_bytecode)
                                                    32594    0.060    0.060  <frozen importlib._bootstrap>:1879(_get_spec)
                                                       66    0.000    0.000  <frozen importlib._bootstrap>:2164(_sanity_check)

Read profile

import sys

if len(sys.argv) == 2:
    filename = sys.argv[1]
else:
    filename = 'profile'

p = pstats.Stats(filename)
p.strip_dirs()
p.sort_stats('tottime')
p.print_stats(25)
p.print_callers(25)
p.print_callees(25)

Run test with profile

python3 -m cProfile -o $profile_file $(which py.test)