Mercurial > hg
view mercurial/lsprofcalltree.py @ 46018:8b0a3ff5ed12
statprof: separate functions and "line", assume 4 digit line numbers
Previously, the profile output looked like this (I've removed many lines that
are mostly inconsequential):
```
| 100.0% 0.02s hg: <module> line 43: dispatch.run()
| 100.0% 0.02s dispatch.py: run line 115: status = dispatch(req)
| 100.0% 0.02s dispatch.py: _runcatchfunc line 432: return _dispatch(req)
\ 50.0% 0.01s dispatch.py: _dispatch line 1228: return runcommand(
| 50.0% 0.01s dispatch.py: runcommand line 883: ret = _runcommand(ui, optio...
| 50.0% 0.01s dispatch.py: _runcommand line 1240: return cmdfunc()
| 50.0% 0.01s localrepo.py: __getitem__ line 1670: quick_access = self._quick_...
| 50.0% 0.01s localrepo.py: _quick_access_changeidline 1650: return self._quick_access_c...
| 50.0% 0.01s localrepo.py: __get__ line 179: return getattr(unfi, self.n...
| 50.0% 0.01s util.py: __get__ line 1747: result = self.func(obj)
| 50.0% 0.01s localrepo.py: _quick_access_changeid_wcline 1611: cl = self.unfiltered().chan...
| 50.0% 0.01s localrepo.py: __get__ line 110: return super(_basefilecache...
| 50.0% 0.01s util.py: __getattribute__line 245: self.__spec__.loader.exec_m...
| 50.0% 0.01s <frozen importlib._bootstrap_external>: exec_moduleline 783:
| 50.0% 0.01s <frozen importlib._bootstrap>: _call_with_frames_removedline 219:
| 50.0% 0.01s changelog.py: <module> line 376: class changelog(revlog.revl...
| 50.0% 0.01s util.py: __getattribute__line 245: self.__spec__.loader.exec_m...
| 50.0% 0.01s <frozen importlib._bootstrap_external>: exec_moduleline 779:
| 50.0% 0.01s <frozen importlib._bootstrap_external>: get_codeline 868:
| 50.0% 0.01s <frozen importlib._bootstrap_external>: path_statsline 1012:
| 50.0% 0.01s <frozen importlib._bootstrap_external>: _path_statline 87:
```
This has a few problems, though I'm only addressing some of them.
1. If the stuff before "line ###" is long, there's no separation between the
function name and the "line" string.
2. If the stuff before "line ###" is really long, there's excessive separation
between the "line" string and the line number.
3. We frequently have 4-digit line numbers, the code on the right wasn't
dynamically indented and ended up quite messy looking.
To solve these problems, I've added a ", " prefix before "line" iff it would
otherwise not have any separation such as spaces. I've added a 'max' so that we
never use a negative width (which is the cause of problem #2 above), and I've
added a default assumption of 4 digit line numbers (but again using a 'max' so
this shouldn't cause problems if we go beyond that.
With these changes, it now looks like this:
```
| 100.0% 0.02s hg: <module> line 43: dispatch.run()
| 100.0% 0.02s dispatch.py: run line 115: status = dispatch(req)
| 100.0% 0.02s dispatch.py: _runcatchfunc line 432: return _dispatch(req)
\ 50.0% 0.01s dispatch.py: _dispatch line 1228: return runcommand(
| 50.0% 0.01s dispatch.py: runcommand line 883: ret = _runcommand(ui, optio...
| 50.0% 0.01s dispatch.py: _runcommand line 1240: return cmdfunc()
| 50.0% 0.01s localrepo.py: __getitem__ line 1670: quick_access = self._quick_...
| 50.0% 0.01s localrepo.py: _quick_access_changeid, line 1650: return self._quick_access_c...
| 50.0% 0.01s localrepo.py: __get__ line 179: return getattr(unfi, self.n...
| 50.0% 0.01s util.py: __get__ line 1747: result = self.func(obj)
| 50.0% 0.01s localrepo.py: _quick_access_changeid_wc, line 1611: cl = self.unfiltered().chan...
| 50.0% 0.01s localrepo.py: __get__ line 110: return super(_basefilecache...
| 50.0% 0.01s util.py: __getattribute__, line 245: self.__spec__.loader.exec_m...
| 50.0% 0.01s <frozen importlib._bootstrap_external>: exec_module, line 783:
| 50.0% 0.01s <frozen importlib._bootstrap>: _call_with_frames_removed, line 219:
| 50.0% 0.01s changelog.py: <module> line 376: class changelog(revlog.revl...
| 50.0% 0.01s util.py: __getattribute__, line 245: self.__spec__.loader.exec_m...
| 50.0% 0.01s <frozen importlib._bootstrap_external>: exec_module, line 779:
| 50.0% 0.01s <frozen importlib._bootstrap_external>: get_code, line 868:
| 50.0% 0.01s <frozen importlib._bootstrap_external>: path_stats, line 1012:
| 50.0% 0.01s <frozen importlib._bootstrap_external>: _path_stat, line 87:
```
Differential Revision: https://phab.mercurial-scm.org/D9511
author | Kyle Lippincott <spectral@google.com> |
---|---|
date | Wed, 02 Dec 2020 12:33:51 -0800 |
parents | 687b865b95ad |
children | 6000f5b25c9b |
line wrap: on
line source
""" lsprofcalltree.py - lsprof output which is readable by kcachegrind Authors: * David Allouche <david <at> allouche.net> * Jp Calderone & Itamar Shtull-Trauring * Johan Dahlin This software may be used and distributed according to the terms of the GNU General Public License, incorporated herein by reference. """ from __future__ import absolute_import from . import pycompat def label(code): if isinstance(code, str): # built-in functions ('~' sorts at the end) return b'~' + pycompat.sysbytes(code) else: return b'%s %s:%d' % ( pycompat.sysbytes(code.co_name), pycompat.sysbytes(code.co_filename), code.co_firstlineno, ) class KCacheGrind(object): def __init__(self, profiler): self.data = profiler.getstats() self.out_file = None def output(self, out_file): self.out_file = out_file out_file.write(b'events: Ticks\n') self._print_summary() for entry in self.data: self._entry(entry) def _print_summary(self): max_cost = 0 for entry in self.data: totaltime = int(entry.totaltime * 1000) max_cost = max(max_cost, totaltime) self.out_file.write(b'summary: %d\n' % max_cost) def _entry(self, entry): out_file = self.out_file code = entry.code if isinstance(code, str): out_file.write(b'fi=~\n') else: out_file.write(b'fi=%s\n' % pycompat.sysbytes(code.co_filename)) out_file.write(b'fn=%s\n' % label(code)) inlinetime = int(entry.inlinetime * 1000) if isinstance(code, str): out_file.write(b'0 %d\n' % inlinetime) else: out_file.write(b'%d %d\n' % (code.co_firstlineno, inlinetime)) # recursive calls are counted in entry.calls if entry.calls: calls = entry.calls else: calls = [] if isinstance(code, str): lineno = 0 else: lineno = code.co_firstlineno for subentry in calls: self._subentry(lineno, subentry) out_file.write(b'\n') def _subentry(self, lineno, subentry): out_file = self.out_file code = subentry.code out_file.write(b'cfn=%s\n' % label(code)) if isinstance(code, str): out_file.write(b'cfi=~\n') out_file.write(b'calls=%d 0\n' % subentry.callcount) else: out_file.write(b'cfi=%s\n' % pycompat.sysbytes(code.co_filename)) out_file.write( b'calls=%d %d\n' % (subentry.callcount, code.co_firstlineno) ) totaltime = int(subentry.totaltime * 1000) out_file.write(b'%d %d\n' % (lineno, totaltime))