joerick/pyinstrument

🚴 Call stack profiler for Python. Shows you why your code is slow!

pyinstrument

Documentation

Pyinstrument is a Python profiler. A profiler is a tool to help you optimize your code - make it faster. To get the biggest speed increase you should focus on the slowest part of your program. Pyinstrument helps you find it!

☕️ Not sure where to start? Check out this video tutorial from calmcode.io!

Installation

pip install pyinstrument

Pyinstrument supports Python 3.7+.

To run Pyinstrument from a git checkout, there's a build step. Take a look at Contributing for more info.

Documentation

To learn how to use pyinstrument, or to check the reference, head to the documentation.

Known issues

• Profiling code inside a Docker container can cause some strange results, because the gettimeofday syscall that pyinstrument uses is slow in that environment. See #83
• When using pyinstrument script.py where script.py contains a class serialized with pickle, you might encounter errors because the serialisation machinery doesn't know where __main__ is. See this issue for workarounds

Changelog

v4.6.2

26 January 2024

• Fixes a bug with the pstats renderer, where additional frames could be seen in the output. (#287)
• Adds show_all option to Profiler.output_html

v4.6.1

8 November 2023

• Fixes a bug with unwanted variable expansion in the IPython magics %pyinstrument (#278)

v4.6.0

12 October 2023

• Adds a feature -c, which allows profiling code directly from the command line, like python -c. (#271)
• Adds a convenience method Profiler.write_html, for writing HTML output to a file directly. (#266)

v4.5.3

7 September 2023

• Fix a problem in the packaging process that prevented upload to PyPI

v4.5.2

1 September 2023

• Show the program name in the header of the HTML output (#260)
• Improve program name capture through resilience to other programs modifying sys.argv (#258)
• Add support for Python 3.12 (#246)

v4.5.1

22 July 2023

• Fix a bug that caused [X frames hidden] in the output when frames were deleted due to __tracebackhide__ (#255)
• Fix a bug causing built-in code to display the filepath None in the console output (#254)
• Some docs improvements (#251)

v4.5.0

5 June 2023

• Adds a flat mode to the console renderer, which can be enabled by passing -p flat on the command line. This mode shows the heaviest frame as measured by self-time, which can be useful in some codebases. (#240)
• Adds the ability to save pstats files. This is the file format used by cprofile in the stdlib. It's less detailed than pyinstrument profiles, but it's compatible with more tools. (#236)
• Fixes a detail of the --show-all option - pyinstrument will no longer remove Python-internal frames when this option is supplied. (#239)
• Internally to the HTML renderer, it now uses Svelte to render the frontend, meaning profile HTML files bundle less javascript and so are smaller. (#222)

v4.4.0

5 November 2022

• Adds the class name to methods in the console & HTML outputs (#203)
• Fix a bug that caused pyinstrument machinery to appear at the start of a profile (#215)
• Frames that set a __traceback_hide__ local variable will now be removed from the output (#217)
• Jupyter/IPython magic now supports async/await, if you run with a --async_mode=enabled flag. (#212)
• Fix a crash when more than one root frame is captured in a thread - this can happen with gevent.
• A big refactor to the backend, allowing more than just static information to be captured. This currently is just powering the class name feature, but more is to come!

v4.3.0

21 August 2022

• Adds buttons in the HTML output to switch between absolute and proportional (percentage) time.
• Adds a command line flag --interval (seconds, default 0.001) to change the interval that pyinstrument samples a program. This is useful for long-running programs, where increasing the interval reduces the memory overhead.
• Includes wheels for CPython 3.11.

v4.2.0

• Adds a command-line option -p --render-option that allows arbitrary setting of render options. This lets you set options like filter_threshold from the command line, by doing something like pyinstrument -p processor_options.filter_threshold=0.

  Here's the help output for the option:

    -p RENDER_OPTION, --render-option=RENDER_OPTION
                      options to pass to the renderer, in the format
                      'flag_name' or 'option_name=option_value'. For
                      example, to set the option 'time', pass '-p
                      time=percent_of_total'. To pass multiple options, use
                      the -p option multiple times. You can set processor
                      options using dot-syntax, like '-p
                      processor_options.filter_threshold=0'. option_value is
                      parsed as a JSON value or a string.
  

• Adds the ability to view times in the console output as percentages, rather than absolute times. Use the ConsoleRenderer option time='percent_of_total', or on the command line, use -p, like pyinstrument -p time=percent_of_total.

• Adds command line options for loading and saving pyinstrument sessions. You can save the raw data for a pyinstrument session with -r session, like pyinstrument -r session -o session.pyisession myscript.py. Loading is via --load, e.g. pyinstrument --load session.pyisession.

• Command line output format is inferred from the -o output file extension. So if you do pyinstrument -o profile.html myscript.py, you don't need to supply -r html, pyinstrument will automatically use the HTML renderer. Or if you do pyinstrument -o profile.pyisession myscript.py, it will save a raw session object.

• Adds usage examples for FastAPI and pytest to the documentation.

• Fixes a bug causing NotImplementedError when using async_mode=strict.

• Adds support for Python 3.11

v4.1.1

• Fixed an issue causing PYINSTRUMENT_PROFILE_DIR_RENDERER to output the wrong file extension when used with the speedscope renderer.

v4.1.0

• You can now use pyinstrument natively in an IPython notebook! Just use %load_ext pyinstrument at the top of your notebook, and then %%pyinstrument in the cell you want to profile.
• Added support for the speedscope format. This provides a way to view interactive flamecharts using pyinstrument. To use, profile with pyinstrument -r speedscope, and upload to the speedscope web app.
• You can now configure renderers for the Django middleware file output, using the PYINSTRUMENT_PROFILE_DIR_RENDERER option.
• Added wheels for Linux aarch64 (64-bit ARM).

v4.0.4

• Fix a packaging issue where a package called 'test' was installed alongside pyinstrument
• Use more modern C APIs to resolve deprecation warnings on Python 3.10.
• Minor docs fixes

v4.0.3

• CPython 3.10 support
• Improve error messages when trying to use Profiler from multiple threads
• Fix crash when rendering sessions that contain a module in a FrameGroup

v4.0.2

• Fix some packaging issues

v4.0.0

• Async support! Pyinstrument now detects when an async task hits an await, and tracks time spent outside of the async context under this await.

  So, for example, here's a simple script with an async task that does a sleep:

  import asyncio
  from pyinstrument import Profiler
  
  async def main():
      p = Profiler(async_mode='disabled')
  
      with p:
          print('Hello ...')
          await asyncio.sleep(1)
          print('... World!')
  
      p.print()
  
  asyncio.run(main())

  Before Pyinstrument 4.0.0, we'd see only time spent in the run loop, like this:

    _     ._   __/__   _ _  _  _ _/_   Recorded: 18:33:03  Samples:  2
   /_//_/// /_\ / //_// / //_'/ //     Duration: 1.006     CPU time: 0.001
  /   _/                      v3.4.2
  
  Program: examples/async_example_simple.py
  
  1.006 _run_once  asyncio/base_events.py:1784
  └─ 1.005 select  selectors.py:553
        [3 frames hidden]  selectors, <built-in>
           1.005 kqueue.control  <built-in>:0
  

  Now, with pyinstrument 4.0.0, we get:

    _     ._   __/__   _ _  _  _ _/_   Recorded: 18:30:43  Samples:  2
   /_//_/// /_\ / //_// / //_'/ //     Duration: 1.007     CPU time: 0.001
  /   _/                      v4.0.0
  
  Program: examples/async_example_simple.py
  
  1.006 main  async_example_simple.py:4
  └─ 1.005 sleep  asyncio/tasks.py:641
        [2 frames hidden]  asyncio
           1.005 [await]
  

  For more information, check out the async profiling documentation and the Profiler.async_mode property.

• Pyinstrument has a documentation site, including full Python API docs!

v3.4.2

• Fix a bug that caused --show, --show-regex, --show-all to be ignored on the command line.

v3.4.1

• Under-the-hood modernisation

v3.4.0

• Added timeline option (boolean) to Profiler methods output_html() and open_in_browser().

v3.3.0

• Fixed issue with pyinstrument -m module, where pyinstrument wouldn't find modules in the current directory.
• Dropped support for Python 2.7 and 3.5. Old versions will remain available on PyPI, and pip should choose the correct one automatically.

v3.2.0

• Added the ability to track time in C functions. Minor note - Pyinstrument will record time spent C functions as 'leaf' functions, due to a limitation in how Python records frames. Python -> C -> Python is recorded as Python -> Python, but Python -> Python -> C will be attributed correctly. (#103)

v3.1.2

• Fix <__array_function__ internals> frames appearing as app code in reports

v3.1.1

• Added support for timeline mode on HTML and JSON renderers
• Released as a tarball as well as a universal wheel

v3.1.0

• Added PYINSTRUMENT_SHOW_CALLBACK option on the Django middleware to add a condition to showing the profile (could be used to run pyinstrument on a live server!)
• Fixed bug in the Django middleware where file would not be written because of a unicode error

v3.0.3

• Fixed bug with the Django middleware on Windows where profiling would fail because we were trying to put an illegal character '?' in the profile path. (#66)

v3.0.2

• Add --show and --show-regex options, to mark certain files to be displayed. This helps to profile inside specific modules, while hiding others. For example, pyinstrument --show '*/sympy/*' script.py.

v3.0.1

• Fix #60: pass all arguments after -m module_name to the called module
• Fix crash during HTML/JSON output when no frames were captured.

v3.0.0

• Pyinstrument will now hide traces through libraries that you're using by default. So instead of showing you loads of frames going through the internals of something external e.g. urllib, it lets you focus on your code.

  Before	After

  To go back to the old behaviour, use --show-all on the command line.

• 'Entry' frames of hidden groups are shown, so you know which call is the problem

• Really slow frames in the groups are shown too, e.g. the 'read' call on the socket

• Application code is highlighted in the console

• Additional metrics are shown at the top of the trace - timestamp, number of samples, duration, CPU time

• Hidden code is controlled by the --hide or --hide-regex options - matching on the path of the code files.

    --hide=EXPR           glob-style pattern matching the file paths whose
                          frames to hide. Defaults to '*/lib/*'.
    --hide-regex=REGEX    regex matching the file paths whose frames to hide.
                          Useful if --hide doesn't give enough control.
  

• Outputting a timeline is supported from the command line.

    -t, --timeline        render as a timeline - preserve ordering and don't
                          condense repeated calls
  

• Because there are a few rendering options now, you can load a previous profiling session using --load-prev - pyinstrument keeps the last 10 sessions.

• Hidden groups can also call back into application code, that looks like this:

  

• (internal) When recording timelines, frame trees are completely linear now, allowing for the creation of super-accurate frame charts.

• (internal) The HTML renderer has been rewritten as a Vue.js app. All the console improvements apply to the HTML output too, plus it's interactive.

• (internal) A lot of unit and integration tests added!

Yikes! See #49 for the gory details. I hope you like it.

v2.3.0

• Big refactor!
  • Recorders have been removed. The frame recording is now internal to the Profiler object. This means the 'frame' objects are more general-purpose, which paves the way for...
  • Processors! These are functions that mutate the tree to sculpt the output. They are used by the renderers to filter the output to the correct form. Now, instead of a time-aggregating recorder, the profiler just uses timeline-style recording (this is lower-overhead anyway) and the aggregation is done as a processing step.
  • The upshot of this is that it's now way easier to alter the tree to filter stuff out, and do more advanced things like combining frames that we don't care about. More features to come that use this in v3.0!
• Importlib frames are removed - you won't see them at all. Their children are retained, so imports are just transparent.
• Django profile file name is now limited to a hundred of characters (#50)
• Fix bug with --html option (#53)
• Add --version command line option

v2.2.1

• Fix crash when using on the command line.

v2.2.0

• Added support for JSON output. Use pyinstrument --renderer=json scriptfile.py. PR

• @iddan has put together an interactive viewer using the JSON output!

  

• When running pyinstrument --html and you don't pipe the output to a file, pyinstrument will write the console output to a temp file and open that in a browser.

v2.1.0

• Added support for running modules with pyinstrument via the command line. The new syntax is the -m flag e.g. pyinstrument -m module_name! PR

v2.0.4

• Fix crashes due to multi-threaded use of pyinstrument. The fix is in the C extension, over at joerick/pyinstrument_cext#3

v2.0.3

• Pyinstrument can now be used in a with block.

  For example:

  profiler = pyinstrument.Profiler()
  with profiler:
      # do some work here...
  print(profiler.output_text())
  

• Middleware fix for older versions of Django

v2.0.2

• Fix for max recursion error when used to profile programs with a lot of frames on the stack.

v2.0.1

• Ensure license is included in the sdist.

v2.0.0

• Pyinstrument uses a new profiling mode. Rather than using signals, pyintrument uses a new statistical profiler built on PyEval_SetProfile. This means no more main thread restriction, no more IO errors when using Pyinstrument, and no need for a separate more 'setprofile' mode!

• Renderers. Users can customize Pyinstrument to use alternative renderers with the renderer argument on Profiler.output(), or using the --renderer argument on the command line.

• Recorders. To support other use cases of Pyinstrument (e.g. flame charts), pyinstrument now has a 'timeline' recorder mode. This mode records captured frames in a linear way, so the program execution can be viewed on a timeline.

v0.13

• pyinstrument command. You can now profile python scripts from the shell by running $ pyinstrument script.py. This is now equivalent to python -m pyinstrument. Thanks @asmeurer!

v0.12

• Application code is highlighted in HTML traces to make it easier to spot

• Added PYINSTRUMENT_PROFILE_DIR option to the Django interface, which will log profiles of all requests to a file the specified folder. Useful for profiling API calls.

• Added PYINSTRUMENT_USE_SIGNAL option to the Django interface, for use when signal mode presents problems.

Contributing

To setup a dev environment:

virtualenv --python=python3 env
. env/bin/activate
pip install --upgrade pip
pip install -r requirements-dev.txt
pre-commit install --install-hooks

To get some sample output:

pyinstrument examples/wikipedia_article_word_count.py

To run the tests:

pytest

To run linting checks locally:

pre-commit run --all-files

Some of the pre-commit checks, like isort or black, will auto-fix the problems they find. So if the above command returns an error, try running it again, it might succeed the second time :)

Running all the checks can be slow, so you can also run checks individually, e.g., to format source code that fails isort or black checks:

pre-commit run --all-files isort
pre-commit run --all-files black

To diagnose why pyright checks are failing:

pre-commit run --all-files pyright

The HTML renderer Vue.js app

The HTML renderer works by embedding a JSON representation of the sample with a Javascript 'bundle' inside an HTML file that can be viewed in any web browser.

To edit the html renderer style, do:

cd html_renderer
npm ci
npm run serve

When launched without a top-level window.profileSession object, it will fetch a sample profile so you can work with it.

To compile the JS app and bundle it back into the pyinstrument python tool:

bin/build_js_bundle.py [--force]

pyinstrument's Issues

How can i use it in windows?

Add a way to ignore modules in the output

It would be nice if there were a way to only show contributions from certain modules. Right now I'm getting a lot of noise in my output from nose since I'm profiling a set of unit tests. It would be nice if I could exclude traces that include nose and just see the timings for my code.

Perhaps this is me not understanding the purpose of the library - feel free to close if you don't agree that this is within the project scope.

Can't see any data regarding any raised exception

Thanks for this lib.
I tried to raise an exception manually to see if I can check it in the trace result, it looks like it doesn't show anything regarding that exception. it just says an error occurred, am I missing something?
Here's the configuration I'm using:

@app.before_request
def before_request():
    g.profiler = Profiler()
    g.profiler.start()

@app.after_request
def after_request(response):
    if not hasattr(g, "profiler"):
        return response
    g.profiler.stop()
    output_html = g.profiler.output_html()
    return make_response(output_html)

+1 suggestion, support web ui with Stand-alone mode.

I really impressed about django mode.
But I usually coded with stand-alone. But I envy the web ui :)
So would you add web ui without django feature?

Feature Request: JSON Renderer

Hey, I've seen on pervious discussion an idea mentioned to implement a JSON renderer.
How hard should it be?
How familiar should I be with the code base and underlying concepts to implement it?
Is it a desired feature in the library?
Awesome work

-m args

Is the module mode -m supporting args?

Add documentation for PYINSTRUMENT_PROFILE_DIR and PYINSTRUMENT_USE_SIGNAL

Python compiled extensions sampling with the gdb 7+ Python extensions

gdb makes it possible to get the backtrace of C programs with the bt command and since version 7, when the program is a Python program it's also possible to get the Python level call stack using the py-bt command, for instance see this post:

http://misspent.wordpress.com/2012/03/24/debugging-cc-and-cpython-using-gdb-7s-new-python-extension-support/

So it might be possible to use that to collect mixed Python + C call stacks every 10ms or so to profile inner call to C compiled extensions (e.g. Cython code) in a Python program when gdb is available on the system.

Also Pyrasite is using gdb to inject arbitrary Python code in a running Python process so it might also be possible to use a similar approach to attach the pyinstrument profiler to an existing running Python process.

Python 3 support

Any plans for Python 3 support?

Continuous segfaults

I am trying to use pyinstrument in a Django project and it's segfaulting in almost every page. In this case, every page is the html itself plus some API requests that are done from the page JavaScript to the same Django server.
I have managed to solve it adding a filter that allows me to profile only one of the requests. The code for the filter is in this commit: jredrejo@004a66c

The project I am profiling is https://github.com/learningequality/kolibri . I added the middleware setup at
https://github.com/learningequality/kolibri/blob/develop/kolibri/deployment/default/settings/base.py

The problem happens whenever PYINSTRUMENT_PROFILE_DIR is set, I need it to profile the api requests.

Maximum recursion depth with python 3.4

Hi,

Thanks for a great tool! I get a maximum recursion depth when running pyinstrument with python 3.4.3, but it completes fine with 2.7.9. Full error log below.

I have these versions for both python 3.4.3 and 2.7.9

pyinstrument (2.0.0)
pyinstrument-cext (0.1.2)

Traceback (most recent call last):
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/runpy.py", line 170, in _run_module_as_main
    "__main__", mod_spec)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/runpy.py", line 85, in _run_code
    exec(code, run_globals)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/__main__.py", line 138, in <module>
    main()
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/__main__.py", line 101, in main
    f.write(profiler.output(renderer=renderer, **renderer_kwargs))
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/profiler.py", line 93, in output
    return renderer.render(self.starting_frame(root=root))
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/profiler.py", line 82, in starting_frame
    return self.first_interesting_frame()
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/profiler.py", line 69, in first_interesting_frame
    while len(frame.children) <= 1:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 74, in time
    for child in self.children:
  File "/Users/kxs624/.pyenv/versions/3.4.3/lib/python3.4/site-packages/pyinstrument/frame.py", line 138, in children
    self._children = sorted(unsorted_children, key=methodcaller('time'), reverse=True)
RuntimeError: maximum recursion depth exceeded while calling a Python object

Re-introduce support for the EventProfiler

Hey Joe,

Thank you for this great little library. I and my colleague find it extremely useful.

The other day, I added configurable support for profiling of all requests on our TurboGears 2-based Web app using your pyinstrument.Profiler. However, when I redployed my development environment, the profiling feature broke. After some investigation I realize it's because we used the EventProfiler, and the new StatProfiler doesn't work (always raising the NotMainThreadError).

I'm stuck using your 69e0d9d commit, and therefore wonder if you could consider re-introducing the EventProfiler?

error in pypy

I got this error when trying to profile a script using pyinstrument in pypy

ImportError: /home/xxxxxxx/.virtualenvs/pypy/site-packages/pyinstrument_cext.pypy3-60-x86_64-linux-gnu.so: undefined symbol: PyFrame_LocalsToFast

Profiling Cython functions

I noticed that even when using the @cython.profile decorator, Cython functions don't show up in the call stack. Is there any way to add support for Cython?

Feature Request: pstats output

One thing that would be very useful is to be able to produce output from pyinstrument in a Python pstats file. That would allow it to, for example, be passed to gprof2dot to produce a call-graph tree. It looks like the file format is pretty simple -- some data in a dictionary gets dumped using marshal.dump (see here).

Literally just want to thank you.

What an incredible package. You clearly put a lot of care and forethought into the design, particularly w.r.t. the plug-ability with Django (which, by the way, is a HUGE lifesaver when dealing with unwieldy ORM issues!) and presentation of statistical profiling metrics. Just, wow.

A round of applause to @joerick !

feature request: dump and analyze

It is cool to print beautiful callstacks after we stop the profiler and call output_text/html. However, this only gives users one angle to look at data: full-depth (the whole callstack is printed) and caller-based (caller are parents, and callee functions are children on the tree).

In many cases, it is useful if we can analyze the same profiling data from different angles. For example:

(1) callee-based: for development in a big software framework, new functions are part of the framework, and are often at the bottom or at most in the middle of the call stack. If the profiler can only print callstack as caller-based, it would take a lot of time to find the data people care about.

(2) reduced callstack depth:if I only want a big picture, I may want to filter the results with an option like "depth=1" or "depth=2" etc, to print only functions at the top or bottom of the callstack. This option should work in either caller-based or callee-based
stack. I know in web UI, the stack tree and fold and expand so it doesn't have to be changed, but the text mode doesn't have this option, and if we want to generate reports, we need to process text output.

In order to do this, we might want to separate result display into two steps. Step1: dump the data. Step 2: process the data.

Step 1 conceptually works as it does now: when profiler is stopped, it "dump" profiling data into a user specified or default file name.

Step 2: this requires a new tool that can understand the dump and display callstacks as a user desires.

So the point is to give users more angles to analyze without having to profile the same application multiple times.

Any thoughts?

Cannot import Profile (DLL failed)

Getting following stacktrace running python2:

  File "C:\xplanbase\version\99.99.999\src\py\xpt\resourceful\api\portfolio\modelling.py", line 571, in __call__
    from pyinstrument import Profiler
  File "C:\Python27\lib\site-packages\pyinstrument\__init__.py", line 1, in <module>
    from pyinstrument.profiler import Profiler
  File "C:\Python27\lib\site-packages\pyinstrument\profiler.py", line 8, in <module>
    from pyinstrument_cext import setstatprofile
ImportError: DLL load failed: The specified module could not be found.

I have
pyinstrument==2.1.1
pyinstrument-cext==0.2.0

Add an entry-point

It would be nice to have a simple bin/pyinstrument (which also gets installed), so that you don't have to run python -m.

BUG: continuous sampling, multiple threads

1. great project, thank you.

2. this project works fine for short single-thread sessions, such as flask request
   https://github.com/joerick/pyinstrument/blob/master/examples/flask_hello.py

3. this project does not work for long running applications with continuous sampling and with multiple threads, due to:

• there is no provision for per-thread setprofile in profiler.py as required by threading.setprofile()
• there will be a guaranteed out-memory due to unbounded queue in profiler.py
• there is no support for multiple call stack roots
• there is no easy way to extract session data without profiler.stop()

4. here is proof-of-concept implementation, which addresses some of these limitations:
   https://gist.github.com/Andrei-Pozolotin/34a4a4f4e1cadf7893f9eecf695def2a

• same stats bean is used for both sampling and rendering
• sampling is activated for both main thread and every extra thread
• samples are stored in bounded map
• stats can be updated on demand from separate thread
• rendering does not affect sampling or stats updaing

5. perhaps you could incorporate some of these ideas in the next release :-)

Profiling with multiprocessing

Is there any support for profiling multiple processes? Right now profiling code that uses multiprocessing gives me eg.

40.909 update_basketball_events_db  db_updater/events.py:38
└─ 40.855 map  multiprocessing/pool.py:261
   └─ 40.855 get  multiprocessing/pool.py:637
      └─ 40.855 wait  multiprocessing/pool.py:634
         └─ 40.855 wait  threading.py:533
            └─ 40.855 wait  threading.py:263

Timeline flag -t is not recognized as keyword argument

I'm trying to run pyinstrument with the -t flag but i'm getting this error:

pyinstrument -t -r html my_script.py

-packages\pyinstrument\__main__.py", line 177, in main renderer = renderer_class(**renderer_kwargs) TypeError: __init__() got an unexpected keyword argument 'timeline'

pyinstrument is very slow on django tests with docker

Dear,

I'm trying to use pyinstrument on docker with a django test setup. When I run the command like this ./manage.py test --keepdb services.rest.tests.test_views:AddCompanyTestCase.test_add_company -v 3 I get something like

240.152 <module>  manage.py:2
└─ 239.407 execute_from_command_line  django/core/management/__init__.py:378
      [23227 frames hidden]  django, django_nose, nose, unittest, ...
         48.646 patched  mock/mock.py:1314
         └─ 48.625 test_add_company  services/rest/tests/test_views.py:59
            ├─ 21.667 post  rest_framework/test.py:296
            │     [770 frames hidden]  rest_framework, django, reversion, se...
            │        21.055 inner  django/core/handlers/exception.py:31
            │        └─ 21.055 __call__  company/middleware.py:28
            │           └─ 21.036 inner  django/core/handlers/exception.py:31
            │              └─ 21.036 __call__  project/middleware.py:10
            │                 └─ 21.036 inner  django/core/handlers/exception.py:31
            │                       [106 frames hidden]  django, rest_framework, re, sre_compi...
            │                          20.995 dispatch  rest_framework/views.py:470
            │                          └─ 20.982 post  services/rest/views.py:813
            │                             └─ 20.851 save  rest_framework/serializers.py:171
            │                                └─ 20.851 create  services/rest/serializers.py:279
            │                                   ├─ 9.561 __get__  django/db/models/fields/related_descriptors.py:373
            │                                   │     [72 frames hidden]  django, raven, weakref
            │                                   ├─ 6.187 now  django/utils/timezone.py:218
            │                                   │     [2 frames hidden]  django
            │                                   └─ 4.289 [self]
            ├─ 19.563 reverse  django/urls/base.py:27
            │     [718 frames hidden]  django, re, sre_compile, sre_parse, e...
            │        4.988 import_module  importlib/__init__.py:109
            │        └─ 4.972 <module>  project/urls.py:1
            └─ 7.285 generate  project/generators.py:151
               └─ 7.281 _make_user  project/generators.py:64
                  ├─ 3.613 _make_username  project/generators.py:54
                  │  └─ 3.612 _make_wordlist  project/generators.py:47
                  │     └─ 3.612 <listcomp>  project/generators.py:49
                  │        └─ 3.602 [self]
                  └─ 3.368 _make_wordlist  project/generators.py:47
                     └─ 3.368 <listcomp>  project/generators.py:49
                        └─ 3.344 [self]
         9.312 load_source  imp.py:165
         └─ 9.291 <module>  services/rest/tests/test_views.py:2
            └─ 4.866 <module>  services/rest/serializers.py:1
               └─ 3.759 <module>  dictdiffer/__init__.py:11
                     [327 frames hidden]  dictdiffer, pkg_resources, re, posixp...
         40.742 import_module  importlib/__init__.py:109
         ├─ 28.759 <module>  shareholder/models.py:1
         │  ├─ 22.735 UserProfile  shareholder/models.py:1117
         │  │  └─ 22.726 __init__  django_languages/fields.py:7
         │  │        [11 frames hidden]  django_languages, django
         │  └─ 2.528 <module>  utils/pdf.py:1
         │     └─ 2.511 <module>  xhtml2pdf/pisa.py:16
         │           [1405 frames hidden]  xhtml2pdf, reportlab, re, sre_compile...
         47.142 import_module  importlib/__init__.py:109
         └─ 47.118 <module>  project/__init__.py:5
            ├─ 39.173 <module>  project/signals.py:4
            │  ├─ 25.066 <module>  registration/signals.py:1
            │  │     [26 frames hidden]  registration, django, importlib, path...
            │  │        25.032 import_module  importlib/__init__.py:109
            │  │        └─ 24.990 <module>  project/settings/dev.py:1
            │  │           └─ 24.953 <module>  project/settings/base.py:12
            │  │              ├─ 19.513 <module>  project/settings/tests.py:4
            │  │              │  └─ 19.512 stack  inspect.py:1511
            │  │              │        [278 frames hidden]  inspect, posixpath, genericpath, cele...
            │  │              └─ 4.018 <module>  raven/__init__.py:7
            │  │                    [951 frames hidden]  raven, requests, urllib3, re, sre_com...
            │  ├─ 8.870 <module>  services/slack.py:3
            │  │  └─ 8.728 register_task  celery/app/base.py:488
            │  │        [319 frames hidden]  celery, kombu, collections, logging, ...
            │  │           8.552 send  celery/utils/dispatch/signal.py:266
            │  │           └─ 8.550 setup_periodic_tasks  project/celery.py:32
            │  │              └─ 8.360 <module>  company/tasks.py:9
            │  │                 └─ 6.836 <module>  bs4/__init__.py:18
            │  │                       [3025 frames hidden]  bs4, soupsieve, re, sre_compile, sre_...
            │  └─ 5.143 <module>  django/contrib/auth/__init__.py:1
            │        [2516 frames hidden]  django, pathlib, re, sre_compile, sre...
            └─ 7.762 <module>  project/celery.py:6
               └─ 6.292 <module>  celery/schedules.py:2
                     [1914 frames hidden]  celery, kombu, importlib_metadata, re...

where even now takes 6s. Without pyinstrument this test takes about ~30s and I need to find out why...

What other information do you need from my side?

AssertionError when use flask+gunicorn+gevent

Hai ! I encount this AssertionError when I use pyinstrument to hook my flask app like the examples/flask_hello.py said.

AssertionError: Please raise an issue at http://github.com/pyinstrument/issues and let me know how you caused this error!

This error doesn't happen every time I send request. Instead, several consecutive requests occur once. Then Nginx will return 500 status code.

Here is the full trackback stack from gunicorn error.log file:

[2020-01-22 04:34:28 +0800] [26251] [ERROR] Error handling request /v2/services/xxxx/xxxx/get?key1=value1&key2=value2&key3=value3&__profile__
Traceback (most recent call last):
  File "/home/pyserver/.pyenv/versions/3.6.6/envs/envpy36/lib/python3.6/site-packages/gunicorn/workers/base_async.py", line 55, in handle
    self.handle_request(listener_name, req, client, addr)
  File "/home/pyserver/.pyenv/versions/3.6.6/envs/envpy36/lib/python3.6/site-packages/gunicorn/workers/ggevent.py", line 143, in handle_request
    super().handle_request(listener_name, req, sock, addr)
  File "/home/pyserver/.pyenv/versions/3.6.6/envs/envpy36/lib/python3.6/site-packages/gunicorn/workers/base_async.py", line 106, in handle_request
    respiter = self.wsgi(environ, resp.start_response)
  File "/home/pyserver/.pyenv/versions/3.6.6/envs/envpy36/lib/python3.6/site-packages/flask/app.py", line 2463, in __call__
    return self.wsgi_app(environ, start_response)
  File "/home/pyserver/.pyenv/versions/3.6.6/envs/envpy36/lib/python3.6/site-packages/werkzeug/middleware/proxy_fix.py", line 228, in __call__
    return self.app(environ, start_response)
  File "/home/pyserver/.pyenv/versions/3.6.6/envs/envpy36/lib/python3.6/site-packages/flask/app.py", line 2449, in wsgi_app
    response = self.handle_exception(e)
  File "/home/pyserver/.pyenv/versions/3.6.6/envs/envpy36/lib/python3.6/site-packages/flask/app.py", line 1866, in handle_exception
    reraise(exc_type, exc_value, tb)
  File "/home/pyserver/.pyenv/versions/3.6.6/envs/envpy36/lib/python3.6/site-packages/flask/_compat.py", line 39, in reraise
    raise value
  File "/home/pyserver/.pyenv/versions/3.6.6/envs/envpy36/lib/python3.6/site-packages/flask/app.py", line 2446, in wsgi_app
    response = self.full_dispatch_request()
  File "/home/pyserver/.pyenv/versions/3.6.6/envs/envpy36/lib/python3.6/site-packages/flask/app.py", line 1952, in full_dispatch_request
    return self.finalize_request(rv)
  File "/home/pyserver/.pyenv/versions/3.6.6/envs/envpy36/lib/python3.6/site-packages/flask/app.py", line 1969, in finalize_request
    response = self.process_response(response)
  File "/home/pyserver/.pyenv/versions/3.6.6/envs/envpy36/lib/python3.6/site-packages/flask/app.py", line 2266, in process_response
    response = handler(response)
  File "/home/pyserver/www/wsgi.py", line 44, in after_request
    output_html = g.profiler.output_html()
  File "</home/pyserver/.pyenv/versions/3.6.6/envs/envpy36/lib/python3.6/site-packages/pyinstrument/vendor/decorator.py:decorator-gen-9>", line 2, in output_html
  File "/home/pyserver/.pyenv/versions/3.6.6/envs/envpy36/lib/python3.6/site-packages/pyinstrument/util.py", line 37, in caller
    return func(*args, **kwargs)
  File "/home/pyserver/.pyenv/versions/3.6.6/envs/envpy36/lib/python3.6/site-packages/pyinstrument/profiler.py", line 101, in output_html
    return renderers.HTMLRenderer().render(self.last_session)
  File "/home/pyserver/.pyenv/versions/3.6.6/envs/envpy36/lib/python3.6/site-packages/pyinstrument/renderers/html.py", line 23, in render
    session_json = self.render_json(session)
  File "/home/pyserver/.pyenv/versions/3.6.6/envs/envpy36/lib/python3.6/site-packages/pyinstrument/renderers/html.py", line 69, in render_json
    return json_renderer.render(session)
  File "/home/pyserver/.pyenv/versions/3.6.6/envs/envpy36/lib/python3.6/site-packages/pyinstrument/renderers/jsonrenderer.py", line 36, in render
    frame = self.preprocess(session.root_frame())
  File "/home/pyserver/.pyenv/versions/3.6.6/envs/envpy36/lib/python3.6/site-packages/pyinstrument/session.py", line 77, in root_frame
    assert root_frame is None, ASSERTION_MESSAGE
AssertionError: Please raise an issue at http://github.com/pyinstrument/issues and let me know how you caused this error!

Here is my gunicorn.conf.py file

import os
import multiprocessing

chdir = WSGI_APP_ROOT

daemon = True
accesslog = os.path.join(LOG_DIR, "access.log")
errorlog  = os.path.join(LOG_DIR, "error.log")

pidfile = os.path.join(RUN_DIR, "gunicorn.pid")

user  = 33  # www-data
group = 33  # www-data

bind = [ "unix:" + os.path.join(RUN_DIR, "gunicorn.sock") ]

workers = multiprocessing.cpu_count() * 2 + 1
worker_class = "gevent"
worker_connections = 1024
threads = multiprocessing.cpu_count() * 3 

timeout = 15
graceful_timeout = 15
keepalive = 5

Here is my wsgi.py module

PYINSTRUMENT_HOOK          = True
PYINSTRUMENT_PROFILE_FIELD = "__profile__"

from gevent.monkey import patch_all
patch_all()

import os
from werkzeug.middleware.proxy_fix import ProxyFix
from v2.app import create_app

app = create_app("development")

if PYINSTRUMENT_HOOK:

    from flask import g, request, make_response
    from pyinstrument import Profiler

    @app.before_request
    def before_request():
        if PYINSTRUMENT_PROFILE_FIELD in request.args:
            g.profiler = Profiler()
            g.profiler.start()

    @app.after_request
    def after_request(response):
        if not hasattr(g, "profiler"):
            return response
        g.profiler.stop()
        output_html = g.profiler.output_html()
        return make_response(output_html)

app.wsgi_app = ProxyFix(app.wsgi_app, x_for=1)

The requirements.txt

Flask==1.1.1
Werkzeug==0.15.4 
greenlet==0.4.15
gevent==1.4.0
gunicorn==20.0.4
pyinstrument==3.1.0

The pyenv version

Python 3.6.6

Useful frames hidden

I am trying to profile some SymPy code. However, the output hides all the useful information in "hidden frames".

# test.py
from sympy import symbols, Min
x = symbols('x:50')
Min(*x)

  _     ._   __/__   _ _  _  _ _/_   Recorded: 23:10:12  Samples:  2312
 /_//_/// /_\ / //_// / //_'/ //     Duration: 3.560     CPU time: 3.540
/   _/                      v3.0.1

Program: test.py

3.559 <module>  test.py:1
├─ 3.062 __new__  sympy/functions/elementary/miscellaneous.py:341
│     [1798 frames hidden]  sympy, random
└─ 0.497 <module>  sympy/__init__.py:12
      [751 frames hidden]  sympy, inspect, enum, re, collections...

To view this report with different options, run:
    pyinstrument --load-prev 2019-03-14T23-10-12 [options]

redis-py while profiling results in ConnectionError

With python 3.6.3, redis 2.10.6 and the pyinstrument currently on pypi, I get a ConnectionError when connecting to redis while the profiler is running. Reproducer:

import redis
from pyinstrument import Profiler

_redis = redis.StrictRedis(...)
_redis.get('foo')
print('Works')

profiler = Profiler()
profiler.start()
_redis = redis.StrictRedis(...)
_redis.get('foo')
print('Fails')

Traceback

Traceback (most recent call last):
  File "/Users/matt/us-research/env/lib/python3.6/site-packages/redis/connection.py", line 484, in connect
    sock = self._connect()
  File "/Users/matt/us-research/env/lib/python3.6/site-packages/redis/connection.py", line 541, in _connect
    raise err
  File "/Users/matt/us-research/env/lib/python3.6/site-packages/redis/connection.py", line 529, in _connect
    sock.connect(socket_address)
OSError: [Errno 22] Invalid argument

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/Users/matt/us-research/env/lib/python3.6/site-packages/redis/client.py", line 667, in execute_command
    connection.send_command(*args)
  File "/Users/matt/us-research/env/lib/python3.6/site-packages/redis/connection.py", line 610, in send_command
    self.send_packed_command(self.pack_command(*args))
  File "/Users/matt/us-research/env/lib/python3.6/site-packages/redis/connection.py", line 585, in send_packed_command
    self.connect()
  File "/Users/matt/us-research/env/lib/python3.6/site-packages/redis/connection.py", line 489, in connect
    raise ConnectionError(self._error_message(e))
redis.exceptions.ConnectionError: Error 22 connecting to 35.195.188.81:6379. Invalid argument.

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/Users/matt/us-research/env/lib/python3.6/site-packages/redis/connection.py", line 484, in connect
    sock = self._connect()
  File "/Users/matt/us-research/env/lib/python3.6/site-packages/redis/connection.py", line 541, in _connect
    raise err
  File "/Users/matt/us-research/env/lib/python3.6/site-packages/redis/connection.py", line 529, in _connect
    sock.connect(socket_address)
OSError: [Errno 22] Invalid argument

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "test.py", line 22, in <module>
    _redis.get('foo')
  File "/Users/matt/us-research/env/lib/python3.6/site-packages/redis/client.py", line 976, in get
    return self.execute_command('GET', name)
  File "/Users/matt/us-research/env/lib/python3.6/site-packages/redis/client.py", line 673, in execute_command
    connection.send_command(*args)
  File "/Users/matt/us-research/env/lib/python3.6/site-packages/redis/connection.py", line 610, in send_command
    self.send_packed_command(self.pack_command(*args))
  File "/Users/matt/us-research/env/lib/python3.6/site-packages/redis/connection.py", line 585, in send_packed_command
    self.connect()
  File "/Users/matt/us-research/env/lib/python3.6/site-packages/redis/connection.py", line 489, in connect

Getting IOError

rahul@rahul-desktop { ~/pycharm-workspace/ceres_new }-> python -m pyinstrument ceres/sim/sim_definition.py
Traceback (most recent call last):
File "/usr/lib/python2.7/runpy.py", line 162, in run_module_as_main
"main", fname, loader, pkg_name)
File "/usr/lib/python2.7/runpy.py", line 72, in run_code
exec code in run_globals
File "/home/rahul/src/pyinstrument/pyinstrument/main.py", line 135, in
main()
File "/home/rahul/src/pyinstrument/pyinstrument/main.py", line 79, in main
exec(code, globs, None)
File "/home/rahul/src/pyinstrument/pyinstrument/main.py", line 25, in exec
exec("exec code in globs, locs")
File "", line 1, in
File "ceres/sim/sim_definition.py", line 48, in
main()
File "ceres/sim/sim_definition.py", line 31, in main
from aglyph.assembler import Assembler
File "/usr/local/lib/python2.7/dist-packages/aglyph/init.py", line 61, in
platform.platform()))
File "/usr/lib/python2.7/platform.py", line 1576, in platform
system,node,release,version,machine,processor = uname()
File "/usr/lib/python2.7/platform.py", line 1273, in uname
processor = _syscmd_uname('-p','')
File "/usr/lib/python2.7/platform.py", line 1029, in _syscmd_uname
output = string.strip(f.read())
IOError: [Errno 4] Interrupted system call
Alarm clock

Add a way to screen out importlib noise

I often use pyinstrument to profile importing a module to figure out ways to speed up imports. On python2 this works very nice but on python3 pyinstrument will pick up frames from importlib, making it much harder to visually see what's happening in the pyinstrument profile. This is happening because importlib was rewritten from C to python in python3, so pyinstrument is able to capture stack frames from it in python3.

To make that concrete, here's the profile for "import sympy" generated under python2:

https://gist.github.com/ngoldbaum/3e2f5213b45a64f67167d0dbd5878ad5

and python3:

https://gist.github.com/ngoldbaum/fb46b92f22a65181aa7442e2af2f51c1

UnicodeEncodeError when writing html

- - - [2019-11-13 05:17:27,813] "- - -" - [ERROR:django.request:256] Internal Server Error: /api/v1/logout
Traceback (most recent call last):
  File "/Users/anand/.local/share/virtualenvs/avilpage-pc50wcPX/lib/python2.7/site-packages/django/core/handlers/base.py", line 223, in get_response
    response = middleware_method(request, response)
  File "/Users/anand/.local/share/virtualenvs/avilpage-pc50wcPX/lib/python2.7/site-packages/pyinstrument/middleware.py", line 53, in process_response
    f.write(output_html)
UnicodeEncodeError: 'ascii' codec can't encode character u'\xa0' in position 87794: ordinal not in range(128)
[13/Nov/2019 05:17:27] "POST /api/v1/logout HTTP/1.1" 500 95880

When adding middleware to django and writing html to profiles directory, it is failing with unicode encode error.

OSError: [Errno 36] File name too long

When using ProfilerMiddleware (pyinstrument 2.2.1) with Django (1.11.9), when profiling view related to an API endpoint that accepts very long GET querystring, I get the following error:

Traceback (most recent call last):
  File "/home/laurent/.pyenv/versions/my_app/lib/python3.6/site-packages/django/core/handlers/base.py", line 131, in get_response
    response = middleware_method(request, response)
   File "/home/laurent/.pyenv/versions/my_app/lib/python3.6/site-packages/pyinstrument/middleware.py", line 43, in process_response
    with open(file_path, 'w') as f:
OSError: [Errno 36] File name too long: 'profiles/2.279s _api_v1_translations_?word=comes&orig...[A_VERY_LONG_QUERYSTRING]'

I guess that the profile file name length could be truncated at some point in this module code.

HTML navigation with arrow keys

Is it possible to allow navigation of the html pages with the arrow keys, with up and down selecting up and down and left and right closing and opening the items?

Better Unicode detection

My terminal supports Unicode, but pyinstrument doesn't use it.

SymPy's Unicode detection seems to be pretty robust (there are tons of users, and the only error reports about misusing Unicode when it isn't supported that I notice are from non-Terminals). It seems to be a combination of doing a unicodedata lookup and trying sys.stdout.encode. I also don't know if it makes sense to restrict unicode output to ttys. That generally only matters for colors, because the ANSI escape sequences might not be interpreted otherwise, and will just clutter the output.

The code's all BSD, so feel free to reuse it.

Error running from master

I get this error trying to run pyinstrument from master

Traceback (most recent call last):
  File "/Users/aaronmeurer/anaconda3/lib/python3.5/runpy.py", line 193, in _run_module_as_main
    "__main__", mod_spec)
  File "/Users/aaronmeurer/anaconda3/lib/python3.5/runpy.py", line 85, in _run_code
    exec(code, run_globals)
  File "/Users/aaronmeurer/Documents/pyinstrument/pyinstrument/__main__.py", line 274, in <module>
    main()
  File "/Users/aaronmeurer/Documents/pyinstrument/pyinstrument/__main__.py", line 160, in main
    f.write(renderer.render(session))
  File "/Users/aaronmeurer/Documents/pyinstrument/pyinstrument/renderers/html.py", line 11, in render
    with io.open(os.path.join(resources_dir, 'app.js'), encoding='utf-8') as f:
FileNotFoundError: [Errno 2] No such file or directory: '/Users/aaronmeurer/Documents/pyinstrument/pyinstrument/renderers/html_resources/app.js'

Is there a file that isn't checked in, or do I need to do some kind of build?

Allow using `Profiler` as context manager

Version 2.0.1 can't import the top level package.

See:

moorepants@garuda:pyinstrument((v2.0.1))$ python -c "import pyinstrument"
Traceback (most recent call last):
  File "<string>", line 1, in <module>
  File "/home/moorepants/src/pyinstrument/pyinstrument/__init__.py", line 1, in <module>
    from pyinstrument.profiler import Profiler
  File "/home/moorepants/src/pyinstrument/pyinstrument/profiler.py", line 8, in <module>
    from pyinstrument_cext import setstatprofile
ImportError: No module named 'pyinstrument_cext'

Note that this was picked up on the conda-forge build: conda-forge/pyinstrument-feedstock#6

Feature request: aggregating output

First of all, thank you for writing this profiler. The visuals are nice, the information is (almost) exactly what I need, and Django integration is easy (as is using it in any other project).

However, I'm trying to get one thing to work, which I haven't been able to yet: aggregating the output data. Currently, I get a pyinstrument html file for every request that is sent to Django, but I'm also interested in the aggregation of all the requests. Is that something that can be made and would you consider accepting a pull request for this?

One possible way I think is to support pstats output, as someone requested in this issue.

Write some tests

No open source project should be without tests. We need to get a test suite in here, but I'm not personally very experienced with writing tests, and I'm unsure how to test pyinstrument!

My main sticking point is that the output isn't deterministic, so we can't check that the output is equal to what we expect.

Does anybody have any ideas about how to test this?

PyPI

It would be great if you could upload this to PyPI.

License?

What is the license of this code? I couldn't find it anywhere.

Feature Request: Attach & detach to a running process

I'd like to be able to run a long time process (for instance a server), attach to it, trace the calls, detach from it and get the frame timings.

Tarball release on PyPI?

Hi, would it be possible to add tarball releases on PyPI? I'm trying to write a package for pyinstrument for the Spack package manager, but the GitHub tarball requires npm to install from source, and I'm having a hell of a time getting npm installed using Python 3. Could you add a tarball on PyPI that doesn't require npm to install from source?

@tgamblin

Failed output_html on Flask app

get the error:

Please raise an issue at http://github.com/pyinstrument/issues and let me know how you caused this error!

my app.py:

from flask import Flask, g, make_response, request 
from pyinstrument import Profiler

....
@app.before_request                                                                                                                                                                                                                                                             
def before_request():                                                                                                                                                                                                                                                           
    request.start_time = time.time() // old naive timings wanting to replace with pyinstrument
    if "profile" in request.args:                                                                                                                                                                                                                                               
        g.profiler = Profiler()                                                                                                                                                                                                                                                 
        g.profiler.start()                                                                                                                                                                                                                                                      
                                                                                                                                                                                                                                                                                
@app.after_request                                                                                                                                                                                                                                                              
def after_request(response):                                                                                                                                                                                                                                                    
    request_latency = time.time() - request.start_time                                                                                                                                                                                                                          
    latency_microseconds = request_latency / 1000000                                                                                                                                                                                                                            
                                                                                                                                                                                                                                                                          
    response.headers['X-Container'] = settings.HOSTNAME                                                                                                                                                                                   
                                                                                                                                                                                                                                                                                
    if not hasattr(g, "profiler"):                                                                                                                                                                                                                                              
        return response                                                                                                                                                                                                                                                                              
                                                                                                                                                                                                                                                                                
    profiler_session = g.profiler.stop()                                                                                                                                                                                                                                        
    try:                                                                                                                                                                                                                                                                        
        output_html = g.profiler.output_html()                                                                                                                                                                                                                                  
    except Exception as e:                                                                                                                                                                                                                                                      
        print('error')                                                                                                                                                                                                                                                          
        print(e)                                                                                                                                                                                                                                                                
    return make_response(output_html)

Let me know what other additional information you need!

--html producing terminal output

I am using

python -m pyinstrument --html -o test.html test.py

test.html contains the terminal formatted output, not the HTML.

Update README to reflect signal=False usage

This allows environments that can't use signal to use pyinstrument (Windows, secondary thread)

Renderer doesn't work.

tested on windows10, python3.6.6 pyinstrument2.30

"--html, -r json, -r html " doesn't work.

And， --output file doesn't work either.

Provide a warning when time is likely spent in another thread

pyinstrument only records one thread at a time. However, due to the GIL, the performance of one thread could be affected by a different active thread in the same program.

Python can now give CPU time per-thread:

• https://docs.python.org/3/library/time.html#time.thread_time
• https://docs.python.org/3/library/time.html#time.clock_gettime

This could be compared with the program CPU time - if the current thread is less than 80% of the program's CPU time, it's likely that that other thread was slowing the profiled one down - this should be communicated in pyinstrument's output.

It would be even better if we could track the time spent inside the GIL (and even subtract it), but I'm not sure how to do that!

Running modules

I'd like to trace a program requiring execution with python -m. How should I do it? I know Python 3.7 has introduced support for it in some of the script executing modules.

RuntimeError: maximum recursion depth exceeded

Since upgrading from rev. 69e0d9d and using the EventProfiler, we now often (i.e. mostly, but not every time) get a RuntimeError when tracing. Here's a stack trace.

Traceback (most recent call last):
  File "/Users/dagh/Documents/Jobb/onlive/tg2env/lib/python2.7/site-packages/tg/support/registry.py", line 247, in __call__
    app_iter = self.application(environ, start_response)
  File "/Users/dagh/Documents/Jobb/onlive/tg2env/lib/python2.7/site-packages/tg/support/middlewares.py", line 65, in __call__
    status, headers, app_iter, exc_info = _call_wsgi_application(self.app, environ)
  File "/Users/dagh/Documents/Jobb/onlive/tg2env/lib/python2.7/site-packages/tg/support/middlewares.py", line 20, in _call_wsgi_application
    app_iter = application(environ, _start_response)
  File "/Users/dagh/Documents/Jobb/onlive/tg2env/lib/python2.7/site-packages/tg/support/middlewares.py", line 130, in __call__
    return self._stream_response(self.app(environ, start_response))
  File "/Users/dagh/Documents/Jobb/onlive/tg2env/lib/python2.7/site-packages/tw/core/middleware.py", line 46, in __call__
    return self.wsgi_app(environ, start_response)
  File "/Users/dagh/Documents/Jobb/onlive/tg2env/lib/python2.7/site-packages/tw/core/middleware.py", line 72, in wsgi_app
    resp = req.get_response(self.application)
  File "/Users/dagh/Documents/Jobb/onlive/tg2env/lib/python2.7/site-packages/webob/request.py", line 1296, in send
    application, catch_exc_info=False)
  File "/Users/dagh/Documents/Jobb/onlive/tg2env/lib/python2.7/site-packages/webob/request.py", line 1260, in call_application
    app_iter = application(self.environ, start_response)
  File "/Users/dagh/Documents/Jobb/onlive/tg2env/lib/python2.7/site-packages/tw/core/resource_injector.py", line 70, in _injector
    resp = req.get_response(app)
  File "/Users/dagh/Documents/Jobb/onlive/tg2env/lib/python2.7/site-packages/webob/request.py", line 1296, in send
    application, catch_exc_info=False)
  File "/Users/dagh/Documents/Jobb/onlive/tg2env/lib/python2.7/site-packages/webob/request.py", line 1260, in call_application
    app_iter = application(self.environ, start_response)
  File "/Users/dagh/Documents/Jobb/onlive/tg2env/lib/python2.7/site-packages/tg/support/transaction_manager.py", line 75, in __call__
    reraise(*exc_info)
  File "/Users/dagh/Documents/Jobb/onlive/tg2env/lib/python2.7/site-packages/tg/support/transaction_manager.py", line 51, in __call__
    response_data = self.app(environ, _start_response)
  File "/Users/dagh/Documents/Jobb/onlive/tg2env/src/repoze.who-l10n-fix/repoze/who/middleware.py", line 87, in __call__
    app_iter = app(environ, wrapper.wrap_start_response)
  File "/Users/dagh/Documents/Jobb/onlive/tg2env/lib/python2.7/site-packages/beaker/middleware.py", line 73, in __call__
    return self.app(environ, start_response)
  File "/Users/dagh/Documents/Jobb/onlive/tg2env/lib/python2.7/site-packages/beaker/middleware.py", line 155, in __call__
    return self.wrap_app(environ, session_start_response)
  File "/Users/dagh/Documents/Jobb/onlive/tg2env/lib/python2.7/site-packages/tg/wsgiapp.py", line 102, in __call__
    response = self.wrapped_dispatch(controller, environ, context)
  File "/Users/dagh/Documents/Jobb/onlive/tg2env/lib/python2.7/site-packages/tg/wsgiapp.py", line 275, in dispatch
    return controller(environ, context)
  File "/Users/dagh/Documents/Jobb/onlive/OnLive/onlive/lib/base.py", line 48, in __call__
    return TGController.__call__(self, environ, context)
  File "/Users/dagh/Documents/Jobb/onlive/tg2env/lib/python2.7/site-packages/tg/controllers/dispatcher.py", line 122, in __call__
    response = self._perform_call(context)
  File "/Users/dagh/Documents/Jobb/onlive/OnLive/onlive/controllers/root.py", line 347, in _perform_call
    content = profiler.output_text()
  File "/Users/dagh/Documents/Jobb/onlive/tg2env/src/pyinstrument-master/pyinstrument/profiler.py", line 147, in output_text
    return self.starting_frame(root=root).as_text(unicode=unicode)
  File "/Users/dagh/Documents/Jobb/onlive/tg2env/src/pyinstrument-master/pyinstrument/profiler.py", line 144, in starting_frame
    return self.first_interesting_frame()
  File "/Users/dagh/Documents/Jobb/onlive/tg2env/src/pyinstrument-master/pyinstrument/profiler.py", line 131, in first_interesting_frame
    while len(frame.children) <= 1:
  File "/Users/dagh/Documents/Jobb/onlive/tg2env/src/pyinstrument-master/pyinstrument/utils.py", line 37, in __get__
    value = self.func(obj)
  File "/Users/dagh/Documents/Jobb/onlive/tg2env/src/pyinstrument-master/pyinstrument/profiler.py", line 251, in children
    return sorted(self.children_dict.values(), key=attrgetter('time'), reverse=True)
  File "/Users/dagh/Documents/Jobb/onlive/tg2env/src/pyinstrument-master/pyinstrument/utils.py", line 37, in __get__
    value = self.func(obj)
  File "/Users/dagh/Documents/Jobb/onlive/tg2env/src/pyinstrument-master/pyinstrument/profiler.py", line 230, in time
    return sum(child.time for child in self.children) + self.self_time
  File "/Users/dagh/Documents/Jobb/onlive/tg2env/src/pyinstrument-master/pyinstrument/utils.py", line 37, in __get__
    value = self.func(obj)
  File "/Users/dagh/Documents/Jobb/onlive/tg2env/src/pyinstrument-master/pyinstrument/profiler.py", line 251, in children
    return sorted(self.children_dict.values(), key=attrgetter('time'), reverse=True)
  File "/Users/dagh/Documents/Jobb/onlive/tg2env/src/pyinstrument-master/pyinstrument/utils.py", line 37, in __get__
    value = self.func(obj)
  File "/Users/dagh/Documents/Jobb/onlive/tg2env/src/pyinstrument-master/pyinstrument/profiler.py", line 230, in time
    return sum(child.time for child in self.children) + self.self_time
  File "/Users/dagh/Documents/Jobb/onlive/tg2env/src/pyinstrument-master/pyinstrument/utils.py", line 37, in __get__
    value = self.func(obj)
  File "/Users/dagh/Documents/Jobb/onlive/tg2env/src/pyinstrument-master/pyinstrument/profiler.py", line 251, in children
    return sorted(self.children_dict.values(), key=attrgetter('time'), reverse=True)
  File "/Users/dagh/Documents/Jobb/onlive/tg2env/src/pyinstrument-master/pyinstrument/utils.py", line 37, in __get__
    value = self.func(obj)
  File "/Users/dagh/Documents/Jobb/onlive/tg2env/src/pyinstrument-master/pyinstrument/profiler.py", line 230, in time
    return sum(child.time for child in self.children) + self.self_time
  File "/Users/dagh/Documents/Jobb/onlive/tg2env/src/pyinstrument-master/pyinstrument/utils.py", line 37, in __get__
    value = self.func(obj)

…and so on.

Thread support in signal mode

Your README says

On Mac/Linux/Unix, pyinstrument can run in 'signal' mode. [...] However, this can only profile the main thread.

You could instead sample the call stacks of all active threads by using sys._current_frames(), which returns a dict mapping thread IDs to frame objects.

Generated html file is huge

I was running pyinstrument and I got a huge html file (214 MB). I have uploaded the file at https://gist.github.com/asmeurer/a31ee881be8e3d77938b. There needs to be some way to limit the output. I think the way that makes the most sense is to not show nodes that take less than a given amount of time (say 1% of the total time).