On: Mercurial’s journey to and reflections on Python 3

[tick_tock_tick]

It takes me 37ms to load hackernews a 20ms start time is embarrassing what is it even doing?

[eesmith → tick_tock_tick]

It does a lot of module imports. Most of those probe the filesystem.

Try "python -vv -c 'pass'" - I'm only showing the first few dozen lines, and I've trimmed some of the paths for conciseness:

    % python -vv -c 'pass'
    import _frozen_importlib # frozen
    import _imp # builtin
    import '_thread' # <class '_frozen_importlib.BuiltinImporter'>
    import '_warnings' # <class '_frozen_importlib.BuiltinImporter'>
    import '_weakref' # <class '_frozen_importlib.BuiltinImporter'>
    # installing zipimport hook
    import 'zipimport' # <class '_frozen_importlib.BuiltinImporter'>
    # installed zipimport hook
    import '_frozen_importlib_external' # <class '_frozen_importlib.FrozenImporter'>
    import '_io' # <class '_frozen_importlib.BuiltinImporter'>
    import 'marshal' # <class '_frozen_importlib.BuiltinImporter'>
    import 'posix' # <class '_frozen_importlib.BuiltinImporter'>
    import _thread # previously loaded ('_thread')
    import '_thread' # <class '_frozen_importlib.BuiltinImporter'>
    import _weakref # previously loaded ('_weakref')
    import '_weakref' # <class '_frozen_importlib.BuiltinImporter'>
    # miniconda3/lib/python3.7/encodings/__pycache__/__init__.cpython-37.pyc matches miniconda3/lib/python3.7/encodings/__init__.py
    # code object from 'miniconda3/lib/python3.7/encodings/__pycache__/__init__.cpython-37.pyc'
    # trying miniconda3/lib/python3.7/codecs.cpython-37m-darwin.so
    # trying miniconda3/lib/python3.7/codecs.abi3.so
    # trying miniconda3/lib/python3.7/codecs.so
    # trying miniconda3/lib/python3.7/codecs.py
    # miniconda3/lib/python3.7/__pycache__/codecs.cpython-37.pyc matches miniconda3/lib/python3.7/codecs.py
    # code object from 'miniconda3/lib/python3.7/__pycache__/codecs.cpython-37.pyc'
    import '_codecs' # <class '_frozen_importlib.BuiltinImporter'>
    import 'codecs' # <_frozen_importlib_external.SourceFileLoader object at 0x10dd44c90>
    # trying miniconda3/lib/python3.7/encodings/aliases.cpython-37m-darwin.so
    # trying miniconda3/lib/python3.7/encodings/aliases.abi3.so
    # trying miniconda3/lib/python3.7/encodings/aliases.so
    # trying miniconda3/lib/python3.7/encodings/aliases.py
    # miniconda3/lib/python3.7/encodings/__pycache__/aliases.cpython-37.pyc matches miniconda3/lib/python3.7/encodings/aliases.py
    # code object from 'miniconda3/lib/python3.7/encodings/__pycache__/aliases.cpython-37.pyc'
    import 'encodings.aliases' # <_frozen_importlib_external.SourceFileLoader object at 0x10dd67d10>
    import 'encodings' # <_frozen_importlib_external.SourceFileLoader object at 0x10dd440d0>
    # trying miniconda3/lib/python3.7/encodings/utf_8.cpython-37m-darwin.so
    # trying miniconda3/lib/python3.7/encodings/utf_8.abi3.so
    # trying miniconda3/lib/python3.7/encodings/utf_8.so
    # trying miniconda3/lib/python3.7/encodings/utf_8.py
    # miniconda3/lib/python3.7/encodings/__pycache__/utf_8.cpython-37.pyc matches miniconda3/lib/python3.7/encodings/utf_8.py
    # code object from 'miniconda3/lib/python3.7/encodings/__pycache__/utf_8.cpython-37.pyc'
    import 'encodings.utf_8' # <_frozen_importlib_external.SourceFileLoader object at 0x10dd44bd0>
    import '_signal' # <class '_frozen_importlib.BuiltinImporter'>
    # trying miniconda3/lib/python3.7/encodings/latin_1.cpython-37m-darwin.so
    # trying miniconda3/lib/python3.7/encodings/latin_1.abi3.so
    # trying miniconda3/lib/python3.7/encodings/latin_1.so
    # trying miniconda3/lib/python3.7/encodings/latin_1.py
    # miniconda3/lib/python3.7/encodings/__pycache__/latin_1.cpython-37.pyc
    matches miniconda3/lib/python3.7/encodings/latin_1
       ... many, many more lines omitted ...

This can be sped up a lot using a zipimport of the Python standard library, https://docs.python.org/3/library/zipimport.html?highlight=z... , where all of the standard library is put in a zipfile. Then there's a file access to get the zip metadata.

One of the things that bugged me in Python2 was that every startup imported UserDict:

    # trying python2.7/UserDict.so
    # trying python2.7/UserDictmodule.so
    # trying python2.7/UserDict.py
    # python2.7/UserDict.pyc matches python2.7/UserDict.py
    import UserDict # precompiled from python2.7/UserDict.pyc

This is because os.environ was an instance of UserDict:

    % python2.7 -c 'import os; print(os.environ.__class__.__bases__)'
    (<class UserDict.IterableUserDict at 0x1029b14c8>,)

Under Python3 this is spelled collections.abc.MutableMapping:

    % python3 -c 'import os; print(os.environ.__class__.__bases__)'
    (<class 'collections.abc.MutableMapping'>,)

which triggers its own set of imports:

    # trying python3.6/collections/abc.cpython-36m-darwin.so
    # trying python3.6/collections/abc.abi3.so
    # trying python3.6/collections/abc.so
    # trying python3.6/collections/abc.py
    # python3.6/collections/__pycache__/abc.cpython-36.pyc matches python3.6/collections/abc.py
    # code object from 'python3.6/collections/__pycache__/abc.cpython-36.pyc'
    import 'collections.abc' # <_frozen_importlib_external.SourceFileLoader object at 0x103c2ecf8>

There's better performance using SDD than a HDD, which is in turn better than using a networked filesystem.

[tick_tock_tick → eesmith]

I'm guessing startup time just isn't an important goal for cython then? I've know they refused to implements some optimization that would significantly increase complexity but this seem like low hanging fruit?

[eesmith → tick_tock_tick]

Oh, there's been plenty of work to reduce the Python startup cost.

It's just hard to fix.

I'm not sure the os.environ example I gave is low-hanging fruit now. The collections.abc module might be imported anyway.

This is neat! Python 3.7 added the `PYTHONPROFILEIMPORTTIME=1` environment variable to help track down these sorts of import overheads:

  % env PYTHONPROFILEIMPORTTIME=1 python -c pass
  import time: self [us] | cumulative | imported package
  import time:       523 |        523 | zipimport
  import time:       722 |        722 | _frozen_importlib_external
  import time:       156 |        156 |     _codecs
  import time:      2254 |       2409 |   codecs
  import time:      1293 |       1293 |   encodings.aliases
  import time:      7192 |      10893 | encodings
  import time:      1108 |       1108 | encodings.utf_8
  import time:       182 |        182 | _signal
  import time:      1069 |       1069 | encodings.latin_1
  import time:       395 |        395 |     _abc
  import time:      1486 |       1881 |   abc
  import time:      1540 |       3420 | io
  import time:       100 |        100 |       _stat
  import time:       975 |       1075 |     stat
  import time:      1481 |       1481 |       genericpath
  import time:      1734 |       3214 |     posixpath
  import time:      2558 |       2558 |     _collections_abc
  import time:      2234 |       9079 |   os
  import time:      1407 |       1407 |   _sitebuiltins
  import time:      3498 |       3498 |   sitecustomize
  import time:        85 |         85 |   usercustomize
  import time:      4129 |      18196 | site

Investigating further, the "import os" which triggered the UserDict/collections.abc is a consequence of "import site". If I use "python -S" then those aren't imported.