From 747bca61f1f5f2ad2de6f7aa6ec4044c8ff98157 Mon Sep 17 00:00:00 2001 From: mattip Date: Thu, 8 Oct 2026 16:40:11 +0300 Subject: [PATCH 1/2] add a kcachegrind-compatible profile printer --- vmprof/show.py | 118 ++++++++++++++++++++++++++++++++++++ vmprof/test/test_show.py | 126 +++++++++++++++++++++++++++++++++++++++ 2 files changed, 244 insertions(+) create mode 100644 vmprof/test/test_show.py diff --git a/vmprof/show.py b/vmprof/show.py index afcf5e8..d9f784d 100644 --- a/vmprof/show.py +++ b/vmprof/show.py @@ -24,6 +24,8 @@ def __new__(cls, content, color, bold=False): cls, "%s%s%s%s" % (color, cls.BOLD if bold else "", content, cls.END)) class AbstractPrinter(object): + _stats = None + def show(self, profile): """ Read and display a vmprof profile file. @@ -42,6 +44,7 @@ def show(self, profile): sys.stderr.write(msg) try: + self._stats = stats tree = stats.get_tree() self._show(tree) except EmptyProfileFile as e: @@ -260,6 +263,109 @@ def collect_node(parent, node): funline=ndescr.funline)) +def _callgrind_position(descr): + """ The (file, function, line) triple callgrind should use for a node. + + Python and native frames carry a file and a line, JIT frames only carry + the address of the generated code, and anything else is unknown. + """ + if descr.filename is not None and descr.funline is not None: + filename = descr.filename if descr.filename != '-' else '???' + try: + lineno = int(descr.funline) + except ValueError: + lineno = 0 + return filename, descr.funname, lineno + if descr.block_type is not None: + return '[%s]' % descr.block_type, descr.funname, 0 + return '???', descr.funname, 0 + + +class CallgrindPrinter(AbstractPrinter): + """ + Write a profile as a callgrind file, for kcachegrind and qcachegrind. + + The exported event is ``Periods``: a sample is weighted by the time + since the previous one, in units of the sampling period, so costs are + proportional to time rather than to how many signals got delivered. + See ``LogReader.sample_weight``. Multiply by the period to get time, + ~0.99ms per unit by default. + + Being a sampling profiler vmprof never sees individual calls, so every + call edge is written as ``calls=1``: treat kcachegrind's call counts as + "this edge was observed", not as a number of calls. Self cost is + attributed to the line a function is defined on, because the call tree + does not record which line each call was made from. Use + ``vmprofshow lines`` for per-line numbers. + """ + + def __init__(self, output=None): + self.output = output + + def _show(self, tree): + self_cost, edges = self._collect(tree) + if self.output is None: + self._write(sys.stdout, self_cost, edges) + else: + with open(self.output, 'w') as fd: + self._write(fd, self_cost, edges) + + def _collect(self, tree): + """ Fold the call tree into per-function self cost and call edges. + + A function shows up once per path through the tree, so costs are + summed per function and kcachegrind is left to work out recursion. + """ + self_cost = {} + edges = {} + + pending = [tree] + while pending: + node = pending.pop() + descr = parse_block_name(node.name) + self_cost[descr] = self_cost.get(descr, 0) + node.self_count + for child in node.children.values(): + key = (descr, parse_block_name(child.name)) + edges[key] = edges.get(key, 0) + child.count + pending.append(child) + + return self_cost, edges + + def _write(self, fd, self_cost, edges): + callees = {} + for (caller, callee), cost in edges.items(): + callees.setdefault(caller, []).append((callee, cost)) + + positions = dict((descr, _callgrind_position(descr)) + for descr in self_cost) + total = sum(int(round(cost)) for cost in self_cost.values()) + + fd.write("# callgrind format\n") + fd.write("version: 1\n") + fd.write("creator: vmprof\n") + argv = self._stats.getargv() if self._stats is not None else '' + if argv: + fd.write("cmd: %s\n" % argv.replace('\n', ' ')) + fd.write("positions: line\n") + fd.write("events: Periods\n") + fd.write("summary: %d\n" % total) + + for descr in sorted(self_cost, key=lambda d: positions[d]): + filename, funname, lineno = positions[descr] + fd.write("\n") + fd.write("fl=%s\n" % filename) + fd.write("fn=%s\n" % funname) + fd.write("%d %d\n" % (lineno, int(round(self_cost[descr])))) + # every node was walked, so a callee always has a position + for callee, cost in sorted(callees.get(descr, []), + key=lambda item: positions[item[0]]): + cfile, cfunname, clineno = positions[callee] + fd.write("cfl=%s\n" % cfile) + fd.write("cfn=%s\n" % cfunname) + fd.write("calls=1 %d\n" % clineno) + fd.write("%d %d\n" % (lineno, int(round(cost)))) + + class LinesPrinter(AbstractPrinter): def __init__(self, filter=None): self.filter = filter @@ -397,6 +503,16 @@ def main(): parser_flat.add_argument('--percent-cutoff', type=float, default=0) parser_flat.set_defaults(mode='flat') + parser_callgrind = subp.add_parser( + "callgrind", + help="Write a callgrind file for kcachegrind/qcachegrind.") + parser_callgrind.add_argument( + '--output', '-o', + metavar='file.callgrind', + default=None, + help='Write to this file instead of stdout.') + parser_callgrind.set_defaults(mode='callgrind') + args = parser.parse_args() mode = getattr(args, 'mode', None) @@ -412,6 +528,8 @@ def main(): include_callees=args.include_callees, no_native=args.no_native, percent_cutoff=args.percent_cutoff) + elif mode == 'callgrind': + pp = CallgrindPrinter(output=args.output) elif mode == 'tree': if args.html: cls = HTMLPrettyPrinter diff --git a/vmprof/test/test_show.py b/vmprof/test/test_show.py new file mode 100644 index 0000000..0b27e14 --- /dev/null +++ b/vmprof/test/test_show.py @@ -0,0 +1,126 @@ +import re + +from vmprof.show import CallgrindPrinter +from vmprof.stats import Node + + +def build_tree(): + """ A tree covering python, native and JIT frames. + + 100 samples, 10 of them its own + `-- work 80 samples, 50 of them its own + `-- JIT code 30 + `-- memcpy 10, native and without a filename + """ + root = Node(1, 'py::1:prog.py', 100) + work = root.add_child(2, 'py:work:10:prog.py', 80) + work.add_child(3, 'jit:0x1234', 30) + root.add_child(4, 'n:memcpy:0:-', 10) + return root + + +def write_callgrind(tmpdir, tree): + path = str(tmpdir.join('out.callgrind')) + printer = CallgrindPrinter(output=path) + printer._show(tree) + with open(path) as fd: + return fd.read() + + +def parse_callgrind(text): + """ Minimal callgrind reader: self cost per fn and the call edges. """ + self_cost = {} + edges = {} + pos = None + callee = None + for line in text.splitlines(): + if line.startswith('fl='): + filename = line[3:] + elif line.startswith('fn='): + pos = (filename, line[3:]) + self_cost.setdefault(pos, 0) + callee = None + elif line.startswith('cfl='): + cfilename = line[4:] + elif line.startswith('cfn='): + callee = (cfilename, line[4:]) + elif line.startswith('calls='): + pass + elif re.match(r'^\d+ \d+$', line): + cost = int(line.split()[1]) + if callee is not None: + edges[(pos, callee)] = cost + callee = None + else: + self_cost[pos] += cost + return self_cost, edges + + +def test_callgrind_header(tmpdir): + text = write_callgrind(tmpdir, build_tree()) + assert text.startswith('# callgrind format\n') + assert 'positions: line\n' in text + assert 'events: Periods\n' in text + assert 'summary: 100\n' in text + + +def test_callgrind_self_cost(tmpdir): + self_cost, _ = parse_callgrind(write_callgrind(tmpdir, build_tree())) + assert self_cost == { + ('prog.py', ''): 10, + ('prog.py', 'work'): 50, + ('[jit]', '0x1234'): 30, + ('???', 'memcpy'): 10, + } + # the summary has to match what the body adds up to + assert sum(self_cost.values()) == 100 + + +def test_callgrind_edges_carry_inclusive_cost(tmpdir): + _, edges = parse_callgrind(write_callgrind(tmpdir, build_tree())) + assert edges == { + (('prog.py', ''), ('prog.py', 'work')): 80, + (('prog.py', ''), ('???', 'memcpy')): 10, + (('prog.py', 'work'), ('[jit]', '0x1234')): 30, + } + + +def test_callgrind_every_callee_is_defined(tmpdir): + self_cost, edges = parse_callgrind(write_callgrind(tmpdir, build_tree())) + for _, callee in edges: + assert callee in self_cost + + +def test_callgrind_folds_repeated_functions(tmpdir): + """ A function reached by two paths is reported once, with costs summed. """ + root = Node(1, 'py::1:prog.py', 100) + left = root.add_child(2, 'py:left:10:prog.py', 60) + right = root.add_child(3, 'py:right:20:prog.py', 40) + # same addr, so the same function, under two different callers + left.add_child(4, 'py:leaf:30:prog.py', 50) + right.add_child(4, 'py:leaf:30:prog.py', 30) + + self_cost, edges = parse_callgrind(write_callgrind(tmpdir, root)) + assert self_cost[('prog.py', 'leaf')] == 80 + assert edges[(('prog.py', 'left'), ('prog.py', 'leaf'))] == 50 + assert edges[(('prog.py', 'right'), ('prog.py', 'leaf'))] == 30 + + +def test_callgrind_rounds_fractional_weights(tmpdir): + """ Sample weights are floats once the profile carries timestamps. + + Costs are rounded on the way out, so the summary is the sum of what + was actually written rather than the unrounded total: the tools check + the former, and a rounding drift of a sample does not matter here. + """ + root = Node(1, 'py::1:prog.py', 10.4) + root.add_child(2, 'py:work:10:prog.py', 4.6) + + text = write_callgrind(tmpdir, root) + for line in text.splitlines(): + if re.match(r'^\d+ ', line): + assert re.match(r'^\d+ \d+$', line), line + + self_cost, _ = parse_callgrind(text) + summary = int(re.search(r'^summary: (\d+)$', text, re.M).group(1)) + assert summary == sum(self_cost.values()) From d84537ff7d44fc71cb2ed5f8306c39b7fff32c7a Mon Sep 17 00:00:00 2001 From: mattip Date: Thu, 8 Oct 2026 16:47:34 +0300 Subject: [PATCH 2/2] rework documentation --- README.md | 94 ++++++++++++++++++++++++++++------ docs/data.rst | 19 ------- docs/development.rst | 109 +++++++++++++++------------------------ docs/faq.rst | 18 ++++--- docs/index.rst | 23 +++++---- docs/jitlog.rst | 36 ++++++++----- docs/native.rst | 4 +- docs/query.rst | 5 -- docs/viewers.rst | 119 +++++++++++++++++++++++++++++++++++++++++++ docs/vmprof.rst | 83 +++++++++--------------------- 10 files changed, 312 insertions(+), 198 deletions(-) delete mode 100644 docs/data.rst create mode 100644 docs/viewers.rst diff --git a/README.md b/README.md index d8fb61d..53b4078 100644 --- a/README.md +++ b/README.md @@ -1,10 +1,12 @@ # VMProf Python package -[![Build Status on TravisCI](https://travis-ci.org/vmprof/vmprof-python.svg?branch=master)](https://travis-ci.org/vmprof/vmprof-python) -[![Build Status on TeamCity](https://teamcity.jetbrains.com/app/rest/builds/buildType:(id:VMprofPython_TestsPy27Win)/statusIcon.svg)](https://teamcity.jetbrains.com/project.html?projectId=VMprofPython) +[![Tests](https://github.com/vmprof/vmprof-python/actions/workflows/tests.yml/badge.svg)](https://github.com/vmprof/vmprof-python/actions/workflows/tests.yml) +[![Wheels](https://github.com/vmprof/vmprof-python/actions/workflows/cibuildwheel.yml/badge.svg)](https://github.com/vmprof/vmprof-python/actions/workflows/cibuildwheel.yml) [![Read The Docs](https://readthedocs.org/projects/vmprof/badge/?version=latest)](https://vmprof.readthedocs.org/en/latest/) -[![Build Status on AppVeyor](https://ci.appveyor.com/api/projects/status/github/vmprof/vmprof-python?branch=master&svg=true)](https://ci.appveyor.com/project/planrich/vmprof-python) +**VMProf** is a lightweight statistical profiler for CPython and PyPy. It samples +the call stack of a running program and writes a profile file you can open in +several viewers. Head over to https://vmprof.readthedocs.org for more info! @@ -12,26 +14,84 @@ Head over to https://vmprof.readthedocs.org for more info! ```console pip install vmprof -python -m vmprof ``` -Our build system ships wheels to PyPI (Linux, Mac OS X). If you build from source you need -to install CPython development headers and libunwind headers (on Linux only). -On Windows this means you need Microsoft Visual C++ Compiler for your Python version. +VMProf 0.6 supports CPython 3.10 through 3.14 and PyPy, on Linux, Mac OS X and +Windows. Native profiling is available on Linux and Mac OS X. + +Wheels are published to PyPI for all three platforms with libunwind bundled in. +If you build from source you need the CPython development headers, and on Linux +the libunwind headers as well — on Debian or Ubuntu, `python3-dev` and +`libunwind-dev`. On Windows you need the Microsoft Visual C++ Compiler for your +Python version. + +## Quick start + +Record a profile: + +```console +$ python -m vmprof -o profile.prof +``` + +Then open `profile.prof` in whichever viewer fits the question you're asking: + +| Viewer | Good for | How | +| --- | --- | --- | +| `vmprofshow` | a quick look, no extra installs | `vmprofshow profile.prof tree` | +| [Firefox Profiler](https://profiler.firefox.com) | flame graph, timeline | `python -m vmprofconvert -convert profile.prof` | +| [kcachegrind](https://kcachegrind.github.io/) | callers/callees, call graph | `vmprofshow profile.prof callgrind -o profile.callgrind` | + +Running `python -m vmprof` without `-o` prints basic statistics and keeps no +file. + +### Firefox Profiler + +The [vmprof-firefox-converter](https://github.com/Cskorpion/vmprof-firefox-converter) +converts a profile into a format the Firefox Profiler UI reads, giving you a +flame graph, a stack chart over time and an inverted call tree in the browser. +It understands PyPy's JIT frames too — see +[the announcement post](https://pypy.org/posts/2024/05/vmprof-firefox-converter.html) +for a tour. + +```console +$ python -m pip install vmprof-firefox-converter +$ python -m vmprofconvert -convert profile.prof +``` + +### kcachegrind + +`vmprofshow` can write the profile in callgrind format, which kcachegrind (or +`qcachegrind` on Mac OS X and Windows) reads: + +```console +$ vmprofshow profile.prof callgrind -o profile.callgrind +$ kcachegrind profile.callgrind +``` + +The exported event is `Periods`: each sample is weighted by the time since the +previous one, in units of the sampling period, so costs are proportional to time +spent. At the default ~1kHz one unit is about 0.99ms. + +Since vmprof samples the stack rather than instrumenting calls, it has no call +counts — every call edge is written as `calls=1`, so ignore kcachegrind's call +count column. Self cost is attributed to the line a function is defined on; use +`vmprofshow profile.prof lines` when you need line-level numbers. ## Development Setting up development can be done using the following commands: - $ virtualenv -p /usr/bin/python3 vmprof3 + $ python3 -m venv vmprof3 $ source vmprof3/bin/activate $ pip install meson-python meson ninja $ pip install --no-build-isolation --editable . You need to install python development packages. In case of e.g. Debian or Ubuntu the package you need is `python3-dev` and `libunwind-dev`. -Now it is time to write a test and implement your feature. If you want -your changes to affect vmprof.com, head over to -https://github.com/vmprof/vmprof-server and follow the setup instructions. + +Run the tests with: + + $ pip install pytest cffi setuptools + $ python -m pytest vmprof/ Consult our section for development at https://vmprof.readthedocs.org for more information. @@ -128,7 +188,7 @@ helpful when functions exist that get called from multiple places, where each invocation does not consume much time, but all invocations taken together do amount to a substantial cost. ```console -$ vmprofshow vmprof_cpuburn.dat flat andreask_work@dunkel 15:24 +$ vmprofshow vmprof_cpuburn.dat flat 28.895% - _PyFunction_Vectorcall:/home/conda/feedstock_root/build_artifacts/python-split_1608956461873/work/Objects/call.c:389 18.076% - _iterate:cpuburn.py:20 17.298% - _next_rand:cpuburn.py:15 @@ -148,7 +208,7 @@ $ vmprofshow vmprof_cpuburn.dat flat ``` Sometimes it may be desirable to exclude "native" functions: ```console -$ vmprofshow vmprof_cpuburn.dat flat --no-native andreask_work@dunkel 15:27 +$ vmprofshow vmprof_cpuburn.dat flat --no-native 53.191% - _next_rand:cpuburn.py:15 46.809% - _iterate:cpuburn.py:20 0.000% - test:cpuburn.py:36 @@ -159,8 +219,8 @@ functions called. (In `--no-native` mode, native-code callees remain included in the total.) Sometimes it may also be desirable to get timings *inclusive* of called functions: -``` -$ vmprofshow vmprof_cpuburn.dat flat --include-callees andreask_work@dunkel 15:31 +```console +$ vmprofshow vmprof_cpuburn.dat flat --include-callees 100.000% - :-:0 100.000% - test:cpuburn.py:36 100.000% - burn:cpuburn.py:27 @@ -179,3 +239,7 @@ $ vmprofshow vmprof_cpuburn.dat flat --include-callees 0.356% - :/home/conda/feedstock_root/build_artifacts/python-split_1608956461873/work/Objects/longobject.c:3432 ``` This view is quite similar to the "tree" view, minus the nesting. + +### Callgrind output + +See [kcachegrind](#kcachegrind) above. diff --git a/docs/data.rst b/docs/data.rst deleted file mode 100644 index d6aefca..0000000 --- a/docs/data.rst +++ /dev/null @@ -1,19 +0,0 @@ -Data sent to vmprof.com -======================= - -We only send the bare essentials to `vmprof.com`_. This package is no spy software. - -It includes the following data: - -* The full command line -* The name of the interpreter used -* Filesystem path names, function names and line numbers of to your scripts -* Generic system information (Operating system, CPU word size, ...) - -If jit log data is sent (--jitlog) on PyPy the following is also included: - -* Meta data the JIT compiler produces. E.g. IR operations, Machine code -* Source code snippets: `vmprof.com`_ will receive source lines of your program. Only those are transmitted that ran often enough to trigger the JIT compiler to optimize your program. - -.. _`vmprof.com`: http://vmprof.com -.. _`PyPy`: http://pypy.org diff --git a/docs/development.rst b/docs/development.rst index 685ecec..8346c4a 100644 --- a/docs/development.rst +++ b/docs/development.rst @@ -1,94 +1,65 @@ Develop VMProf ============== -VMProf consists of several projects working together: - -* `vmprof-python`_: The PyPI package providing the command line interface to enable vmprof. -* `vmprof-server`_: Webservice hosted at `vmprof.com`_. Hosts and visualizes data uploaded by `vmprof-python`_ package. -* `vmprof-integration`_: Test suite for pulling together all different projects and ensuring that all play together nicely. -* `PyPy`_: A virtual machine for the Python programming language. Most notably it contains an implementation for the logging facility `vmprof-server`_ can display. - -The following description helps you to set up a development environment on Linux. For Windows -and MacOSX the instructions might be similar. +vmprof is made up of a Python package and a C extension, built with +`meson-python`_. The `PyPy`_ side of the JIT log support lives in PyPy itself. +.. _`meson-python`: https://mesonbuild.com/meson-python/ .. _`PyPy`: http://pypy.org -.. _`vmprof.com`: http://vmprof.com .. _`vmprof-python`: https://github.com/vmprof/vmprof-python -.. _`vmprof-server`: https://github.com/vmprof/vmprof-server -.. _`vmprof-integration`: https://github.com/vmprof/vmprof-integration - -Develop VMProf on Linux ------------------------ - -It is recommended to use Python 3.x for development. Here is a list of requirements -on your system: - -* python -* sqlite3 -* virtualenv - -Please move you shell to the location you store your source code in and setup -a virtual environment:: - $ virtualenv -p /usr/bin/python3 vmprof3 - $ source vmprof3/bin/activate - -All commands from now on assume you have the vmprof3 virutal environment enabled. - -Clone the repositories ----------------------- +Setting up +---------- -:: +Create a virtual environment and install vmprof in editable mode:: - $ git clone git@github.com:vmprof/vmprof-integration.git - $ git clone git@github.com:vmprof/vmprof-server.git $ git clone git@github.com:vmprof/vmprof-python.git - # on old mercurial version the following command takes ages. please use a recent version - $ hg clone ssh://hg@bitbucket.org/pypy/pypy # optional, only if you want to hack on pypy as well - -VMProf Server -------------- - -:: - - # setup django service - $ cd vmprof-server - $ pip install -r requirements/development.txt - $ python manage.py migrate - # to run the service - $ python manage.py runserver -v 3 - -VMProf Python -------------- - -An optional stage. It is only necessary if you want to co develop `vmprof-python`_ with `vmprof-server`_:: - - # install vmprof for development (only needed if you want to co develop vmprof-python) $ cd vmprof-python + $ python3 -m venv vmprof3 + $ source vmprof3/bin/activate $ pip install meson-python meson ninja $ pip install --no-build-isolation --editable . +Because the build is ``--no-build-isolation``, the C extension is rebuilt on +import when you change anything under ``src/``, so there is no separate build +step while developing. -Now you are able to change both the python package and the server and see the results. -Here are some more hints on how to develop this platform +You need your distribution's Python development headers, and on Linux the +libunwind headers as well. On Debian or Ubuntu those are ``python3-dev`` and +``libunwind-dev``. -Smaller Profiles ----------------- +Running the tests +----------------- + +:: -Some times it is tedious to generate a big log file and develop a new feature with it. -Both for VMProf and JitLog you can generate small log files that ease development. + $ pip install pytest cffi setuptools + $ python -m pytest vmprof/ -There are small logs generated by a python script in `vmprof-server/vmlog/test/data/loggen.py`. Use the following command to load those:: +Some tests build small C extensions to exercise native profiling, which is why +``cffi`` and a compiler are needed. - $ ./manage.py loaddata vmlog/test/fixtures.yaml +Smaller profiles +---------------- -Now open your browser and redirect them to the jitlog. E.g. http://localhost:8000/#/1v1/traces +Reading a profile of a long run is tedious while working on a feature. The +``vmprof/test/`` directory holds small recorded profiles, and +``vmprof/test/cpuburn.py`` generates fresh ones:: -Integration Tests ------------------ + $ python -m vmprof -o profile.prof vmprof/test/cpuburn.py -This is a very important test suite to ensure that all packages work together. It is automatically run every day by travis. You can run them locally. If you happen not to run a Debian base distribution, you can provide the following shell variable to prevent the tests from downloading a Debian PyPy:: +Working on the output modes +--------------------------- - $ TEST_PYPY_EXEC=/path/to/pypy py.test testvmprof/ +The viewers in :doc:`viewers` all read the same profile file, so a profile +recorded once can be replayed through every mode while you iterate:: + $ vmprofshow profile.prof tree + $ vmprofshow profile.prof flat + $ vmprofshow profile.prof callgrind -o profile.callgrind +The printers live in ``vmprof/show.py``. Each one subclasses +``AbstractPrinter`` and implements ``_show(tree)``, where ``tree`` is the +``Node`` tree built by ``Stats.get_tree()``; see ``vmprof/stats.py`` for what a +node carries. ``vmprof/test/test_show.py`` builds ``Node`` trees by hand, which +is the quickest way to test a new output mode without recording anything. diff --git a/docs/faq.rst b/docs/faq.rst index f632d77..b5eee41 100644 --- a/docs/faq.rst +++ b/docs/faq.rst @@ -9,22 +9,24 @@ Frequently Asked Questions * **Is it possible to just profile a part of my program?**: Yes here an example how you could do just that:: - with open('test.prof', 'w+b') as fd: + with open('profile.prof', 'w+b') as fd: vmprof.enable(fd.fileno()) my_function_or_program() vmprof.disable() - Upload it later to vmprof.com if you choose to inspect it further:: + Then open ``profile.prof`` in any of the viewers described in + :doc:`viewers`. - $ python -m vmprof.upload test.prof - - - -* **What do the colors on vmprof.com mean?**: For plain CPython there is no particular meaning, we might change - that in the future. For PyPy we have a color coding to show at which state the VM sampled (e.g. JIT, Warmup, ...). +* **Which viewer should I use?**: ``vmprofshow`` is bundled and needs nothing + installed, the Firefox Profiler gives you a flame graph and a timeline, and + kcachegrind gives you caller and callee lists and a call graph. See + :doc:`viewers`. * **My Windows profile is malformed?**: Please ensure that you open the file in binary mode. Otherwise Windows will transform ``\n`` to ``\r\n``. * **Do I need to install libunwind?**: Usually not. We ship python wheels that bundle libunwind shared objects. If you install vmprof from source, then you need to install the development headers of your distribution. OSX ships libunwind per default. If your pip version is really old it does not pull wheels and it will end up compiling from source. +* **Why are the call counts in kcachegrind all 1?**: Because vmprof samples + the stack rather than instrumenting calls, so it never sees an individual + call and cannot count them. See :doc:`viewers`. diff --git a/docs/index.rst b/docs/index.rst index eef8b10..e0062ca 100644 --- a/docs/index.rst +++ b/docs/index.rst @@ -7,30 +7,33 @@ | | -VMProf Platform -=============== +vmprof +====== -`vmprof`_ is a platform to understand and resolve performance bottlenecks in your code. -It includes a *lightweight profiler* for `CPython`_ 2.7, `CPython`_ 3 and `PyPy`_ -and an assembler log visualizer for `PyPy`_. Currently we support Linux, Mac OS X and Windows. +`vmprof`_ is a lightweight `statistical profiler`_ for `CPython`_ 3.10+ and +`PyPy`_, along with an assembler log reader for `PyPy`_. It runs on Linux, +Mac OS X and Windows. -The following provides more information about CPU profiles and JIT Compiler Logs: +Profiling writes a profile file, which you open in the viewer of your choice: +the bundled ``vmprofshow``, the Firefox Profiler, or kcachegrind:: + + pip install vmprof + python -m vmprof -o profile.prof + vmprofshow profile.prof tree .. toctree:: :maxdepth: 2 vmprof + viewers faq - development native format jitlog query - data + development .. _`CPython`: http://python.org .. _`PyPy`: http://pypy.org .. _`vmprof`: https://github.com/vmprof/vmprof-python .. _`statistical profiler`: https://en.wikipedia.org/wiki/Profiling_(computer_programming)#Statistical_profilers -.. _`gperftools`: https://code.google.com/p/gperftools/ -.. _`vtune`: https://software.intel.com/en-us/intel-vtune-amplifier-xe diff --git a/docs/jitlog.rst b/docs/jitlog.rst index a093ab3..285318b 100644 --- a/docs/jitlog.rst +++ b/docs/jitlog.rst @@ -9,23 +9,35 @@ It was built primarily for the following use cases: * Track down speed issues * Help bug reporting -This version is now integrated within the webservice `vmprof.com`_ and can be used free of charge. - Usage ===== -The following commands show example usages:: +Recording a JIT log alongside a CPU profile writes it next to the profile, +with a ``.jit`` suffix:: + + pypy -m vmprof --jitlog -o profile.prof + # writes profile.prof and profile.prof.jit + +To record only the JIT log, without profiling:: + + pypy -m jitlog -o profile.jit + +This also works when your program crashes, since the log is written as it +goes: run it, let it segfault, and the log is still there to inspect. + +Viewing a JIT log +================= + +The `vmprof-firefox-converter`_ can fold a JIT log, and PyPy's own log, into +the same Firefox Profiler view as the CPU profile:: - # upload both vmprof & jitlog profiles - pypy -m vmprof --web --jitlog + PYPYLOG=profile.pypylog pypy -m vmprof --jitlog -o profile.prof + python -m vmprofconvert -convert profile.prof -jitlog profile.prof.jit -pypylog profile.pypylog - # upload only a jitlog profile - pypy -m jitlog --web +To read traces in the terminal, use the query interface described in +:doc:`query`:: - # upload a jitlog when your program segfaults/crashes - $ pypy -m jitlog -o /tmp/file.log - - $ pypy -m jitlog --upload /tmp/file.log + pypy -m jitlog profile.jit -q 'bridges & op("int_add_ovf")' -.. _`vmprof.com`: http://vmprof.com +.. _`vmprof-firefox-converter`: https://github.com/Cskorpion/vmprof-firefox-converter .. _`PyPy`: http://pypy.org diff --git a/docs/native.rst b/docs/native.rst index f7c979a..96f3947 100644 --- a/docs/native.rst +++ b/docs/native.rst @@ -16,8 +16,8 @@ Technical Design Native sampling utilizes ``libunwind`` in the signal handler to unwind the stack. Each stack frame is inspected until the frame evaluation function is encountered. Then the stack walking -switches back to the traditional Python frame walking. Callbacks (Python frame -> ... C frame ... -> Python frame -> - C frame) +switches back to the traditional Python frame walking. Callbacks (Python frame -> +... C frame ... -> Python frame -> C frame) will not display intermediate native functions. It would give the impression that the first C frame was never called, but it will show the second C frame. diff --git a/docs/query.rst b/docs/query.rst index 2a46ed2..0c5b64c 100644 --- a/docs/query.rst +++ b/docs/query.rst @@ -27,17 +27,12 @@ Now run the following command to generate the log:: # run your program and output the log pypy -m vmprof -o log.jit example.py -This generates the file that normally is sent to `vmprof.com`_ whenever -`--web` is provided. - The query interface is a the flag '-q' which incooperates a small query language. Here is an example:: pypy -m jitlog log.jit -q 'bridges & op("int_add_ovf")' ... # will print the filtered traces -.. _`vmprof.com`: http://vmprof.com - Query API --------- diff --git a/docs/viewers.rst b/docs/viewers.rst new file mode 100644 index 0000000..925f769 --- /dev/null +++ b/docs/viewers.rst @@ -0,0 +1,119 @@ +================ +Viewing Profiles +================ + +vmprof writes a profile to a plain file on your machine, and that file is the +only thing the viewers need. Nothing is uploaded anywhere. + +Record a profile +================ + +Pass ``-o`` to get a profile file:: + + python -m vmprof -o profile.prof + +Add ``--lines`` if you also want per-line numbers inside functions:: + + python -m vmprof --lines -o profile.prof + +From here, pick whichever of the viewers below suits the question you are +asking. + +In the terminal: vmprofshow +=========================== + +``vmprofshow`` ships with vmprof and needs nothing else installed. It has +three modes. + +``tree`` shows where time goes from the root of the call graph down:: + + vmprofshow profile.prof tree + +``--html`` writes the same tree as a page with branches you can expand and +collapse:: + + vmprofshow profile.prof tree --html > profile.html + +``flat`` aggregates per function instead, which is the view you want when a +function is called from many places and no single call site looks expensive:: + + vmprofshow profile.prof flat + +``lines`` shows the cost of individual lines, for profiles recorded with +``--lines``:: + + vmprofshow profile.prof lines --filter + +Flame graphs and timelines: the Firefox Profiler +================================================ + +The `vmprof-firefox-converter`_ turns a profile into something the `Firefox +Profiler`_ UI can read, which gets you a flame graph, a stack chart over time, +an inverted call tree and a source view, all in the browser. It understands +PyPy's JIT frames too. See the `announcement post`_ for a tour with +screenshots. + +Install it:: + + python -m pip install vmprof-firefox-converter + +Convert a profile you already recorded, which opens the Firefox Profiler on +it:: + + python -m vmprofconvert -convert profile.prof + +Add ``--nobrowser`` to only write the converted profile. You can also skip the +two steps and profile straight into the viewer:: + + python -m vmprofconvert -run + +On PyPy you can fold the JIT and interpreter logs into the same view:: + + PYPYLOG=profile.pypylog pypy -m vmprof --jitlog -o profile.prof + python -m vmprofconvert -convert profile.prof -jitlog profile.prof.jit -pypylog profile.pypylog + +.. _`vmprof-firefox-converter`: https://github.com/Cskorpion/vmprof-firefox-converter +.. _`Firefox Profiler`: https://profiler.firefox.com +.. _`announcement post`: https://pypy.org/posts/2024/05/vmprof-firefox-converter.html + +Call graphs: kcachegrind +======================== + +``vmprofshow`` can write a profile in `callgrind`_ format, which `kcachegrind`_ +(or ``qcachegrind`` on Mac OS X and Windows) reads. That gives you the callee +and caller lists, the call graph view and sorting by self or inclusive cost:: + + vmprofshow profile.prof callgrind -o profile.callgrind + kcachegrind profile.callgrind + +Without ``-o`` the callgrind data goes to stdout. The same file also works +with ``callgrind_annotate``, if you would rather stay in a terminal:: + + vmprofshow profile.prof callgrind -o profile.callgrind + callgrind_annotate profile.callgrind + +Three things about this export are worth knowing, because they follow from +vmprof being a sampling profiler: + +* The event is called ``Periods``, not instruction or cycle counts. Each + sample is weighted by the time since the previous one, in units of the + sampling period, so a cost is proportional to time spent rather than to + the number of signals that happened to be delivered. Multiply by the + period to get time: with the default ~1kHz, one unit is about 0.99ms, so + a cost of 1000 is roughly a second. + +* Call counts are not measured. vmprof never observes an individual call, so + every edge is written as ``calls=1``. Read kcachegrind's call count column + as "this call was seen", and ignore the numbers in it. + +* Self cost is attributed to the line a function is defined on, since the + profile does not record which line each call was made from. kcachegrind's + source annotation will therefore put a function's whole cost on its ``def`` + line. Use ``vmprofshow profile.prof lines`` when you need line level detail. + +Functions reached by more than one path are folded together, so a function +appears once with its costs summed, and recursion shows up as a cycle that +kcachegrind detects on its own. + +.. _`callgrind`: https://valgrind.org/docs/manual/cl-format.html +.. _`kcachegrind`: https://kcachegrind.github.io/ diff --git a/docs/vmprof.rst b/docs/vmprof.rst index 524c404..c6c9b72 100644 --- a/docs/vmprof.rst +++ b/docs/vmprof.rst @@ -10,25 +10,18 @@ very helpful to profile higher-level languages which run on top of a virtual machine, while vmprof is designed specifically for them. vmprof is also thread safe and will correctly display the information regardless of usage of threads. -There are three primary modes. The recommended one is to use our server -infrastructure for a web-based visualization of the result:: - - python -m vmprof --web - -If you prefer a barebone terminal-based visualization, which will display only -some basic statistics:: +Profiling a program writes a profile file, which you then open in a viewer. +To get a quick overview in the terminal:: python -m vmprof -To display a terminal-based tree of calls:: - - python -m vmprof -o output.log - - vmprofshow output.log +To keep the profile around, which is what you want for every viewer other +than the one above:: -To upload an already saved profile log to the vmprof web server:: + python -m vmprof -o profile.prof - python -m vmprof.upload output.log +That file can be read by the bundled ``vmprofshow`` command, by the Firefox +Profiler and by kcachegrind. :doc:`viewers` covers all three. For more advanced use cases, vmprof can be invoked and controlled from within the program using the given API. @@ -41,8 +34,8 @@ the program using the given API. Requirements ------------ -VMProf runs on x86_64 and x86. It supports Linux, Mac OS X and Windows running -CPython 2.7, 3.4, 3.5 and PyPy 4.1+. +vmprof 0.6 supports CPython 3.10 through 3.14 and PyPy, on Linux, Mac OS X and +Windows. Native profiling is available on Linux and Mac OS X. Installation ------------ @@ -51,30 +44,18 @@ Installation of ``vmprof`` is performed with a simple command:: pip install vmprof -PyPi ships wheels with libunwind shared objects (this means you need a recent version of pip). - -If you build VMProf from source you need to compile C code: - - sudo apt-get install python-dev - -.. _`CPython`: http://python.org -.. _`PyPy`: http://pypy.org - -We strongly suggest using the ``--web`` option that will display you a much -nicer web interface hosted on ``vmprof.com``. +PyPI ships wheels for Linux, Mac OS X and Windows, with the libunwind shared +objects bundled in. If you build from source you need the CPython development +headers, and on Linux the libunwind headers as well. On Debian or Ubuntu those +are the ``python3-dev`` and ``libunwind-dev`` packages. On Windows you need the +Microsoft Visual C++ compiler for your Python version. -If you prefer to host your own vmprof visualization server, you need the -`vmprof-server`_ package. +Command line options +-------------------- After ``-m vmprof`` you can specify some options: -* ``--web`` - Use the web-based visualization. By default, the result can be - viewed on our `server`_. - -* ``--web-url`` - the URL to upload the profiling info as JSON. The default is - ``vmprof.com`` - -* ``--web-auth`` - auth token for user name support in the server. +* ``-o file`` - save the profile to a file, to open in a viewer later. * ``-p period`` - seconds between profile runs, sets the profiling frequency. The value must be between 1e-6 and 1.0, and should not result in a round @@ -88,7 +69,9 @@ After ``-m vmprof`` you can specify some options: * ``--lines`` - enable line profiling mode. This mode adds some overhead to profiling, but in addition to function calls it marks the execution of the specific lines inside functions. -* ``-o file`` - save logs for later +* ``--mem`` - also record the total RSS of the process alongside the stacks. + +* ``--jitlog`` - on PyPy, also write the JIT compiler log. See :doc:`jitlog`. * ``--help`` - display help @@ -97,12 +80,8 @@ After ``-m vmprof`` you can specify some options: Example `config.ini` file:: [global] - web-url = vmprof.com - web-auth = ffb7d4bee2d6436bbe97e4d191bf7d23f85dfeb2 period = 0.0099 - -.. _`vmprof-server`: https://github.com/vmprof/vmprof-server -.. _`server`: http://vmprof.com + lines = True API @@ -180,7 +159,7 @@ None of the existing solutions satisfied our requirements, hence we decided to create our own profiler. In particular, cProfile is slow on PyPy, does not understand the JITted code very well and is shown in the JIT traces. -.. _`CProfile`: https://docs.python.org/2/library/profile.html +.. _`CProfile`: https://docs.python.org/3/library/profile.html .. _`lsprofcalltree.py`: https://pypi.python.org/pypi/lsprofcalltree .. _`plop`: https://github.com/bdarnell/plop @@ -196,9 +175,9 @@ approach used e.g. by `gperftools`_. However, when profiling an interpreter such as CPython, inspecting the C stack is not enough, because most of the time will always be spent inside the opcode -dispatching loop of the virtual machine (e.g., ``PyEval_EvalFrameEx`` in case -of CPython). To be able to display useful information, we need to know which -Python-level function correspond to each C-level ``PyEval_EvalFrameEx``. +dispatching loop of the virtual machine (e.g., ``_PyEval_EvalFrameDefault`` in +case of CPython). To be able to display useful information, we need to know +which Python-level function correspond to each C-level frame evaluation. This is done by reading the stack of Python frames instead of C stack. @@ -209,15 +188,3 @@ extract the relevant info from those as well. Once we have gathered all the low-level info, we can post-process and visualize them in various ways: for example, we can decide to filter out the places where we are inside the ``select()`` syscall, etc. - -The machinery to gather the information has been the focus of the initial -phase of vmprof development and now it is working well: we are currently -focusing on the frontend to make sure we can process and display the info in -useful ways. - -Links -===== - -* `vmprof-flamegraph `_ - Convert vmprof data into text format for - `flamegraph `_