bdarnell / plop Goto Github PK

Python Low-Overhead Profiler

License: MIT License

Python 80.29% Shell 2.29% HTML 6.20% Ruby 1.02% JavaScript 10.07% CSS 0.13%

plop's Introduction

Plop: Python Low-Overhead Profiler

Plop is a stack-sampling profiler for Python. Profile collection can be turned on and off in a live process with minimal performance impact.

Plop is currently a work in progress and pretty rough around the edges, so be prepared to run into bugs and extremely unrefined interfaces (which are likely to change in backwards-incompatible ways in future releases).

Installation

pip install plop

Prerequisites

Plop runs on Python 2.7 and 3.x. The plop.collector module runs on Unixy platforms including Linux, BSD and Mac OS X (must support the setitimer system call). The plop.viewer module requires Tornado 2.x or newer. The viewer can be (and usually is) run separately from the collector.

Usage

In the application to be profiled, create a plop.collector.Collector, call start(), wait, then stop(). Create a Formatter (either PlopFormatter or FlamegraphFormatter) and call its save() method to write the output to a file. See ProfileHandler in demo/busy_server.py for an example of how to trigger profiling via an HTTP interface.

To profile an entire Python script, run:

python -m plop.collector myscript.py

This will write the profile to ./profiles/[timestamp]. Add -f flamegraph for flamegraph output.

To use the viewer for the default .plop output format, , run:

python -m plop.viewer --datadir=demo/profiles

and go to http://localhost:8888. For .flame format, see https://github.com/brendangregg/FlameGraph

Interpretation

In the default viewer, circle size is based on the amount of time that function was at the top of the stack (i.e. time in that function, not any of its descendants). Arrow thickness is based on how often that call was present anywhere in the stack.

In other words, the circle size corresponds to "time", and the arrow size roughly corresponds to "cumulative time".

Example

An end-to-end demo is available in the demo directory. create_profile.sh will run a server (which talks to itself to generate load), generate a profile, and shut it down. view_profile.sh will run the viewer app.

More info

The source code is hosted at https://github.com/bdarnell/plop

plop's People

Contributors

Stargazers

Watchers

Forkers

royshan mvanast posborne robbyt disqus lorin up1 delegans nandigama jietang nmichaud vbabiy blep coleb cnsoft ravipudi nuance soasme pychan fabioz dellis23 bernii andreasf cypreess udnay lijinhui cnh twistedlog proffalken why-not-sky e0ne davidals lgautier naufraghi omidraha tahajahangir fabianvf szl-926929 desertkun lord-prizrak teastburn rim99 upfluence lxhope dgmp88 cacalote kalin8 awesome-python struppimoppi lluke yunstanford eargie mukgupta tylerwiersing dpc-profilers-py stelles pquentin duruyi scoreunder dzbarsky gc-ss asafshon seanpm2001 gkuo06

plop's Issues

http://localhost:8888/gui/ 404: Not Found

I followed the instructions.
python2 -m plop.collector myscript2.pyw
python2 -m plop.viewer --datadir=./profiles/myscript2.pyw-20160206-2116-18.plop

Got empty 404: Not Found page and console utput:

server starting at http://localhost:8888
[W 160206 21:19:34 web:1946] 404 GET /gui/ (::1) 0.80ms

Line-by-line profiling?

It is possible to introspect the current line number in a CPython frame (f_lineno), and recording this information can obviously help the optimization of large-ish functions (see https://github.com/rkern/line_profiler for an instrumenting profiler with the same approach).

Any chance this capability can be added to plop? (crossposted as vmprof/vmprof-python#54)

New release

The previous release on PyPi is from 2015, and there have been some important changes since then (for example, taking the basename of the target script).

Time for a new release?

Missing tornado dep

Just after install the viewer gives this error:

(py-env)[naufraghi@odello src]$ python -m plop.viewer --datadir=demo/profiles
Traceback (most recent call last):
  File "/usr/lib64/python2.7/runpy.py", line 162, in _run_module_as_main
    "__main__", fname, loader, pkg_name)
  File "/usr/lib64/python2.7/runpy.py", line 72, in _run_code
    exec code in run_globals
  File "/home/naufraghi/.virtualenvs/py-env/lib/python2.7/site-packages/plop/viewer.py", line 7, in <module>
    from tornado.ioloop import IOLoop
ImportError: No module named tornado.ioloop

After pip install tornado it goes on as expected.

give full(er) stack for each sample

Is it possible to make it give more stack info? What I want is for each observation to contain what python prints when I press ctrl+c. The numbers will be different of course since each observation has more information, instead of just ('/usr/lib/python2.7/threading.py', N, 'waiter_acquire') you have

"""File "/foo/fie.py", line 278, in
sys.exit(main(sys.argv))
File "/foo/fie.py", line 262, in main
x = init(argv[1], argv[2], argv[3])
File "/foo/fie.py", line 25, in init
moo)
File "/foo/bar.py", line 50, in init
mie.join()
File "/usr/lib/python2.7/threading.py", line 949, in join
self.__block.wait()
File "/usr/lib/python2.7/threading.py", line 339, in wait
waiter.acquire()
"""

.flame format error or parsing error

I ran some script from scripts directory with -m plop.collector -f flamegraph and it generated a profiles/scripts/xxx.py-xxx.flame file, that starts like this:

None 1
_run_module_as_main ( ... [snip]
_run_module_as_main ( ... [snip]

When I try to view it using -m plop.viewer --datadir=profiles/scripts/ the server part crashes:

[E 160201 08:51:26 web:1524] Uncaught exception GET /data?filename=put_chunked_file.py-20160201-0850-43.flame (::1)
    HTTPServerRequest(protocol='http', host='localhost:8888', method='GET', uri='/data?filename=put_chunked_file.py-20160201-0850-43.flame', version='HTTP/1.1', remote_ip='::1', headers={'Accept-Language': 'en-GB,en-US;q=0.8,en;q=0.6', 'Accept-Encoding': 'gzip, deflate, sdch', 'Host': 'localhost:8888', 'Accept': 'application/json,*/*', 'User-Agent': 'Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/48.0.2564.82 Safari/537.36', 'Connection': 'keep-alive', 'Referer': 'http://localhost:8888/view?filename=xxx.py-20160201-0850-43.flame'})
    Traceback (most recent call last):
      File "/dima/plc/lib/python2.7/site-packages/tornado/web.py", line 1443, in _execute
        result = method(*self.path_args, **self.path_kwargs)
      File "/dima/plc/lib/python2.7/site-packages/plop/viewer.py", line 44, in get
        self.write(profile_to_json(self.get_argument('filename')))
      File "/dima/plc/lib/python2.7/site-packages/plop/viewer.py", line 50, in profile_to_json
        graph = CallGraph.load(abspath)
      File "/dima/plc/lib/python2.7/site-packages/plop/callgraph.py", line 87, in load
        data = ast.literal_eval(f.read())
      File "/usr/lib64/python2.7/ast.py", line 49, in literal_eval
        node_or_string = parse(node_or_string, mode='eval')
      File "/usr/lib64/python2.7/ast.py", line 37, in parse
        return compile(source, filename, mode, PyCF_ONLY_AST)
      File "<unknown>", line 1
        None 1

Add an option to collector to specify output directory

collector fails to write when the target is in a dir the user doesn't have write privileges to.

Also, if the target is in a virtual environment (such as py.test), the output is written to the virtualenv as well.

'platform' module conflict with python built-in module

$ cat a.py
import platform
print platform.uname()[0]
$ python a.py
FreeBSD
$ python -m plop.collector a.py
Traceback (most recent call last):
  File "/usr/local/lib/python2.7/runpy.py", line 162, in _run_module_as_main
    "__main__", fname, loader, pkg_name)
  File "/usr/local/lib/python2.7/runpy.py", line 72, in _run_code
    exec code in run_globals
  File "/usr/local/lib/python2.7/site-packages/plop/collector.py", line 104, in main
    exec f.read() in globals(), globals()
  File "<string>", line 2, in <module>
AttributeError: 'module' object has no attribute 'uname'

This is because collector pass globals() to user script, but __package__='plop' too.

update pypi to include FlamegraphFormatter

please? :)

Does not cover more than one instruction in a row

For the following pseudocode:

def main_function():
pc.start()
function_1()
funtcion_2()
function_3()
pc.stop()

The result only contains data for function_1 (and then only for the first thing that happens in there, and so on). Data for the following functions 2 and 3 is not present in the output of the profiler. (Or at least, is not visible in the visualization).

KeyError when adding to stack

I think this is somehow related to the fact that I'm using plop with a multithreaded application (which runs under Twisted), but I'm getting these errors every once in a while, any ideas what it might be?:

Unhandled Error
Traceback (most recent call last):
  File "/home/diogobaeder/some-company/some-project/profiling-support/utilities/serve_wsgi_with_twisted.py", line 43, in <module>
    sys.exit(main())
  File "/home/diogobaeder/some-company/some-project/profiling-support/utilities/../lib/some-project/wsgi/twisted.py", line 1704, in main
    return run_worker(options, config)
  File "/home/diogobaeder/some-company/some-project/profiling-support/utilities/../lib/some-project/wsgi/twisted.py", line 1684, in run_worker
    reactor.run()
  File "/usr/lib/python2.7/dist-packages/twisted/internet/base.py", line 1169, in run
    self.mainLoop()
--- <exception caught here> ---
  File "/usr/lib/python2.7/dist-packages/twisted/internet/base.py", line 1181, in mainLoop
    self.doIteration(t)
  File "/usr/lib/python2.7/dist-packages/twisted/internet/epollreactor.py", line 181, in doPoll
    l = self._poller.wait(len(self._selectables), timeout)
  File "/home/diogobaeder/some-company/some-project/profiling-support/utilities/../lib/plop/collector.py", line 65, in handler
    self.stack_counts[tuple(frames)] += 1
exceptions.KeyError: (('/home/diogobaeder/some-company/some-project/profiling-support/utilities/../lib/django/utils/encoding.py', 104, 'smart_str'), ('/home/diogobaeder/some-company/some-project/profiling-support/utilities/../lib/django/utils/encoding.py', 132, 'iri_to_uri'), ('/home/diogobaeder/some-company/some-project/profiling-support/utilities/../lib/django/core/urlresolvers.py', 422, 'reverse'), ('/home/diogobaeder/some-company/some-project/profiling-support/utilities/../lib/django/template/defaulttags.py', 395, 'render'), ('/home/diogobaeder/some-company/some-project/profiling-support/utilities/../lib/django/template/debug.py', 72, 'render_node'), ('/home/diogobaeder/some-company/some-project/profiling-support/utilities/../lib/django/template/base.py', 819, 'render'), ('/home/diogobaeder/some-company/some-project/profiling-support/utilities/../lib/django/template/loader_tags.py', 48, 'render'), ('/home/diogobaeder/some-company/some-project/profiling-support/utilities/../lib/django/template/debug.py', 72, 'render_node'), ('/home/diogobaeder/some-company/some-project/profiling-support/utilities/../lib/django/template/base.py', 819, 'render'), ('/home/diogobaeder/some-company/some-project/profiling-support/utilities/../lib/django/template/base.py', 133, '_render'), ('/home/diogobaeder/some-company/some-project/profiling-support/utilities/../lib/django/template/base.py', 136, 'render'), ('/home/diogobaeder/some-company/some-project/profiling-support/utilities/../lib/django/template/loader_tags.py', 131, 'render_template'), ('/home/diogobaeder/some-company/some-project/profiling-support/utilities/../lib/django/template/loader_tags.py', 152, 'render'), ('/home/diogobaeder/some-company/some-project/profiling-support/utilities/../lib/django/template/debug.py', 72, 'render_node'), ('/home/diogobaeder/some-company/some-project/profiling-support/utilities/../lib/django/template/base.py', 819, 'render'), ('/home/diogobaeder/some-company/some-project/profiling-support/utilities/../lib/django/template/base.py', 133, '_render'), ('/home/diogobaeder/some-company/some-project/profiling-support/utilities/../lib/django/template/loader_tags.py', 100, 'render'), ('/home/diogobaeder/some-company/some-project/profiling-support/utilities/../lib/django/template/debug.py', 72, 'render_node'), ('/home/diogobaeder/some-company/some-project/profiling-support/utilities/../lib/django/template/base.py', 819, 'render'), ('/home/diogobaeder/some-company/some-project/profiling-support/utilities/../lib/django/template/base.py', 133, '_render'), ('/home/diogobaeder/some-company/some-project/profiling-support/utilities/../lib/django/template/loader_tags.py', 100, 'render'), ('/home/diogobaeder/some-company/some-project/profiling-support/utilities/../lib/django/template/debug.py', 72, 'render_node'), ('/home/diogobaeder/some-company/some-project/profiling-support/utilities/../lib/django/template/base.py', 819, 'render'), ('/home/diogobaeder/some-company/some-project/profiling-support/utilities/../lib/django/template/base.py', 133, '_render'), ('/home/diogobaeder/some-company/some-project/profiling-support/utilities/../lib/django/template/base.py', 136, 'render'), ('/home/diogobaeder/some-company/some-project/profiling-support/utilities/../lib/django/template/loader.py', 158, 'render_to_string'), ('/home/diogobaeder/some-company/some-project/profiling-support/utilities/../lib/django/shortcuts/__init__.py', 14, 'render_to_response'), ('/home/diogobaeder/some-company/some-project/profiling-support/servers/u1servers/web/admin/storage/views.py', 24, 'view_index'), ('/home/diogobaeder/some-company/some-project/profiling-support/utilities/../lib/some-project/account/djangolib/decorators.py', 91, '__call__'), ('/home/diogobaeder/some-company/some-project/profiling-support/utilities/../lib/django/core/handlers/base.py', 72, 'get_response'), ('/home/diogobaeder/some-company/some-project/profiling-support/utilities/../lib/django/core/handlers/wsgi.py', 210, '__call__'), ('/home/diogobaeder/some-company/some-project/profiling-support/utilities/../lib/some-project/wsgi/handlers.py', 40, '__call__'), ('/home/diogobaeder/some-company/some-project/profiling-support/utilities/../lib/some-project/wsgi/middleware/bzrheader.py', 16, '__call__'), ('/home/diogobaeder/some-company/some-project/profiling-support/utilities/../lib/storm/wsgi.py', 49, 'wrapper'), ('/usr/lib/pymodules/python2.7/timeline/wsgi.py', 27, 'wrapper'), ('/usr/lib/python2.7/dist-packages/oops_wsgi/middleware.py', 103, 'oops_middleware'), ('/home/diogobaeder/some-company/some-project/profiling-support/utilities/../lib/some-project/wsgi/middleware/opstats.py', 29, '__call__'), ('/home/diogobaeder/some-company/some-project/profiling-support/utilities/../lib/some-project/wsgi/middleware/meliae_middleware.py', 19, '__call__'), ('/home/diogobaeder/some-company/some-project/profiling-support/utilities/../lib/some-project/wsgi/twisted.py', 597, 'run'), ('/home/diogobaeder/some-company/some-project/profiling-support/utilities/../lib/some-project/wsgi/twisted.py', 183, 'wrapper'), ('/usr/lib/python2.7/dist-packages/twisted/python/context.py', 61, 'callWithContext'), ('/usr/lib/python2.7/dist-packages/twisted/python/context.py', 117, 'callWithContext'), ('/usr/lib/python2.7/dist-packages/twisted/python/threadpool.py', 193, '_worker'), ('/usr/lib/python2.7/threading.py', 501, 'run'), ('/usr/lib/python2.7/threading.py', 533, '__bootstrap_inner'), ('/usr/lib/python2.7/threading.py', 510, '__bootstrap'))

flamegraph visualization fails

Hi, thanks for the very nice tool!

The standard view works fine, but I am having trouble with -f flamegraph option though. The problem can be seen in this simple example:

def func(x):
    for i in xrange(x):
        fibo(i)

def fibo(n):
    if n == 0: return 0
    elif n == 1: return 1
    else: return fibo(n-1)+fibo(n-2)


if __name__ == "__main__":
    func(20)

To produce a flame output:

$ python -m plop.collector -f flamegraph testprofile.py 
profile output saved to profiles/testprofile.py-20170222-1740-59.flame
overhead was 6.49690628052e-05 per sample (0.00649690628052%)

the profiles/testprofile.py-20170222-1740-59.flame looks like:

None 1
_run_module_as_main (/usr/lib/python2.7/runpy.py:147);_run_code (/usr/lib/python2.7/runpy.py:62);<module> (/home/perrette/envs/default/lib/python2.7/site-packages/plop/collector.py:1);main (/home/perrette/envs/default/lib/python2.7/site-packages/plop/collector.py:128);exec_ (/home/perrette/envs/default/local/lib/python2.7/site-packages/six.py:689);<module> (<string>:1);<module> (<string>:1);func (<string>:1);fibo (<string>:5);fibo (<string>:5);fibo (<string>:5);fibo (<string>:5);fibo (<string>:5);fibo (<string>:5);fibo (<string>:5);fibo (<string>:5);fibo (<string>:5);fibo (<string>:5);fibo (<string>:5) 1
_run_module_as_main (/usr/lib/python2.7/runpy.py:147);_run_code (/usr/lib/python2.7/runpy.py:62);<module> (/home/perrette/envs/default/lib/python2.7/site-packages/plop/collector.py:1);main (/home/perrette/envs/default/lib/python2.7/site-packages/plop/collector.py:128);exec_ (/home/perrette/envs/default/local/lib/python2.7/site-packages/six.py:689);<module> (<string>:1);<module> (<string>:1);func (<string>:1);fibo (<string>:5);fibo (<string>:5);fibo (<string>:5);fibo (<string>:5);fibo (<string>:5);fibo (<string>:5);fibo (<string>:5);fibo (<string>:5);fibo (<string>:5);fibo (<string>:5) 1

Which yields the following error when run in the server:

[I 170222 17:43:19 web:1971] 200 GET /view?filename=testprofile.py-20170222-1740-59.flame (127.0.0.1) 2.11ms
[E 170222 17:43:20 web:1548] Uncaught exception GET /data?filename=testprofile.py-20170222-1740-59.flame (127.0.0.1)
    HTTPServerRequest(protocol='http', host='localhost:8888', method='GET', uri='/data?filename=testprofile.py-20170222-1740-59.flame', version='HTTP/1.1', remote_ip='127.0.0.1', headers={'Accept-Language': 'de-DE,de;q=0.8,en-US;q=0.6,en;q=0.4,fr;q=0.2', 'Accept-Encoding': 'gzip, deflate, sdch, br', 'Host': 'localhost:8888', 'Accept': 'application/json,*/*', 'User-Agent': 'Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/55.0.2883.87 Safari/537.36', 'Dnt': '1', 'Connection': 'keep-alive', 'Referer': 'http://localhost:8888/view?filename=testprofile.py-20170222-1740-59.flame'})
    Traceback (most recent call last):
      File "/home/perrette/envs/default/local/lib/python2.7/site-packages/tornado/web.py", line 1467, in _execute
        result = method(*self.path_args, **self.path_kwargs)
      File "/home/perrette/envs/default/lib/python2.7/site-packages/plop/viewer.py", line 44, in get
        self.write(profile_to_json(self.get_argument('filename')))
      File "/home/perrette/envs/default/lib/python2.7/site-packages/plop/viewer.py", line 50, in profile_to_json
        graph = CallGraph.load(abspath)
      File "/home/perrette/envs/default/local/lib/python2.7/site-packages/plop/callgraph.py", line 87, in load
        data = ast.literal_eval(f.read())
      File "/usr/lib/python2.7/ast.py", line 49, in literal_eval
        node_or_string = parse(node_or_string, mode='eval')
      File "/usr/lib/python2.7/ast.py", line 37, in parse
        return compile(source, filename, mode, PyCF_ONLY_AST)
      File "<unknown>", line 1
        None 1
             ^
    SyntaxError: invalid syntax
[E 170222 17:43:20 web:1971] 500 GET /data?filename=testprofile.py-20170222-1740-59.flame (127.0.0.1) 6.81ms

What about IO and threads?

The docs say (https://docs.python.org/2/library/signal.html) that it won't cover running threads nor blocking operations.

Do you plan on covering those in some way?

Testsuite is broken on tornado 5.x

Since tornadoweb/tornado#2083 LogTrapTestCase no longer exists...

Windows support - time.sleep()?

In your commit "This doesn't need to be linux-only" you pull in libc, which is not present on my system (I assume it's part of GLibC).

I wonder however, why you can't use threading.Timer or time.sleep? It ought to have a resolution of at least 16ms on windows, but according to http://stackoverflow.com/questions/1133857/how-accurate-is-pythons-time-sleep could potentially be higher.

This could potentially make things work in vanilla Python without extra dependencies, even just as a cross platform fallback, and 16 samples a second seems fine to me for many uses.

Perhaps there's a good reason for not doing this though, I just don't know enough about it, so wanted to ask.

Add documentation on interpreting web viewer output

It's unclear to me at the moment whether color has any significance, and exactly what the circle and arrow size mean. It'd be nice to have an explanation. If I figure it out I'd be happy to write something up and submit a PR.

Add new UI features to the web viewer

At the moment, it's somewhat difficult to move around. For me, the output is far off the screen, and I have to scroll down and to the size to see it. There also doesn't seem to be a way to zoom out, other than using the native browser zoom.

It's looking like this project could be very useful to us, so I'd be happy to work on this as I use it and contribute back the results if it's something you think would be valuable.