Swapping Two Imports Moved 5.5 ms to a Different Module

-X importtime prints two numbers per module and almost every import cost quoted in public is the second one. The documentation is precise about what it contains: it “shows module name, cumulative time (including nested imports) and self time (excluding nested imports)”. What it does not say is that the containing is decided by order, and that a module already in sys.modules produces no line at all.

Import asyncio and then logging, and the report charges asyncio 23.5 ms and never mentions logging. Import them the other way round and logging is charged 5.6 ms and asyncio 18.0. Nothing about the program changed.

The same two imports, swapped

$ python3 experiments/importtime/attribution.py
python 3.13.2 on darwin
median of 9 processes each, warm filesystem cache

the same two imports, swapped

program                        first      second      total
import asyncio, logging      23.5 ms    (nested)    23.5 ms
import logging, asyncio       5.6 ms     18.0 ms    23.6 ms

import unittest, typing      11.2 ms      1.0 ms    12.2 ms
import typing, unittest       2.1 ms      9.8 ms    11.9 ms

import dataclasses, typing    6.9 ms      0.9 ms     7.8 ms
import typing, dataclasses    2.3 ms      6.0 ms     8.2 ms

what `import asyncio` is charged, given what is already resident

already imported                     charged   modules added
nothing                              22.6 ms             100
logging                              17.1 ms              69
typing                               20.6 ms              86
logging, typing                      15.7 ms              67
logging, typing, re, functools       15.3 ms              67

(the bare interpreter holds 36 modules)

a generated package with one shared subtree

program                        alpha      beta   shared self
import alpha, beta            6.4 ms    0.1 ms        3.7 ms
import beta, alpha            0.1 ms    6.3 ms        3.7 ms

The (nested) cell is the whole mechanism. When asyncio goes first it imports logging itself, so logging appears indented inside asyncio’s subtree and never gets a top-level line of its own. Its 5.6 ms is inside asyncio’s 23.5.

The totals are the control. 23.5 against 23.6, 12.2 against 11.9, 7.8 against 8.2: the program does the same work either way, and the swap redistributes it.

The other two pairs are the same effect without the containment. unittest does not import typing at all — after import unittest, typing is not in sys.modules — and swapping them still moves a millisecond. typing costs 2.1 ms first and 1.0 ms second, because unittest has already loaded part of what typing needs. Neither module is inside the other; they overlap, and the report gives the overlap to whichever ran first.

Why the second importer looks free

An import is executed once per process. The second import logging finds the module in sys.modules, binds the name and returns, and on 3.13 that costs nothing and prints nothing. The report has no row for work that did not happen, which is correct, and no row for work that happened on someone else’s line, which is what misleads.

That is why the report cannot be read as a bill. A bill has one line per thing bought; this has one line per thing bought first. Two modules that share three-quarters of their dependencies produce a report in which one of them appears to cost four times the other, and moving one statement above another rewrites it.

The generated package removes any doubt that this is a property of the report rather than of asyncio. Two modules, alpha and beta, each importing one shared module whose body compiles four hundred regular expressions:

$ python3 -X importtime -c "import alpha, beta" 2>&1 | grep -E "alpha|beta|shared"
import time:      3618 |       6014 |   shared
import time:        68 |       6082 | alpha
import time:        69 |         69 | beta

alpha is charged 6,082 µs and beta 69. The difference between them is the order they were written in. On 3.14 the same program under -X importtime=2 says so out loud:

$ python3.14 -X importtime=2 -c "import alpha, beta" 2>&1 | grep -E "alpha|beta|shared"
import time:      3142 |       3142 |   shared
import time:        68 |       3209 | alpha
import time: cached    | cached     | shared
import time:        65 |         65 | beta

The cached line is new in 3.14 and it is the row 3.13 does not print. It carries no time, so the arithmetic is still manual, but beta’s dependence on shared is at least visible. The two versions load different modules at startup, so their millisecond figures are not comparable with each other; the shape is the point.

Asking the question that has an answer

“What does asyncio cost” has no version that a single number answers. What a program can answer is what removing it would give back, and that is a marginal measurement: import everything else first, then import the candidate, and read what the second step is charged.

The context block above does that. Alone, asyncio is charged 22.6 ms and adds 100 modules. With logging, typing, re and functools already resident — four imports a service is likely to have — it is charged 15.3 ms and adds 67. Roughly a third of the headline figure is modules that were going to be loaded regardless of whether asyncio was in the program.

That is also the rule for reading someone else’s number. A benchmark that imports one library into a bare interpreter measures the library plus the standard library subtree it happens to touch first. The same library, dropped into an application that already imports half of that subtree, costs less, and the published figure gives no way to tell how much less.

It cuts the other way in a dependency review. A package that looks cheap in a report may be cheap only because it was measured second, and the cost it appears to avoid is sitting on the line above it. The test that settles it is removal: take the import out, run the program’s real entry point, and compare the two startups. Anything else is reading an attribution.

Where to stop

One machine, warm filesystem cache, CPython 3.13.2 with one 3.14.7 output shown for its shape. Every figure is the median of nine processes.

The absolute numbers drift. This harness charged import asyncio 20.8 ms in one run and 23.5 in another, on the same machine minutes apart, and the published entry that measured it with a different harness got 21.9. Comparisons here are within a single run, between two lines of the same table, and that is the only kind this measurement supports.

Nothing here says how to make an import cheaper — deferring it is a separate question with a separate answer. This entry says which number to stop quoting: the cumulative figure beside a module’s name is a fact about the program that imported it first.