|
| 1 | +""" |
| 2 | +Simple "active LOC" analyzer |
| 3 | +
|
| 4 | +Runs a program, and using a sampling profiler, outputs some statistics about how many |
| 5 | +lines of code contribute to the majority of the runtime. |
| 6 | +
|
| 7 | +For example: |
| 8 | +$ python tools/measure_loc.py minibenchmarks/fannkuch_med.py |
| 9 | +[...] |
| 10 | +Found 36 unique lines with 116480 samples |
| 11 | +minibenchmarks/fannkuch_med.py:28 48244 41.4% 1 41.4% |
| 12 | +minibenchmarks/fannkuch_med.py:36 18703 16.1% 2 57.5% |
| 13 | +minibenchmarks/fannkuch_med.py:30 8835 7.6% 3 65.1% |
| 14 | +minibenchmarks/fannkuch_med.py:37 6388 5.5% 4 70.5% |
| 15 | +minibenchmarks/fannkuch_med.py:29 5348 4.6% 5 75.1% |
| 16 | +minibenchmarks/fannkuch_med.py:27 4562 3.9% 6 79.1% |
| 17 | +minibenchmarks/fannkuch_med.py:20 3599 3.1% 7 82.1% |
| 18 | +minibenchmarks/fannkuch_med.py:21 2985 2.6% 8 84.7% |
| 19 | +minibenchmarks/fannkuch_med.py:26 2984 2.6% 9 87.3% |
| 20 | +minibenchmarks/fannkuch_med.py:23 2835 2.4% 10 89.7% |
| 21 | +minibenchmarks/fannkuch_med.py:24 2781 2.4% 11 92.1% |
| 22 | +minibenchmarks/fannkuch_med.py:40 2089 1.8% 12 93.9% |
| 23 | +minibenchmarks/fannkuch_med.py:38 2038 1.7% 13 95.6% |
| 24 | +minibenchmarks/fannkuch_med.py:35 1990 1.7% 14 97.3% |
| 25 | +minibenchmarks/fannkuch_med.py:19 1769 1.5% 15 98.9% |
| 26 | +minibenchmarks/fannkuch_med.py:39 1108 1.0% 16 99.8% |
| 27 | +minibenchmarks/fannkuch_med.py:42 179 0.2% 17 100.0% |
| 28 | +minibenchmarks/fannkuch_med.py:49 10 0.0% 18 100.0% |
| 29 | +minibenchmarks/fannkuch_med.py:51 7 0.0% 19 100.0% |
| 30 | +/usr/lib/python2.7/runpy.py:220 3 0.0% 20 100.0% |
| 31 | +(and 16 more -- see measure_loc.pkl) |
| 32 | +Picked 2 lines out of 36 to reach 57.48% |
| 33 | +Picked 5 lines out of 36 to reach 75.14% |
| 34 | +Picked 11 lines out of 36 to reach 92.09% |
| 35 | +Picked 16 lines out of 36 to reach 99.81% |
| 36 | +
|
| 37 | +
|
| 38 | +By default, this tool reports lines of code by the amount of time that was spent on them. |
| 39 | +There is also a mode to change the accounting to "number of times the line executed"; |
| 40 | +use the python_trace_counter instead of python_sampler (you have to modify the script). |
| 41 | +""" |
| 42 | + |
| 43 | + |
| 44 | +import os |
| 45 | +import pickle |
| 46 | +import runpy |
| 47 | +import signal |
| 48 | +import sys |
| 49 | +import time |
| 50 | +import traceback |
| 51 | + |
| 52 | +class SamplingProfiler(object): |
| 53 | + # Copied + modified from https://github.com/bdarnell/plop/blob/master/plop/collector.py |
| 54 | + MODES = { |
| 55 | + 'prof': (signal.ITIMER_PROF, signal.SIGPROF), |
| 56 | + 'virtual': (signal.ITIMER_VIRTUAL, signal.SIGVTALRM), |
| 57 | + 'real': (signal.ITIMER_REAL, signal.SIGALRM), |
| 58 | + } |
| 59 | + |
| 60 | + def __init__(self, sighandler, dumper, mode, interval=0.0001): |
| 61 | + self.sighandler = sighandler |
| 62 | + self.dumper = dumper |
| 63 | + self.mode = mode |
| 64 | + self.interval = interval |
| 65 | + |
| 66 | + def start(self): |
| 67 | + timer, sig = SamplingProfiler.MODES[self.mode] |
| 68 | + |
| 69 | + signal.signal(sig, signal_handler) |
| 70 | + signal.setitimer(timer, self.interval, self.interval) |
| 71 | + |
| 72 | + def stop(self): |
| 73 | + timer, sig = SamplingProfiler.MODES[self.mode] |
| 74 | + signal.setitimer(timer, 0, 0) |
| 75 | + signal.signal(sig, signal.SIG_DFL) |
| 76 | + return self.dumper() |
| 77 | + |
| 78 | +# Try to prevent / notice if someone else sets a debugger. |
| 79 | +# (Note: removing sys.settrace is not sufficient since one can set |
| 80 | +# frame.f_trace) |
| 81 | +sys_settrace = sys.settrace |
| 82 | +sys.settrace = None |
| 83 | +import bdb |
| 84 | +bdb.Bdb.set_trace = None |
| 85 | +bdb.set_trace = None |
| 86 | +import pdb |
| 87 | +pdb.set_trace = None |
| 88 | +pdb.Pdb.set_trace = None |
| 89 | + |
| 90 | +class TracingProfiler(object): |
| 91 | + def __init__(self, tracefunc, dumper): |
| 92 | + self.tracefunc = tracefunc |
| 93 | + self.dumper = dumper |
| 94 | + |
| 95 | + def start(self): |
| 96 | + sys_settrace(self.tracefunc) |
| 97 | + |
| 98 | + def stop(self): |
| 99 | + assert sys.gettrace() == self.tracefunc, "Problem! Someone/something removed our tracer. It's now: %r" % sys.gettrace() |
| 100 | + sys_settrace(None) |
| 101 | + return self.dumper() |
| 102 | + |
| 103 | +times = {} |
| 104 | +start_time = time.time() |
| 105 | +SKIP_WARMUP = 0 |
| 106 | +def signal_handler(sig, frame): |
| 107 | + if time.time() >= start_time + SKIP_WARMUP: |
| 108 | + # print("Starting sampling") |
| 109 | + def real_signal_handler(sig, frame): |
| 110 | + loc = frame.f_code.co_filename, frame.f_lineno |
| 111 | + times[loc] = times.get(loc, 0) + 1 |
| 112 | + |
| 113 | + signal.signal(sig, real_signal_handler) |
| 114 | + real_signal_handler(sig, frame) |
| 115 | + return |
| 116 | + |
| 117 | +def trace_count(frame, event, arg): |
| 118 | + if event == "line": |
| 119 | + loc = frame.f_code.co_filename, frame.f_lineno |
| 120 | + times[loc] = times.get(loc, 0) + 1 |
| 121 | + |
| 122 | + return trace_count |
| 123 | + |
| 124 | +def get_times(): |
| 125 | + return list(times.items()) |
| 126 | + |
| 127 | +def run(sampler, kind): |
| 128 | + fn = sys.argv[1] |
| 129 | + |
| 130 | + if fn == '-m': |
| 131 | + module = sys.argv[2] |
| 132 | + args = sys.argv[3:] |
| 133 | + else: |
| 134 | + args = sys.argv[2:] |
| 135 | + sys.argv = [sys.argv[0]] + args |
| 136 | + |
| 137 | + sys.path[0] = os.path.abspath(os.path.dirname(fn)) |
| 138 | + |
| 139 | + sampler.start() |
| 140 | + |
| 141 | + # del sys.modules["__main__"] # do we need this? |
| 142 | + try: |
| 143 | + if fn == '-m': |
| 144 | + runpy.run_module(module, run_name="__main__") |
| 145 | + else: |
| 146 | + runpy.run_path(fn, run_name="__main__") |
| 147 | + except KeyboardInterrupt: |
| 148 | + print("Interrupted!") |
| 149 | + traceback.print_exc() |
| 150 | + except SystemExit: |
| 151 | + pass |
| 152 | + except: |
| 153 | + print("ERROR!") |
| 154 | + traceback.print_exc() |
| 155 | + |
| 156 | + print("Stopping timer and tallying statistics...") |
| 157 | + times = sampler.stop() |
| 158 | + |
| 159 | + times.sort(key=lambda p: p[1], reverse=True) |
| 160 | + with open("measure_loc.pkl", "wb") as f: |
| 161 | + pickle.dump(times, f) |
| 162 | + |
| 163 | + total = 0.0 |
| 164 | + for l, t in times: |
| 165 | + total += t |
| 166 | + if kind == "time": |
| 167 | + print("Found %d unique lines for a total of %.2fs" % (len(times), total)) |
| 168 | + else: |
| 169 | + print("Found %d unique lines with %d samples" % (len(times), total)) |
| 170 | + |
| 171 | + FRACTIONS = [0.5, 0.75, 0.9, 0.99, 1] |
| 172 | + frac_counts = [] |
| 173 | + frac_fracs = [] |
| 174 | + frac_idx = 0 |
| 175 | + DISPLAY_THRESH = 20 |
| 176 | + |
| 177 | + sofar = 0.0 |
| 178 | + total_lines = 0 |
| 179 | + for (l, t) in times: |
| 180 | + if not l: |
| 181 | + continue |
| 182 | + fn, lineno = l |
| 183 | + total_lines += 1 |
| 184 | + sofar += t |
| 185 | + if total_lines <= DISPLAY_THRESH: |
| 186 | + if kind == "time": |
| 187 | + print(("%s:%s" % (fn, lineno)).ljust(50), "%.4fs %4.1f%% % 3d %4.1f%%" % (t, t / total * 100, total_lines, sofar / total * 100.0)) |
| 188 | + else: |
| 189 | + print(("%s:%s" % (fn, lineno)).ljust(50), "% 3d %4.1f%% % 3d %4.1f%%" % (t, t / total * 100, total_lines, sofar / total * 100.0)) |
| 190 | + if sofar >= total * FRACTIONS[frac_idx]: |
| 191 | + if FRACTIONS[frac_idx] == 1: |
| 192 | + break |
| 193 | + |
| 194 | + frac_counts.append(total_lines) |
| 195 | + frac_fracs.append(sofar) |
| 196 | + frac_idx += 1 |
| 197 | + |
| 198 | + if len(times) > DISPLAY_THRESH: |
| 199 | + print("(and %d more -- see measure_loc.pkl)" % (len(times) - DISPLAY_THRESH)) |
| 200 | + |
| 201 | + assert len(frac_counts) == len(FRACTIONS) -1 |
| 202 | + for i in range(len(frac_counts)): |
| 203 | + print("Picked %d lines out of %d to reach %.2f%%" % (frac_counts[i], len(times), frac_fracs[i] / total * 100.0)) |
| 204 | + |
| 205 | +python_sampler = SamplingProfiler(signal_handler, get_times, "real", interval=0.0001) |
| 206 | +python_trace_counter = TracingProfiler(trace_count, get_times) |
| 207 | +try: |
| 208 | + import measure_loc_ext |
| 209 | + cext_trace_timer = TracingProfiler(measure_loc_ext.trace, lambda: measure_loc_ext.get_times().items()) |
| 210 | +except ImportError: |
| 211 | + print("(extension module not available)") |
| 212 | + |
| 213 | +if __name__ == "__main__": |
| 214 | + if sys.argv[1] == '-t': |
| 215 | + del sys.argv[1] |
| 216 | + run(cext_trace_timer, "time") |
| 217 | + else: |
| 218 | + run(python_sampler, "count") |
| 219 | + # run(python_trace_counter, "count") |
0 commit comments