DEV Community

Inada Naoki
Inada Naoki

Posted on • Updated on

How to speed up Python application startup time

I hear pipenv 9.0.2 is released with major startup time improvement.

I tried it soon and I didn't feel it's fast. So I investigated it with Python 3.7's new feature.

In this article, I introduce the feature and how to use it.


Startup time ≒ import time

For example, execution time of pipenv -h is much larger than time to show help message.

Generally speaking, when application starts, there are some startup process like loading environment variables or config files.

In case of Python application, importing module takes most of startup time. For example, pipenv --version took about 800ms and import pipenv took 700ms.

$ time local/py37/bin/python3 -c 'import pipenv'

real    0m0.696s
user    0m0.648s
sys     0m0.048s

$ time local/py37/bin/pipenv --version
pipenv, version 9.0.3

real    0m0.812s
user    0m0.761s
sys     0m0.052s
Enter fullscreen mode Exit fullscreen mode

Show import time for modules

Python 3.7 has new feature to show time for importing modules.

This feature is enabled with -X importtime option or PYTHONPROFILEIMPORTTIME environment variable.

For example, you can profile import time of pipenv by

python3.7 -X importtime -c 'import pipenv' 2> pipenv-imports
Enter fullscreen mode Exit fullscreen mode

or

PYTHONPROFILEIMPORTTIME=1 pipenv --version 2>pipenv-imports
Enter fullscreen mode Exit fullscreen mode

Here is example output of pipenv --version

Investigating import time

At last of the output, you can see these lines:

import time: self [us] | cumulative | imported package
...
import time:      3246 |     578972 |   pipenv.cli
import time:       507 |     579479 | pipenv
Enter fullscreen mode Exit fullscreen mode

In last line, 579479 means import pipenv took 579 479us.

While importing pipenv, many other modules are imported. From above example, you can see pipenv imports pipenv.cli. Subimports are indented with 2 spaces.

See last line again. 507 means only 507us was took when running pipenv module. 579 479 - 507 = 578 972us is used for subimports.

Finding slow part

Let's find slow subtree from the output. I selected some lines.

import time: self [us] | cumulative | imported package
...
import time:     86500 |     179327 | pkg_resources
...
import time:       385 |     236655 |             IPython
import time:        22 |     236677 |           IPython.core
import time:        26 |     236703 |         IPython.core.magic
import time:       978 |     237680 |       dotenv.ipython
import time:       199 |     239032 |     dotenv
...
...
import time:      3246 |     578972 |   pipenv.cli
import time:       507 |     579479 | pipenv
Enter fullscreen mode Exit fullscreen mode

pkg_resources

As you can see, importing pkg_resources is slow.
And surprisingly, pkg_resources is not indented; it's not subimport of pipenv.

It means pkg_resources is imported by pipenv script, not module.

$ cat local/py37/bin/pipenv
#!/home/inada-n/local/py37/bin/python3.7
# EASY-INSTALL-ENTRY-SCRIPT: 'pipenv==9.0.3','console_scripts','pipenv'
__requires__ = 'pipenv==9.0.3'
import re
import sys
from pkg_resources import load_entry_point

if __name__ == '__main__':
    sys.argv[0] = re.sub(r'(-script\.pyw?|\.exe)?$', '', sys.argv[0])
    sys.exit(
        load_entry_point('pipenv==9.0.3', 'console_scripts', 'pipenv')()
    )
Enter fullscreen mode Exit fullscreen mode

Bad news: Importing pkg_resources is slow. It's known issue and it's difficult to fix without breaking backward compatibility.

Good news: you can avoid importing pkg_resources!

$ local/py37/bin/pip install wheel
$ local/py37/bin/pip install -U --force-reinstall pipenv
$ time local/py37/bin/pipenv --version
pipenv, version 9.0.3

real    0m0.704s
user    0m0.653s
sys     0m0.052s
Enter fullscreen mode Exit fullscreen mode

When wheel is installed, pip builds wheel and install from it.

Installing from wheel (.whl) and from source package (.tar.gz) are different process.
When installing from wheel, pkg_resources is not used in script:

$ cat local/py37/bin/pipenv
#!/home/inada-n/local/py37/bin/python3.7

# -*- coding: utf-8 -*-
import re
import sys

from pipenv import cli

if __name__ == '__main__':
    sys.argv[0] = re.sub(r'(-script\.pyw?|\.exe)?$', '', sys.argv[0])
    sys.exit(cli())
Enter fullscreen mode Exit fullscreen mode

IPython

See next part.

import time:       385 |     236655 |             IPython
import time:        22 |     236677 |           IPython.core
import time:        26 |     236703 |         IPython.core.magic
import time:       978 |     237680 |       dotenv.ipython
import time:       199 |     239032 |     dotenv
Enter fullscreen mode Exit fullscreen mode

pipenv imports dotenv, dotenv imports dotenv.ipython, and it imports IPython.

That's why pipenv starts slow on my environment; I have IPython installed.

But why IPython is imported? I read dotenv source and I found it's for IPython's extension.

Surely, pipenv and many dotenv users don't use IPython extension.
I made pull request to dotenv which make importing IPython on demand.

And since pipenv has own copy of dotenv, I made pull request to pipenv which removes dotenv.ipython completely.

Conclusion

I can reduce time for pipenv --version from 800ms to 500ms.

$ time local/py37/bin/pipenv --version
pipenv, version 9.0.3

real    0m0.503s
user    0m0.463s
sys     0m0.040s
Enter fullscreen mode Exit fullscreen mode

Import time profiling is very nice way to investigating and optimize application startup time.

Top comments (2)

Collapse
 
rhymes profile image
rhymes

Great work Inada!

Collapse
 
techalchemy profile image
Dan Ryan

Thanks for putting this article together and most importantly, thanks for contributing back to the project!