asottile / importtime-waterfall

Generate waterfalls from `-Ximporttime` tracing.

importtime-waterfall

Generate waterfalls from -Ximporttime tracing.

install

pip install importtime-waterfall

note: importtime-waterfall requires python3.7+

usage

importtime-waterfall provides a single executable by the same name.

importtime-waterfall takes a module name as a positional argument. This is the module that will be profiled.

--include-interpreter-startup

Include tracing information of modules that are always imported as part of interpreter startup. These are usually not interesting and so they are left out by default.

--har

Output as an HTTP Archive or "HAR" file. Yes these aren't actual HTTP requests but it's an easy way to get a visualization using a standardized data format.

HAR unfortunaly doesn't have microsecond resolution so all times in the HAR output are * 1000 (1 μs => 1ms).

The easiest way to use the output of this is to paste it into a har viewer.

I use the following:

$ importtime-waterfall importtime_waterfall --har | xclip -selection c

xclip takes the output and puts it onto the clipboard. Alternatively, you can redirect to a file (> foo.har) and upload it that way.

Once pasted into the viewer you can inspect the output.

The blocked import time is represented as "waiting" (purple) and the self time is represented as "receiving" (grey). Generally when looking for slow modules look for ones with large grey chunks.

--graph

(this is the default display). Display the output as a tree. This doesn't really add much on top of what python -Ximporttime already displays (but was useful for developing / debugging this tool). I guess it's in human order instead of reversed so that's something 🤷.

Times displayed next to the module names are self-times in μs.

$ importtime-waterfall importtime_waterfall
importtime_waterfall (419)
  argparse (864)
    re (599)
      enum (661)
      sre_compile (270)
        _sre (109)
        sre_parse (336)
          sre_constants (339)
      copyreg (161)
    gettext (1056)
      locale (820)
  datetime (768)
    time (234)
    math (57)
    _datetime (154)
  json (254)
    json.decoder (446)
      json.scanner (481)
        _json (193)
    json.encoder (443)
  subprocess (628)
    signal (1030)
    errno (101)
    _posixsubprocess (40)
    select (51)
    selectors (543)
      collections.abc (184)
    threading (578)
      traceback (394)
        linecache (162)
          tokenize (911)
            token (178)
      _weakrefset (217)
  typing (1469)

success stories

I used this to find a 24% speedup in flake8's startup.

nitty-gritty how it works

importtime-waterfall imports the profiled module in a subprocess while setting the -Ximporttime flag. importtime-waterfall picks the best-of-5 (by total time) and uses that result. It parses the "import time:" lines and then outputs.

importtime-waterfall's Issues

(optionally) limit the depth of the --graph output

(follow-up to #93)

Sometimes, it's useful to limit the depth of the --graph output; e.g. to get a summary to paste in an issue, or because the output is too large to follow easily (and one doesn't need it to descend into external dependencies).

Proposed implementation: a --max-depth X option (like in #93). Example output here.

output to google's trace format?

https://docs.google.com/document/d/1CvAClvFfyA5R-PhYUmn5OOQtYMH4h6I0nSsKchNAySU/preview

No executable command provided and no output

Hello,

I can't get this package to work at all. I installed via pip (21.3.1) and python3.9 and I can successfully import it in python.

The entry point doesn't appear for me in bash (Mac OS 11.6.1, python3.9 from macports). Can't see how to execute or use this manually through python - no instructions for this. I tried:

python -X importtime_waterfall --har ~/importmypackage.py

where importmypackage.py just does import mypackage. This works fine with the regular importtime.

The above command runs but produces no output whatsover. No print out, no files.

Sort --graph output by cumulative time

(follow-up to #93)

It would be useful to sort the modules in the --graph output that have the same "parent" by cumulative time, descending (and also show it for each module). Example output here.

The reasoning is when using this to optimize imports, one is mostly interested in modules that take the most time.

In the simplest implementation, this would be the only order (like in #93); sorting by name or self time doesn't seem very useful (idem for the "default" order?). Barring this, a -s cumulative|none option would also work (a la cProfile).

Cannot install on python-3.10

This is on Arch Linux, with latest updates. Python is 3.10.4

Please let me know if you need additional information.

$ pip install --user importtime-waterfall
Collecting importtime-waterfall
  Downloading importtime_waterfall-1.0.0-py2.py3-none-any.whl (5.9 kB)
WARNING: Discarding https://files.pythonhosted.org/packages/1d/5c/a299cf9f5748cc13f506934e2fa3ea5bbc9584946c0a773dc5104cb770f2/importtime_waterfall-1.0.0-py2.py3-none-any.whl#sha256=e65dbc4d23f0fd698ca3e8cfe767937b86f697e11790ac672aa86109792b3595 (from https://pypi.org/simple/importtime-waterfall/) (requires-python:>=3.7). Requested importtime-waterfall from https://files.pythonhosted.org/packages/1d/5c/a299cf9f5748cc13f506934e2fa3ea5bbc9584946c0a773dc5104cb770f2/importtime_waterfall-1.0.0-py2.py3-none-any.whl#sha256=e65dbc4d23f0fd698ca3e8cfe767937b86f697e11790ac672aa86109792b3595 has inconsistent version: filename has '1.0.0', but metadata has '1.0.0'
  Downloading importtime_waterfall-1.0.0.tar.gz (5.5 kB)
WARNING: Discarding https://files.pythonhosted.org/packages/0c/f8/0d33c4d69344cb55116a656ef103b499f69a5f33f748ac0cd32c297cc955/importtime_waterfall-1.0.0.tar.gz#sha256=8140eb8e1774a39d426df82220f36b17d78ccbbba2adc75466979a315395f391 (from https://pypi.org/simple/importtime-waterfall/) (requires-python:>=3.7). Requested importtime-waterfall from https://files.pythonhosted.org/packages/0c/f8/0d33c4d69344cb55116a656ef103b499f69a5f33f748ac0cd32c297cc955/importtime_waterfall-1.0.0.tar.gz#sha256=8140eb8e1774a39d426df82220f36b17d78ccbbba2adc75466979a315395f391 has inconsistent version: filename has '1.0.0', but metadata has '1.0.0'
  Downloading importtime_waterfall-0.0.0-py2.py3-none-any.whl (4.3 kB)
WARNING: Discarding https://files.pythonhosted.org/packages/d7/b0/b4fe097c99f1cac840b6c2d84b7e0b544c9e408980527fbe4d828f77025f/importtime_waterfall-0.0.0-py2.py3-none-any.whl#sha256=7be00b0e032c3f1730aa44cae6eeb49e5d8b9c60a6ee430df8d6d5d9ed6c2a12 (from https://pypi.org/simple/importtime-waterfall/) (requires-python:>=3.7). Requested importtime-waterfall from https://files.pythonhosted.org/packages/d7/b0/b4fe097c99f1cac840b6c2d84b7e0b544c9e408980527fbe4d828f77025f/importtime_waterfall-0.0.0-py2.py3-none-any.whl#sha256=7be00b0e032c3f1730aa44cae6eeb49e5d8b9c60a6ee430df8d6d5d9ed6c2a12 has inconsistent version: filename has '0.0.0', but metadata has '0.0.0'
  Downloading importtime_waterfall-0.0.0.tar.gz (4.3 kB)
WARNING: Discarding https://files.pythonhosted.org/packages/ae/10/d861ebbbcc3b40e2bf3a1b24e2c16ceed41b80711a67101c5d6f9cbf7c97/importtime_waterfall-0.0.0.tar.gz#sha256=4d270c529c5c1abeeb33d83ae5a1f9c50a7cca93bf5ebddb49b8fa2a1b7cd51c (from https://pypi.org/simple/importtime-waterfall/) (requires-python:>=3.7). Requested importtime-waterfall from https://files.pythonhosted.org/packages/ae/10/d861ebbbcc3b40e2bf3a1b24e2c16ceed41b80711a67101c5d6f9cbf7c97/importtime_waterfall-0.0.0.tar.gz#sha256=4d270c529c5c1abeeb33d83ae5a1f9c50a7cca93bf5ebddb49b8fa2a1b7cd51c has inconsistent version: filename has '0.0.0', but metadata has '0.0.0'
ERROR: Could not find a version that satisfies the requirement importtime-waterfall
ERROR: No matching distribution found for importtime-waterfall

Or via cloning:

$ git clone https://github.com/asottile/importtime-waterfall
$ cd importtime-waterfall
$ pip install --user .
Processing /home/REDACTED/tmp/importtime-waterfall
ERROR: Exception:
Traceback (most recent call last):
  File "/usr/lib/python3.10/site-packages/pip/_internal/cli/base_command.py", line 189, in _main
    status = self.run(options, args)
  File "/usr/lib/python3.10/site-packages/pip/_internal/cli/req_command.py", line 178, in wrapper
    return func(self, options, args)
  File "/usr/lib/python3.10/site-packages/pip/_internal/commands/install.py", line 316, in run
    requirement_set = resolver.resolve(
  File "/usr/lib/python3.10/site-packages/pip/_internal/resolution/resolvelib/resolver.py", line 121, in resolve
    self._result = resolver.resolve(
  File "/usr/lib/python3.10/site-packages/resolvelib/resolvers.py", line 454, in resolve
    state = resolution.resolve(requirements, max_rounds=max_rounds)
  File "/usr/lib/python3.10/site-packages/resolvelib/resolvers.py", line 319, in resolve
    name, crit = self._merge_into_criterion(r, parent=None)
  File "/usr/lib/python3.10/site-packages/resolvelib/resolvers.py", line 176, in _merge_into_criterion
    crit = Criterion.from_requirement(self._p, requirement, parent)
  File "/usr/lib/python3.10/site-packages/resolvelib/resolvers.py", line 80, in from_requirement
    cands = build_iter_view(matches)
  File "/usr/lib/python3.10/site-packages/resolvelib/structs.py", line 148, in build_iter_view
    matches = list(matches)
  File "/usr/lib/python3.10/site-packages/pip/_internal/resolution/resolvelib/factory.py", line 283, in <genexpr>
    if constraint.is_satisfied_by(c)
  File "/usr/lib/python3.10/site-packages/pip/_internal/resolution/resolvelib/base.py", line 66, in is_satisfied_by
    return self.specifier.contains(candidate.version, prereleases=True)
  File "/usr/lib/python3.10/site-packages/packaging/specifiers.py", line 790, in contains
    item = parse(item)
  File "/usr/lib/python3.10/site-packages/packaging/version.py", line 57, in parse
    return Version(version)
  File "/usr/lib/python3.10/site-packages/packaging/version.py", line 296, in __init__
    match = self._regex.search(version)
TypeError: expected string or bytes-like object

Profiling django manage.py runserver

I came here from this post https://forum.djangoproject.com/t/slow-runserver-start-up-how-to-debug/15078 from @adamchainz

I am trying to do

$ importtime-waterfall --include-interpreter-startup manage.py runserver
usage: importtime-waterfall [-h] [--include-interpreter-startup]
                            [--graph | --har]
                            module
importtime-waterfall: error: unrecognized arguments: runserver

However this does not work, seems I can only add a single word/command as "module"argument

however python3 -Ximporttime manage.py runserver works. Any idea how I can use your package so I can get a better visual of manage.py runserver (final aim is to understand why it is slow)

Django Support

Hi,

Please add django support for detecting the slow loading.

Thanks.