Permalink
Please sign in to comment.
Browse files
Add a stub for pytrace, a tracing module that uses sys.setprofile().
I looked both at both kwlzn/pytracing and evanhempel/python-flamegraph on Github, and am thinking about combining their approaches. - pytracing can't handle all of 'osh abuild -h' (too many events to output directly as JSON) - python-flamegraph seems to introduce a bias toward I/O (e.g. _GetLine), possibly because of threading/locking. And it might not give enough examples.
- Loading branch information...
Showing
with
227 additions
and 16 deletions.
- +3 −1 benchmarks/pypy.sh
- +78 −0 benchmarks/pytrace.py
- +120 −0 benchmarks/pytrace.sh
- +26 −15 bin/oil.py
| @@ -0,0 +1,78 @@ | ||
| #!/usr/bin/python | ||
| """ | ||
| pytrace.py | ||
| """ | ||
| import cStringIO | ||
| import os | ||
| import struct | ||
| import sys | ||
| # TODO: Two kinds of tracing? | ||
| # - FullTracer -> Chrome trace? | ||
| # - ReservoirSamplingTracer() -- flame graph that is deterministic? | ||
| # TODO: Check this in but just go ahead and fix wild.sh instead. | ||
| class Tracer(object): | ||
| # Limit to 10M events by default. | ||
| def __init__(self, max_events=10e6): | ||
| self.pid = os.getpid() | ||
| # append | ||
| self.event_strs = cStringIO.StringIO() | ||
| # After max_events we stop recording | ||
| self.max_events = max_events | ||
| self.num_events = 0 | ||
| # Python VM callback | ||
| def OnEvent(self, frame, event_type, arg): | ||
| # Test overhead | ||
| # 7.5 seconds. Geez. That's crazy high. | ||
| # The baseline is 2.7 seconds, and _lsprof takes 3.8 seconds. | ||
| # I guess that's why pytracing is a decorator and only works on one part of | ||
| # the program. | ||
| # pytracing isn't usable with large programs. It can't run abuild -h. | ||
| # What I really want is the nicer visualization. I don't want the silly | ||
| # cProfile output. | ||
| self.num_events += 1 | ||
| return | ||
| self.event_strs.write('') # struct.pack(s) | ||
| # TODO: | ||
| def Start(self): | ||
| sys.setprofile(self.OnEvent) | ||
| def Stop(self, path): | ||
| # Only one process should write out the file! | ||
| if os.getpid() != self.pid: | ||
| return | ||
| # TODO: | ||
| # - report number of events? | ||
| # - report number of bytes? | ||
| print >>sys.stderr, 'num_events: %d' % self.num_events | ||
| print >>sys.stderr, 'Writing to %r' % path | ||
| with open(path, 'w') as f: | ||
| f.write(self.event_strs.getvalue()) | ||
| def main(argv): | ||
| t = Tracer() | ||
| import urlparse | ||
| t.Start() | ||
| print urlparse.urlparse('http://example.com/foo') | ||
| t.Stop('demo.pytrace') | ||
| if __name__ == '__main__': | ||
| try: | ||
| main(sys.argv) | ||
| except RuntimeError as e: | ||
| print >>sys.stderr, 'FATAL: %s' % e | ||
| sys.exit(1) |
| @@ -0,0 +1,120 @@ | ||
| #!/bin/bash | ||
| # | ||
| # Use sys.setprofile() and maybe sys.settrace() to trace Oil execution. | ||
| # | ||
| # Usage: | ||
| # ./pytrace.sh <function name> | ||
| set -o nounset | ||
| set -o pipefail | ||
| set -o errexit | ||
| readonly ABUILD=~/git/alpine/abuild/abuild | ||
| readonly -a RUN_ABUILD=(bin/oil.py osh $ABUILD -h) | ||
| # | ||
| # Use Python's cProfile, which uses _lsprof. This is pretty fast. | ||
| # | ||
| # ~2.7 seconds without tracing | ||
| abuild() { | ||
| time "${RUN_ABUILD[@]}" | ||
| ls -l -h *.json | ||
| } | ||
| # 3.8 seconds. So less than 2x overhead. | ||
| cprofile-abuild() { | ||
| local out=abuild.cprofile | ||
| time python -m cProfile -o $out "${RUN_ABUILD[@]}" | ||
| ls -l $out | ||
| } | ||
| # Yeah I understand from this why Chrome Tracing / Flame Graphs are better. | ||
| # This format doesn't respect the stack! | ||
| # cumtime: bin/oil.py is the top, obviously | ||
| print-cprofile() { | ||
| python -c ' | ||
| import pstats | ||
| p = pstats.Stats("abuild.cprofile") | ||
| p.sort_stats("tottime").print_stats() | ||
| ' | ||
| } | ||
| # | ||
| # My Own Tracing with pytrace.py. Too slow! | ||
| # | ||
| # Abuild call/return events: | ||
| # Parsing: 4,345,706 events | ||
| # Execution: 530,924 events | ||
| # Total events: | ||
| # 14,918,308 | ||
| # Actually that is still doable as binary. Not sure it's viewable in Chrome | ||
| # though. | ||
| # 14 bytes * 14.9M is 209 MB. | ||
| abuild-trace() { | ||
| _PY_TRACE=abuild.pytrace time "${RUN_ABUILD[@]}" | ||
| } | ||
| # | ||
| # Depends on pytracing, which is also too slow. | ||
| # | ||
| # Trace a parsing function | ||
| parse() { | ||
| #local script=$ABUILD | ||
| local script=$0 | ||
| time bin/oil.py osh -n $script >/dev/null | ||
| } | ||
| # Trace the execution | ||
| execute() { | ||
| #local script=$ABUILD | ||
| local script=$0 | ||
| #time bin/oil.py osh -c 'echo hi' | ||
| time bin/oil.py osh $0 | ||
| ls -l -h *.json | ||
| } | ||
| # Idea: I Want a flame graph based on determistic data! That way you get the | ||
| # full stack trace. | ||
| # It wasn't happening in the python-flamegraph stuff for some reason. Not sure | ||
| # why. I think it is because I/O was exaggerated. | ||
| # | ||
| # Interpreter hook: | ||
| # | ||
| # for thread_id, frame in sys._current_frames().items(): | ||
| # if thread_id == my_thread: | ||
| # continue | ||
| # Note that opening file descriptors can cause bugs! I have to open it above | ||
| # descriptor 10! | ||
| # python-flamegraph | ||
| # - suffers from measurement error due to threads. | ||
| # - is RunCommandSub is being inflated? | ||
| # - well actually i'm not sure. I have to do it myself on a single thread | ||
| # and see. | ||
| # pytracing: | ||
| # - the format is too bloated. It can't handle abuild -h. So I have to | ||
| # optimize it. | ||
| # | ||
| # I want to unify these two approaches: both flame graphs and function traces. | ||
| # | ||
| # Advantage: sys.setprofile() gets C function call events! | ||
| # | ||
| # Reservoir Sampling! Get a list of all unique stacks. | ||
| # | ||
| # You can figure out the stack from the current/call/return sequence. So you | ||
| # can use the reservoir sampling algorithm to get say 100,000 random stacks out | ||
| # of 14 M events. | ||
| # | ||
| # sys.getframes() | ||
| "$@" |
0 comments on commit
c448b23