Time taken by an import in Python

Question

I want to know how much time an import takes for both built-in as well as user defined modules.

Answer 1

Starting from Python3.7 releaese, new -X importtime option is available. To measure import time, just simply execute your script with that option, e.g. python -X importtime my_script.py.

For reference:

• https://docs.python.org/3.7/using/cmdline.html#id5

Answer 2

One way to profile imports is to use the profile_imports module used in bzr source code:

# put those two lines at the top of your script
import profile_imports
profile_imports.install()

# display the results
profile_imports.log_stack_info(sys.stderr)

Besides giving you timing for imports, this also estimates time to compile regex, which is often a significant cause for slowdown in imports.

Answer 3

You can test this runnning

$ time python -c "import math"

However, what would this help you? Importing only happens once and will almost never be a bottle neck. Importing the same module over and over will not run significantly slower than importing it once, since Python tracks which modules have already been imported.

What are you actually trying to achieve?

Answer 4

Tested on Windows in Python 2.4 - you can try it yourself.

>>> import time

>>> ## Built-in module
>>> def testTime():
        now = time.clock() # use time.time() on unix-based systems
        import math
        print time.clock() - now

>>> testTime()
7.54285810167e-006



>>> ## My own module
>>> def testTime():
        now = time.clock()
        import myBuiltInModule # Not its actual name ;-)
        print time.clock() - now

>>> testTime()
0.00253174635324
>>> testTime()
3.70158777141e-006

So there is a big difference between cached modules and those being brought in from scratch. To illustrate, we can reload the module:

>>> def testTime():
        now = time.clock()
        reload(myBuiltInModule )
        print time.clock() - now


>>> testTime()
0.00250017809526

Answer 5

Use cProfile:

python -m cProfile yourscript.py

Answer 6

I ran into this issue profiling a large legacy application with a multi-second startup time. It's relatively simple to replace the builtin importer with something that does some profiling. Below is a hacky way of showing approximately how long each module takes to execute:

import os
import sys
import time


class ImportEventNode(object):
    def __init__(self, name, start_time, children=None, end_time=None):
        self.name = name
        self.start_time = start_time
        self.children = [] if children is None else children
        self.end_time = end_time

    def __repr__(self):
        return 'ImportEventNode({self.name}, {self.start_time}, children={self.children}, end_time={self.end_time})'.format(self=self)

    @property
    def total_time(self):
        return self.end_time - self.start_time

    @property
    def net_time(self):
        return self.total_time - sum(child.total_time for child in self.children)


root_node = cur_node = None

all_nodes = []
old_import = __import__
def __import__(*args, **kwargs):
    global root_node, cur_node
    name = args[0]
    if name not in sys.modules:
        t0 = time.time()
        if root_node is None:
            root_node = prev_node = cur_node = lcur_node = ImportEventNode(args[0], t0)
        else:
            prev_node = cur_node
            cur_node = lcur_node = ImportEventNode(name, t0)
            prev_node.children.append(cur_node)
        try:
            ret = old_import(*args, **kwargs)
        finally:
            lcur_node.end_time = time.time()
        all_nodes.append(lcur_node)
        cur_node = prev_node
        return ret
    else:
        return old_import(*args, **kwargs)


__builtins__.__import__ = __import__

Running on a simple example, here's how it looks on importing scipy.stats:

:import scipy.stats
:
:nodes = sorted(all_nodes, key=(lambda x: x.net_time), reverse=True)
:for node in nodes[:10]:
:    print(node.name, node.net_time)
:
:<EOF>
('pkg_resources', 0.08431100845336914)
('', 0.05861020088195801)
('decomp_schur', 0.016885995864868164)
('PIL', 0.0143890380859375)
('scipy.stats', 0.010602712631225586)
('pkg_resources._vendor.packaging.specifiers', 0.007072925567626953)
('add_newdocs', 0.00637507438659668)
('mtrand', 0.005497932434082031)
('scipy.sparse.linalg', 0.005171060562133789)
('scipy.linalg', 0.004471778869628906)