Mercurial > public > mercurial-scm > hg
comparison mercurial/statprof.py @ 30253:b032a7b676c6
statprof: vendor statprof.py
Vendored from https://bitbucket.org/facebook/hg-experimental
changeset 73f9db47ae5a1a9fa29a98dfe92d557ad51234c3 without
modification.
This introduces a number of code style violations. The file
already has the magic words to skip test-check-code.t. I'll
make additional changes to clean up the test-check-py3-compat.t
warnings and to change some behavior in the code that isn't
suitable for general use.
test-check-commit.t also complains about numerous things. But
there's nothing we can do if we're importing as-is.
author | Gregory Szorc <gregory.szorc@gmail.com> |
---|---|
date | Tue, 01 Nov 2016 18:54:03 -0700 |
parents | |
children | ad4c0236168d |
comparison
equal
deleted
inserted
replaced
30252:bb5869668189 | 30253:b032a7b676c6 |
---|---|
1 #!/usr/bin/env python | |
2 ## statprof.py | |
3 ## Copyright (C) 2012 Bryan O'Sullivan <bos@serpentine.com> | |
4 ## Copyright (C) 2011 Alex Fraser <alex at phatcore dot com> | |
5 ## Copyright (C) 2004,2005 Andy Wingo <wingo at pobox dot com> | |
6 ## Copyright (C) 2001 Rob Browning <rlb at defaultvalue dot org> | |
7 | |
8 ## This library is free software; you can redistribute it and/or | |
9 ## modify it under the terms of the GNU Lesser General Public | |
10 ## License as published by the Free Software Foundation; either | |
11 ## version 2.1 of the License, or (at your option) any later version. | |
12 ## | |
13 ## This library is distributed in the hope that it will be useful, | |
14 ## but WITHOUT ANY WARRANTY; without even the implied warranty of | |
15 ## MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU | |
16 ## Lesser General Public License for more details. | |
17 ## | |
18 ## You should have received a copy of the GNU Lesser General Public | |
19 ## License along with this program; if not, contact: | |
20 ## | |
21 ## Free Software Foundation Voice: +1-617-542-5942 | |
22 ## 59 Temple Place - Suite 330 Fax: +1-617-542-2652 | |
23 ## Boston, MA 02111-1307, USA gnu@gnu.org | |
24 | |
25 """ | |
26 statprof is intended to be a fairly simple statistical profiler for | |
27 python. It was ported directly from a statistical profiler for guile, | |
28 also named statprof, available from guile-lib [0]. | |
29 | |
30 [0] http://wingolog.org/software/guile-lib/statprof/ | |
31 | |
32 To start profiling, call statprof.start(): | |
33 >>> start() | |
34 | |
35 Then run whatever it is that you want to profile, for example: | |
36 >>> import test.pystone; test.pystone.pystones() | |
37 | |
38 Then stop the profiling and print out the results: | |
39 >>> stop() | |
40 >>> display() | |
41 % cumulative self | |
42 time seconds seconds name | |
43 26.72 1.40 0.37 pystone.py:79:Proc0 | |
44 13.79 0.56 0.19 pystone.py:133:Proc1 | |
45 13.79 0.19 0.19 pystone.py:208:Proc8 | |
46 10.34 0.16 0.14 pystone.py:229:Func2 | |
47 6.90 0.10 0.10 pystone.py:45:__init__ | |
48 4.31 0.16 0.06 pystone.py:53:copy | |
49 ... | |
50 | |
51 All of the numerical data is statistically approximate. In the | |
52 following column descriptions, and in all of statprof, "time" refers | |
53 to execution time (both user and system), not wall clock time. | |
54 | |
55 % time | |
56 The percent of the time spent inside the procedure itself (not | |
57 counting children). | |
58 | |
59 cumulative seconds | |
60 The total number of seconds spent in the procedure, including | |
61 children. | |
62 | |
63 self seconds | |
64 The total number of seconds spent in the procedure itself (not | |
65 counting children). | |
66 | |
67 name | |
68 The name of the procedure. | |
69 | |
70 By default statprof keeps the data collected from previous runs. If you | |
71 want to clear the collected data, call reset(): | |
72 >>> reset() | |
73 | |
74 reset() can also be used to change the sampling frequency from the | |
75 default of 1000 Hz. For example, to tell statprof to sample 50 times a | |
76 second: | |
77 >>> reset(50) | |
78 | |
79 This means that statprof will sample the call stack after every 1/50 of | |
80 a second of user + system time spent running on behalf of the python | |
81 process. When your process is idle (for example, blocking in a read(), | |
82 as is the case at the listener), the clock does not advance. For this | |
83 reason statprof is not currently not suitable for profiling io-bound | |
84 operations. | |
85 | |
86 The profiler uses the hash of the code object itself to identify the | |
87 procedures, so it won't confuse different procedures with the same name. | |
88 They will show up as two different rows in the output. | |
89 | |
90 Right now the profiler is quite simplistic. I cannot provide | |
91 call-graphs or other higher level information. What you see in the | |
92 table is pretty much all there is. Patches are welcome :-) | |
93 | |
94 | |
95 Threading | |
96 --------- | |
97 | |
98 Because signals only get delivered to the main thread in Python, | |
99 statprof only profiles the main thread. However because the time | |
100 reporting function uses per-process timers, the results can be | |
101 significantly off if other threads' work patterns are not similar to the | |
102 main thread's work patterns. | |
103 """ | |
104 # no-check-code | |
105 from __future__ import division | |
106 | |
107 import inspect, json, os, signal, tempfile, sys, getopt, threading, traceback | |
108 import time | |
109 from collections import defaultdict | |
110 from contextlib import contextmanager | |
111 from subprocess import call | |
112 | |
113 __all__ = ['start', 'stop', 'reset', 'display', 'profile'] | |
114 | |
115 skips = set(["util.py:check", "extensions.py:closure", | |
116 "color.py:colorcmd", "dispatch.py:checkargs", | |
117 "dispatch.py:<lambda>", "dispatch.py:_runcatch", | |
118 "dispatch.py:_dispatch", "dispatch.py:_runcommand", | |
119 "pager.py:pagecmd", "dispatch.py:run", | |
120 "dispatch.py:dispatch", "dispatch.py:runcommand", | |
121 "hg.py:<module>", "evolve.py:warnobserrors", | |
122 ]) | |
123 | |
124 ########################################################################### | |
125 ## Utils | |
126 | |
127 def clock(): | |
128 times = os.times() | |
129 return times[0] + times[1] | |
130 | |
131 | |
132 ########################################################################### | |
133 ## Collection data structures | |
134 | |
135 class ProfileState(object): | |
136 def __init__(self, frequency=None): | |
137 self.reset(frequency) | |
138 | |
139 def reset(self, frequency=None): | |
140 # total so far | |
141 self.accumulated_time = 0.0 | |
142 # start_time when timer is active | |
143 self.last_start_time = None | |
144 # a float | |
145 if frequency: | |
146 self.sample_interval = 1.0 / frequency | |
147 elif not hasattr(self, 'sample_interval'): | |
148 # default to 1000 Hz | |
149 self.sample_interval = 1.0 / 1000.0 | |
150 else: | |
151 # leave the frequency as it was | |
152 pass | |
153 self.remaining_prof_time = None | |
154 # for user start/stop nesting | |
155 self.profile_level = 0 | |
156 | |
157 self.samples = [] | |
158 | |
159 def accumulate_time(self, stop_time): | |
160 self.accumulated_time += stop_time - self.last_start_time | |
161 | |
162 def seconds_per_sample(self): | |
163 return self.accumulated_time / len(self.samples) | |
164 | |
165 state = ProfileState() | |
166 | |
167 | |
168 class CodeSite(object): | |
169 cache = {} | |
170 | |
171 __slots__ = ('path', 'lineno', 'function', 'source') | |
172 | |
173 def __init__(self, path, lineno, function): | |
174 self.path = path | |
175 self.lineno = lineno | |
176 self.function = function | |
177 self.source = None | |
178 | |
179 def __eq__(self, other): | |
180 try: | |
181 return (self.lineno == other.lineno and | |
182 self.path == other.path) | |
183 except: | |
184 return False | |
185 | |
186 def __hash__(self): | |
187 return hash((self.lineno, self.path)) | |
188 | |
189 @classmethod | |
190 def get(cls, path, lineno, function): | |
191 k = (path, lineno) | |
192 try: | |
193 return cls.cache[k] | |
194 except KeyError: | |
195 v = cls(path, lineno, function) | |
196 cls.cache[k] = v | |
197 return v | |
198 | |
199 def getsource(self, length): | |
200 if self.source is None: | |
201 lineno = self.lineno - 1 | |
202 fp = None | |
203 try: | |
204 fp = open(self.path) | |
205 for i, line in enumerate(fp): | |
206 if i == lineno: | |
207 self.source = line.strip() | |
208 break | |
209 except: | |
210 pass | |
211 finally: | |
212 if fp: | |
213 fp.close() | |
214 if self.source is None: | |
215 self.source = '' | |
216 | |
217 source = self.source | |
218 if len(source) > length: | |
219 source = source[:(length - 3)] + "..." | |
220 return source | |
221 | |
222 def filename(self): | |
223 return os.path.basename(self.path) | |
224 | |
225 class Sample(object): | |
226 __slots__ = ('stack', 'time') | |
227 | |
228 def __init__(self, stack, time): | |
229 self.stack = stack | |
230 self.time = time | |
231 | |
232 @classmethod | |
233 def from_frame(cls, frame, time): | |
234 stack = [] | |
235 | |
236 while frame: | |
237 stack.append(CodeSite.get(frame.f_code.co_filename, frame.f_lineno, | |
238 frame.f_code.co_name)) | |
239 frame = frame.f_back | |
240 | |
241 return Sample(stack, time) | |
242 | |
243 ########################################################################### | |
244 ## SIGPROF handler | |
245 | |
246 def profile_signal_handler(signum, frame): | |
247 if state.profile_level > 0: | |
248 now = clock() | |
249 state.accumulate_time(now) | |
250 | |
251 state.samples.append(Sample.from_frame(frame, state.accumulated_time)) | |
252 | |
253 signal.setitimer(signal.ITIMER_PROF, | |
254 state.sample_interval, 0.0) | |
255 state.last_start_time = now | |
256 | |
257 stopthread = threading.Event() | |
258 def samplerthread(tid): | |
259 while not stopthread.is_set(): | |
260 now = clock() | |
261 state.accumulate_time(now) | |
262 | |
263 frame = sys._current_frames()[tid] | |
264 state.samples.append(Sample.from_frame(frame, state.accumulated_time)) | |
265 | |
266 state.last_start_time = now | |
267 time.sleep(state.sample_interval) | |
268 | |
269 stopthread.clear() | |
270 | |
271 ########################################################################### | |
272 ## Profiling API | |
273 | |
274 def is_active(): | |
275 return state.profile_level > 0 | |
276 | |
277 lastmechanism = None | |
278 def start(mechanism='thread'): | |
279 '''Install the profiling signal handler, and start profiling.''' | |
280 state.profile_level += 1 | |
281 if state.profile_level == 1: | |
282 state.last_start_time = clock() | |
283 rpt = state.remaining_prof_time | |
284 state.remaining_prof_time = None | |
285 | |
286 global lastmechanism | |
287 lastmechanism = mechanism | |
288 | |
289 if mechanism == 'signal': | |
290 signal.signal(signal.SIGPROF, profile_signal_handler) | |
291 signal.setitimer(signal.ITIMER_PROF, | |
292 rpt or state.sample_interval, 0.0) | |
293 elif mechanism == 'thread': | |
294 frame = inspect.currentframe() | |
295 tid = [k for k, f in sys._current_frames().items() if f == frame][0] | |
296 state.thread = threading.Thread(target=samplerthread, | |
297 args=(tid,), name="samplerthread") | |
298 state.thread.start() | |
299 | |
300 def stop(): | |
301 '''Stop profiling, and uninstall the profiling signal handler.''' | |
302 state.profile_level -= 1 | |
303 if state.profile_level == 0: | |
304 if lastmechanism == 'signal': | |
305 rpt = signal.setitimer(signal.ITIMER_PROF, 0.0, 0.0) | |
306 signal.signal(signal.SIGPROF, signal.SIG_IGN) | |
307 state.remaining_prof_time = rpt[0] | |
308 elif lastmechanism == 'thread': | |
309 stopthread.set() | |
310 state.thread.join() | |
311 | |
312 state.accumulate_time(clock()) | |
313 state.last_start_time = None | |
314 statprofpath = os.environ.get('STATPROF_DEST') | |
315 save_data(statprofpath) | |
316 | |
317 def save_data(path=None): | |
318 try: | |
319 path = path or (os.environ['HOME'] + '/statprof.data') | |
320 file = open(path, "w+") | |
321 | |
322 file.write(str(state.accumulated_time) + '\n') | |
323 for sample in state.samples: | |
324 time = str(sample.time) | |
325 stack = sample.stack | |
326 sites = ['\1'.join([s.path, str(s.lineno), s.function]) | |
327 for s in stack] | |
328 file.write(time + '\0' + '\0'.join(sites) + '\n') | |
329 | |
330 file.close() | |
331 except (IOError, OSError) as ex: | |
332 # The home directory probably didn't exist, or wasn't writable. Oh well. | |
333 pass | |
334 | |
335 def load_data(path=None): | |
336 path = path or (os.environ['HOME'] + '/statprof.data') | |
337 lines = open(path, 'r').read().splitlines() | |
338 | |
339 state.accumulated_time = float(lines[0]) | |
340 state.samples = [] | |
341 for line in lines[1:]: | |
342 parts = line.split('\0') | |
343 time = float(parts[0]) | |
344 rawsites = parts[1:] | |
345 sites = [] | |
346 for rawsite in rawsites: | |
347 siteparts = rawsite.split('\1') | |
348 sites.append(CodeSite.get(siteparts[0], int(siteparts[1]), | |
349 siteparts[2])) | |
350 | |
351 state.samples.append(Sample(sites, time)) | |
352 | |
353 | |
354 | |
355 def reset(frequency=None): | |
356 '''Clear out the state of the profiler. Do not call while the | |
357 profiler is running. | |
358 | |
359 The optional frequency argument specifies the number of samples to | |
360 collect per second.''' | |
361 assert state.profile_level == 0, "Can't reset() while statprof is running" | |
362 CodeSite.cache.clear() | |
363 state.reset(frequency) | |
364 | |
365 | |
366 @contextmanager | |
367 def profile(): | |
368 start() | |
369 try: | |
370 yield | |
371 finally: | |
372 stop() | |
373 display() | |
374 | |
375 | |
376 ########################################################################### | |
377 ## Reporting API | |
378 | |
379 class SiteStats(object): | |
380 def __init__(self, site): | |
381 self.site = site | |
382 self.selfcount = 0 | |
383 self.totalcount = 0 | |
384 | |
385 def addself(self): | |
386 self.selfcount += 1 | |
387 | |
388 def addtotal(self): | |
389 self.totalcount += 1 | |
390 | |
391 def selfpercent(self): | |
392 return self.selfcount / len(state.samples) * 100 | |
393 | |
394 def totalpercent(self): | |
395 return self.totalcount / len(state.samples) * 100 | |
396 | |
397 def selfseconds(self): | |
398 return self.selfcount * state.seconds_per_sample() | |
399 | |
400 def totalseconds(self): | |
401 return self.totalcount * state.seconds_per_sample() | |
402 | |
403 @classmethod | |
404 def buildstats(cls, samples): | |
405 stats = {} | |
406 | |
407 for sample in samples: | |
408 for i, site in enumerate(sample.stack): | |
409 sitestat = stats.get(site) | |
410 if not sitestat: | |
411 sitestat = SiteStats(site) | |
412 stats[site] = sitestat | |
413 | |
414 sitestat.addtotal() | |
415 | |
416 if i == 0: | |
417 sitestat.addself() | |
418 | |
419 return [s for s in stats.itervalues()] | |
420 | |
421 class DisplayFormats: | |
422 ByLine = 0 | |
423 ByMethod = 1 | |
424 AboutMethod = 2 | |
425 Hotpath = 3 | |
426 FlameGraph = 4 | |
427 Json = 5 | |
428 | |
429 def display(fp=None, format=3, **kwargs): | |
430 '''Print statistics, either to stdout or the given file object.''' | |
431 | |
432 if fp is None: | |
433 import sys | |
434 fp = sys.stdout | |
435 if len(state.samples) == 0: | |
436 print >> fp, ('No samples recorded.') | |
437 return | |
438 | |
439 if format == DisplayFormats.ByLine: | |
440 display_by_line(fp) | |
441 elif format == DisplayFormats.ByMethod: | |
442 display_by_method(fp) | |
443 elif format == DisplayFormats.AboutMethod: | |
444 display_about_method(fp, **kwargs) | |
445 elif format == DisplayFormats.Hotpath: | |
446 display_hotpath(fp, **kwargs) | |
447 elif format == DisplayFormats.FlameGraph: | |
448 write_to_flame(fp, **kwargs) | |
449 elif format == DisplayFormats.Json: | |
450 write_to_json(fp) | |
451 else: | |
452 raise Exception("Invalid display format") | |
453 | |
454 if format != DisplayFormats.Json: | |
455 print >> fp, ('---') | |
456 print >> fp, ('Sample count: %d' % len(state.samples)) | |
457 print >> fp, ('Total time: %f seconds' % state.accumulated_time) | |
458 | |
459 def display_by_line(fp): | |
460 '''Print the profiler data with each sample line represented | |
461 as one row in a table. Sorted by self-time per line.''' | |
462 stats = SiteStats.buildstats(state.samples) | |
463 stats.sort(reverse=True, key=lambda x: x.selfseconds()) | |
464 | |
465 print >> fp, ('%5.5s %10.10s %7.7s %-8.8s' % | |
466 ('% ', 'cumulative', 'self', '')) | |
467 print >> fp, ('%5.5s %9.9s %8.8s %-8.8s' % | |
468 ("time", "seconds", "seconds", "name")) | |
469 | |
470 for stat in stats: | |
471 site = stat.site | |
472 sitelabel = '%s:%d:%s' % (site.filename(), site.lineno, site.function) | |
473 print >> fp, ('%6.2f %9.2f %9.2f %s' % (stat.selfpercent(), | |
474 stat.totalseconds(), | |
475 stat.selfseconds(), | |
476 sitelabel)) | |
477 | |
478 def display_by_method(fp): | |
479 '''Print the profiler data with each sample function represented | |
480 as one row in a table. Important lines within that function are | |
481 output as nested rows. Sorted by self-time per line.''' | |
482 print >> fp, ('%5.5s %10.10s %7.7s %-8.8s' % | |
483 ('% ', 'cumulative', 'self', '')) | |
484 print >> fp, ('%5.5s %9.9s %8.8s %-8.8s' % | |
485 ("time", "seconds", "seconds", "name")) | |
486 | |
487 stats = SiteStats.buildstats(state.samples) | |
488 | |
489 grouped = defaultdict(list) | |
490 for stat in stats: | |
491 grouped[stat.site.filename() + ":" + stat.site.function].append(stat) | |
492 | |
493 # compute sums for each function | |
494 functiondata = [] | |
495 for fname, sitestats in grouped.iteritems(): | |
496 total_cum_sec = 0 | |
497 total_self_sec = 0 | |
498 total_percent = 0 | |
499 for stat in sitestats: | |
500 total_cum_sec += stat.totalseconds() | |
501 total_self_sec += stat.selfseconds() | |
502 total_percent += stat.selfpercent() | |
503 | |
504 functiondata.append((fname, | |
505 total_cum_sec, | |
506 total_self_sec, | |
507 total_percent, | |
508 sitestats)) | |
509 | |
510 # sort by total self sec | |
511 functiondata.sort(reverse=True, key=lambda x: x[2]) | |
512 | |
513 for function in functiondata: | |
514 if function[3] < 0.05: | |
515 continue | |
516 print >> fp, ('%6.2f %9.2f %9.2f %s' % (function[3], # total percent | |
517 function[1], # total cum sec | |
518 function[2], # total self sec | |
519 function[0])) # file:function | |
520 function[4].sort(reverse=True, key=lambda i: i.selfseconds()) | |
521 for stat in function[4]: | |
522 # only show line numbers for significant locations (>1% time spent) | |
523 if stat.selfpercent() > 1: | |
524 source = stat.site.getsource(25) | |
525 stattuple = (stat.selfpercent(), stat.selfseconds(), | |
526 stat.site.lineno, source) | |
527 | |
528 print >> fp, ('%33.0f%% %6.2f line %s: %s' % (stattuple)) | |
529 | |
530 def display_about_method(fp, function=None, **kwargs): | |
531 if function is None: | |
532 raise Exception("Invalid function") | |
533 | |
534 filename = None | |
535 if ':' in function: | |
536 filename, function = function.split(':') | |
537 | |
538 relevant_samples = 0 | |
539 parents = {} | |
540 children = {} | |
541 | |
542 for sample in state.samples: | |
543 for i, site in enumerate(sample.stack): | |
544 if site.function == function and (not filename | |
545 or site.filename() == filename): | |
546 relevant_samples += 1 | |
547 if i != len(sample.stack) - 1: | |
548 parent = sample.stack[i + 1] | |
549 if parent in parents: | |
550 parents[parent] = parents[parent] + 1 | |
551 else: | |
552 parents[parent] = 1 | |
553 | |
554 if site in children: | |
555 children[site] = children[site] + 1 | |
556 else: | |
557 children[site] = 1 | |
558 | |
559 parents = [(parent, count) for parent, count in parents.iteritems()] | |
560 parents.sort(reverse=True, key=lambda x: x[1]) | |
561 for parent, count in parents: | |
562 print >> fp, ('%6.2f%% %s:%s line %s: %s' % | |
563 (count / relevant_samples * 100, parent.filename(), | |
564 parent.function, parent.lineno, parent.getsource(50))) | |
565 | |
566 stats = SiteStats.buildstats(state.samples) | |
567 stats = [s for s in stats | |
568 if s.site.function == function and | |
569 (not filename or s.site.filename() == filename)] | |
570 | |
571 total_cum_sec = 0 | |
572 total_self_sec = 0 | |
573 total_self_percent = 0 | |
574 total_cum_percent = 0 | |
575 for stat in stats: | |
576 total_cum_sec += stat.totalseconds() | |
577 total_self_sec += stat.selfseconds() | |
578 total_self_percent += stat.selfpercent() | |
579 total_cum_percent += stat.totalpercent() | |
580 | |
581 print >> fp, ( | |
582 '\n %s:%s Total: %0.2fs (%0.2f%%) Self: %0.2fs (%0.2f%%)\n' % | |
583 ( | |
584 filename or '___', | |
585 function, | |
586 total_cum_sec, | |
587 total_cum_percent, | |
588 total_self_sec, | |
589 total_self_percent | |
590 )) | |
591 | |
592 children = [(child, count) for child, count in children.iteritems()] | |
593 children.sort(reverse=True, key=lambda x: x[1]) | |
594 for child, count in children: | |
595 print >> fp, (' %6.2f%% line %s: %s' % | |
596 (count / relevant_samples * 100, child.lineno, child.getsource(50))) | |
597 | |
598 def display_hotpath(fp, limit=0.05, **kwargs): | |
599 class HotNode(object): | |
600 def __init__(self, site): | |
601 self.site = site | |
602 self.count = 0 | |
603 self.children = {} | |
604 | |
605 def add(self, stack, time): | |
606 self.count += time | |
607 site = stack[0] | |
608 child = self.children.get(site) | |
609 if not child: | |
610 child = HotNode(site) | |
611 self.children[site] = child | |
612 | |
613 if len(stack) > 1: | |
614 i = 1 | |
615 # Skip boiler plate parts of the stack | |
616 while i < len(stack) and '%s:%s' % (stack[i].filename(), stack[i].function) in skips: | |
617 i += 1 | |
618 if i < len(stack): | |
619 child.add(stack[i:], time) | |
620 | |
621 root = HotNode(None) | |
622 lasttime = state.samples[0].time | |
623 for sample in state.samples: | |
624 root.add(sample.stack[::-1], sample.time - lasttime) | |
625 lasttime = sample.time | |
626 | |
627 def _write(node, depth, multiple_siblings): | |
628 site = node.site | |
629 visiblechildren = [c for c in node.children.itervalues() | |
630 if c.count >= (limit * root.count)] | |
631 if site: | |
632 indent = depth * 2 - 1 | |
633 filename = '' | |
634 function = '' | |
635 if len(node.children) > 0: | |
636 childsite = list(node.children.itervalues())[0].site | |
637 filename = (childsite.filename() + ':').ljust(15) | |
638 function = childsite.function | |
639 | |
640 # lots of string formatting | |
641 listpattern = ''.ljust(indent) +\ | |
642 ('\\' if multiple_siblings else '|') +\ | |
643 ' %4.1f%% %s %s' | |
644 liststring = listpattern % (node.count / root.count * 100, | |
645 filename, function) | |
646 codepattern = '%' + str(55 - len(liststring)) + 's %s: %s' | |
647 codestring = codepattern % ('line', site.lineno, site.getsource(30)) | |
648 | |
649 finalstring = liststring + codestring | |
650 childrensamples = sum([c.count for c in node.children.itervalues()]) | |
651 # Make frames that performed more than 10% of the operation red | |
652 if node.count - childrensamples > (0.1 * root.count): | |
653 finalstring = '\033[91m' + finalstring + '\033[0m' | |
654 # Make frames that didn't actually perform work dark grey | |
655 elif node.count - childrensamples == 0: | |
656 finalstring = '\033[90m' + finalstring + '\033[0m' | |
657 print >> fp, finalstring | |
658 | |
659 newdepth = depth | |
660 if len(visiblechildren) > 1 or multiple_siblings: | |
661 newdepth += 1 | |
662 | |
663 visiblechildren.sort(reverse=True, key=lambda x: x.count) | |
664 for child in visiblechildren: | |
665 _write(child, newdepth, len(visiblechildren) > 1) | |
666 | |
667 if root.count > 0: | |
668 _write(root, 0, False) | |
669 | |
670 def write_to_flame(fp, scriptpath=None, outputfile=None, **kwargs): | |
671 if scriptpath is None: | |
672 scriptpath = os.environ['HOME'] + '/flamegraph.pl' | |
673 if not os.path.exists(scriptpath): | |
674 print >> fp, "error: missing %s" % scriptpath | |
675 print >> fp, "get it here: https://github.com/brendangregg/FlameGraph" | |
676 return | |
677 | |
678 fd, path = tempfile.mkstemp() | |
679 | |
680 file = open(path, "w+") | |
681 | |
682 lines = {} | |
683 for sample in state.samples: | |
684 sites = [s.function for s in sample.stack] | |
685 sites.reverse() | |
686 line = ';'.join(sites) | |
687 if line in lines: | |
688 lines[line] = lines[line] + 1 | |
689 else: | |
690 lines[line] = 1 | |
691 | |
692 for line, count in lines.iteritems(): | |
693 file.write("%s %s\n" % (line, count)) | |
694 | |
695 file.close() | |
696 | |
697 if outputfile is None: | |
698 outputfile = '~/flamegraph.svg' | |
699 | |
700 os.system("perl ~/flamegraph.pl %s > %s" % (path, outputfile)) | |
701 print "Written to %s" % outputfile | |
702 | |
703 def write_to_json(fp): | |
704 samples = [] | |
705 | |
706 for sample in state.samples: | |
707 stack = [] | |
708 | |
709 for frame in sample.stack: | |
710 stack.append((frame.path, frame.lineno, frame.function)) | |
711 | |
712 samples.append((sample.time, stack)) | |
713 | |
714 print >> fp, json.dumps(samples) | |
715 | |
716 def printusage(): | |
717 print """ | |
718 The statprof command line allows you to inspect the last profile's results in | |
719 the following forms: | |
720 | |
721 usage: | |
722 hotpath [-l --limit percent] | |
723 Shows a graph of calls with the percent of time each takes. | |
724 Red calls take over 10%% of the total time themselves. | |
725 lines | |
726 Shows the actual sampled lines. | |
727 functions | |
728 Shows the samples grouped by function. | |
729 function [filename:]functionname | |
730 Shows the callers and callees of a particular function. | |
731 flame [-s --script-path] [-o --output-file path] | |
732 Writes out a flamegraph to output-file (defaults to ~/flamegraph.svg) | |
733 Requires that ~/flamegraph.pl exist. | |
734 (Specify alternate script path with --script-path.)""" | |
735 | |
736 def main(argv=None): | |
737 if argv is None: | |
738 argv = sys.argv | |
739 | |
740 if len(argv) == 1: | |
741 printusage() | |
742 return 0 | |
743 | |
744 displayargs = {} | |
745 | |
746 optstart = 2 | |
747 displayargs['function'] = None | |
748 if argv[1] == 'hotpath': | |
749 displayargs['format'] = DisplayFormats.Hotpath | |
750 elif argv[1] == 'lines': | |
751 displayargs['format'] = DisplayFormats.ByLine | |
752 elif argv[1] == 'functions': | |
753 displayargs['format'] = DisplayFormats.ByMethod | |
754 elif argv[1] == 'function': | |
755 displayargs['format'] = DisplayFormats.AboutMethod | |
756 displayargs['function'] = argv[2] | |
757 optstart = 3 | |
758 elif argv[1] == 'flame': | |
759 displayargs['format'] = DisplayFormats.FlameGraph | |
760 else: | |
761 printusage() | |
762 return 0 | |
763 | |
764 # process options | |
765 try: | |
766 opts, args = getopt.getopt(sys.argv[optstart:], "hl:f:o:p:", | |
767 ["help", "limit=", "file=", "output-file=", "script-path="]) | |
768 except getopt.error as msg: | |
769 print msg | |
770 printusage() | |
771 return 2 | |
772 | |
773 displayargs['limit'] = 0.05 | |
774 path = None | |
775 for o, value in opts: | |
776 if o in ("-l", "--limit"): | |
777 displayargs['limit'] = float(value) | |
778 elif o in ("-f", "--file"): | |
779 path = value | |
780 elif o in ("-o", "--output-file"): | |
781 displayargs['outputfile'] = value | |
782 elif o in ("-p", "--script-path"): | |
783 displayargs['scriptpath'] = value | |
784 elif o in ("-h", "help"): | |
785 printusage() | |
786 return 0 | |
787 else: | |
788 assert False, "unhandled option %s" % o | |
789 | |
790 load_data(path=path) | |
791 | |
792 display(**displayargs) | |
793 | |
794 return 0 | |
795 | |
796 if __name__ == "__main__": | |
797 sys.exit(main()) |