Slow library import time

[kjngineering]

I have been attempting to use python-can on an embedded buildroot system, which essentially will be a CAN based display. Hardware is relatively low level, single ARM Cortex-A7 1.2GHz, 64mb ram, SPI can interface, SD card based storage/boot media.

I had done some function tests with python-can originally and it had worked as intended, but now I am getting to optimisations and I am stumped. Now I have introduced python-can into my runtime, library import -- "import can" is taking a huge block of time which is interfering with the user experience.

As library imports are blocking (as far as I know) its causing a blank screen for the duration of the load time until the display library can make a call and refresh the display.

My typical load times for the can library are in the 2800ms > 3000ms range, which is forever compared to the rest of the process, some benchmarks for reference:

• Power on to boot screen ~ 1200ms
• Power on to user environment ~1800ms
• Script runtime to user display ~500ms (no import-can)
• Script runtime to user display ~3500ms (with import-can)
• Configure can interface (socket can) start receiving packets once library is loaded (10ms)

I'm using the bare minimum of the library:

• SocketCan interface
• Basic Filters
• Single Listener

No logger, no asnycio, no other interfaces or parts of the API.

Is this load time normal? or is there an issue which is slowing down the use of the library? what avenues exist to speed up this process? (selective loading?)

some data from the target hardware:

# python -c "import can; print(can.__version__)"
3.3.4

python -X importtime -c 'import can'
import time: self [us] | cumulative | imported package
import time:      8001 |       8001 | _frozen_importlib_external
import time:      2443 |       2443 |   time
import time:      4229 |       6671 | zipimport
import time:      1298 |       1298 |     _codecs
import time:      8647 |       9945 |   codecs
import time:      5928 |       5928 |   encodings.aliases
import time:      9471 |      25343 | encodings
import time:      4001 |       4001 | encodings.utf_8
import time:      1948 |       1948 | _signal
import time:      5758 |       5758 | encodings.latin_1
import time:      1175 |       1175 |     _abc
import time:      5806 |       6980 |   abc
import time:      5761 |      12741 | io
import time:      1500 |       1500 |       _stat
import time:      5071 |       6571 |     stat
import time:     21029 |      21029 |     _collections_abc
import time:      3479 |       3479 |       genericpath
import time:      4619 |       8097 |     posixpath
import time:     11335 |      47031 |   os
import time:      4056 |       4056 |   _sitebuiltins
import time:      4965 |       4965 |   sitecustomize
import time:      1910 |       1910 |   usercustomize
import time:     10528 |      68489 | site
import time:      5153 |       5153 |   __future__
import time:      7336 |       7336 |         types
import time:     18057 |      25393 |       enum
import time:      1575 |       1575 |         _sre
import time:      7989 |       7989 |           sre_constants
import time:      9148 |      17137 |         sre_parse
import time:      8350 |      27061 |       sre_compile
import time:      1911 |       1911 |             _operator
import time:      9692 |      11602 |           operator
import time:      4421 |       4421 |           keyword
import time:      6125 |       6125 |             _heapq
import time:      6023 |      12148 |           heapq
import time:      2269 |       2269 |           itertools
import time:      5321 |       5321 |           reprlib
import time:      1664 |       1664 |           _collections
import time:     22441 |      59863 |         collections
import time:      1235 |       1235 |         _functools
import time:     23470 |      84566 |       functools
import time:      1758 |       1758 |       _locale
import time:      5033 |       5033 |       copyreg
import time:     15566 |     159374 |     re
import time:      5291 |       5291 |           token
import time:     24374 |      29665 |         tokenize
import time:      5207 |      34871 |       linecache
import time:      7702 |      42573 |     traceback
import time:      7282 |       7282 |     warnings
import time:      5919 |       5919 |       _weakrefset
import time:     10208 |      16126 |     weakref
import time:      4965 |       4965 |     collections.abc
import time:      1145 |       1145 |       _string
import time:     20021 |      21165 |     string
import time:     12966 |      12966 |     threading
import time:      1071 |       1071 |     atexit
import time:     55403 |     320920 |   logging
import time:      5687 |       5687 |       _queue
import time:      7715 |      13402 |     queue
import time:      5444 |       5444 |           concurrent
import time:     13930 |      13930 |           concurrent.futures._base
import time:      7998 |      27371 |         concurrent.futures
import time:     12379 |      12379 |           _socket
import time:      7889 |       7889 |             math
import time:      6893 |       6893 |             select
import time:     14169 |      28950 |           selectors
import time:      1756 |       1756 |           errno
import time:     44833 |      87917 |         socket
import time:     24209 |      24209 |           signal
import time:     12379 |      12379 |           contextlib
import time:      2389 |       2389 |           msvcrt
import time:      5359 |       5359 |           _posixsubprocess
import time:     13603 |      57937 |         subprocess
import time:      2461 |       2461 |           _ssl
import time:     10101 |      12562 |         ssl
import time:      6248 |       6248 |         asyncio.constants
import time:      5071 |       5071 |                 _opcode
import time:      7845 |      12916 |               opcode
import time:     10117 |      23032 |             dis
import time:      6221 |       6221 |               importlib
import time:      6423 |      12643 |             importlib.machinery
import time:     41206 |      76880 |           inspect
import time:      4247 |       4247 |             asyncio.format_helpers
import time:      5506 |       9752 |           asyncio.base_futures
import time:      3769 |       3769 |           asyncio.log
import time:      8147 |      98546 |         asyncio.coroutines
import time:      5018 |       5018 |             _contextvars
import time:      4785 |       9803 |           contextvars
import time:      5177 |       5177 |           asyncio.exceptions
import time:      5687 |       5687 |             asyncio.base_tasks
import time:      9983 |      15669 |           _asyncio
import time:     12483 |      43130 |         asyncio.events
import time:      6383 |       6383 |         asyncio.futures
import time:      5720 |       5720 |         asyncio.protocols
import time:      2491 |       2491 |             _ssl
import time:     20385 |      22875 |           ssl
import time:      6554 |       6554 |           asyncio.transports
import time:     10995 |      40423 |         asyncio.sslproto
import time:     42512 |      42512 |           typing
import time:      8339 |       8339 |           asyncio.locks
import time:      8920 |       8920 |           asyncio.tasks
import time:     12521 |      72290 |         asyncio.staggered
import time:      5668 |       5668 |         asyncio.trsock
import time:     25667 |     489856 |       asyncio.base_events
import time:      4425 |       4425 |       asyncio.runners
import time:      6633 |       6633 |       asyncio.queues
import time:      8775 |       8775 |       asyncio.streams
import time:      6313 |       6313 |       asyncio.subprocess
import time:      6649 |       6649 |         asyncio.base_subprocess
import time:      2430 |       2430 |             _ssl
import time:      9178 |      11607 |           ssl
import time:     12312 |      23919 |         asyncio.selector_events
import time:     17012 |      47580 |       asyncio.unix_events
import time:     10650 |     574228 |     asyncio
import time:      7687 |     595316 |   can.listener
import time:      4526 |       4526 |       can.io.generic
import time:      9876 |       9876 |           _datetime
import time:     20236 |      30112 |         datetime
import time:      2188 |       2188 |                 org
import time:      1028 |       3215 |               org.python
import time:       992 |       4206 |             org.python.core
import time:      6240 |      10446 |           copy
import time:      6057 |      16503 |         can.message
import time:     55036 |      55036 |           platform
import time:     49264 |      49264 |           configparser
import time:     13348 |      13348 |                 binascii
import time:     11799 |      11799 |                   importlib.abc
import time:      7634 |      19432 |                 importlib.util
import time:      5041 |       5041 |                   fnmatch
import time:      8691 |       8691 |                   zlib
import time:      5766 |       5766 |                     _compression
import time:      2352 |       2352 |                     _bz2
import time:      7452 |      15568 |                   bz2
import time:      2452 |       2452 |                     _lzma
import time:      6133 |       8585 |                   lzma
import time:      1256 |       1256 |                   pwd
import time:      5293 |       5293 |                   grp
import time:     17558 |      61989 |                 shutil
import time:      7261 |       7261 |                   _struct
import time:      4872 |      12132 |                 struct
import time:      2392 |       2392 |                   _bz2
import time:      4782 |       7174 |                 bz2
import time:      2836 |       2836 |                   _lzma
import time:      4510 |       7345 |                 lzma
import time:     21649 |     143067 |               zipfile
import time:     11058 |      11058 |               pkgutil
import time:      5520 |       5520 |                     xml
import time:      6982 |      12502 |                   xml.parsers
import time:     26076 |      26076 |                   pyexpat
import time:      6187 |      44763 |                 xml.parsers.expat
import time:     25889 |      70652 |               plistlib
import time:      5782 |       5782 |                 email
import time:     11027 |      11027 |                   email.errors
import time:      7013 |       7013 |                       email.quoprimime
import time:      6314 |       6314 |                         base64
import time:      5497 |      11810 |                       email.base64mime
import time:      5030 |       5030 |                           quopri
import time:      5065 |      10095 |                         email.encoders
import time:     17905 |      27999 |                       email.charset
import time:     21666 |      68487 |                     email.header
import time:      5252 |       5252 |                           _bisect
import time:      5320 |      10571 |                         bisect
import time:      7325 |       7325 |                         _sha512
import time:      5459 |       5459 |                         _random
import time:     10573 |      33927 |                       random
import time:      5683 |       5683 |                         urllib
import time:     23371 |      29053 |                       urllib.parse
import time:     21336 |      21336 |                           locale
import time:     12163 |      33499 |                         calendar
import time:      6682 |      40181 |                       email._parseaddr
import time:     14972 |     118131 |                     email.utils
import time:      9895 |     196512 |                   email._policybase
import time:     18120 |     225658 |                 email.feedparser
import time:      8645 |     240084 |               email.parser
import time:      9228 |       9228 |               tempfile
import time:     33977 |      33977 |               textwrap
import time:      2454 |       2454 |                 nt
import time:      2257 |       2257 |                 nt
import time:      2544 |       2544 |                 nt
import time:      2271 |       2271 |                 nt
import time:      9032 |      18556 |               ntpath
import time:      7214 |       7214 |               pkg_resources.extern
import time:      4981 |       4981 |                   pkg_resources._vendor
import time:     18966 |      23947 |                 pkg_resources._vendor.six
import time:      3782 |      27728 |               pkg_resources.extern.six
import time:     15776 |      15776 |                   pkg_resources._vendor.six
import time:      2217 |      17993 |                 pkg_resources._vendor.six.moves
import time:      1901 |      19893 |               pkg_resources.extern.six.moves
import time:       912 |        912 |                 pkg_resources._vendor.six.moves
import time:      1852 |       2764 |               pkg_resources._vendor.six.moves.urllib
import time:      4135 |       4135 |               pkg_resources.py31compat
import time:      6149 |       6149 |                 pkg_resources._vendor.appdirs
import time:      2682 |       8830 |               pkg_resources.extern.appdirs
import time:      5126 |       5126 |                   pkg_resources._vendor.packaging.__about__
import time:      6097 |      11222 |                 pkg_resources._vendor.packaging
import time:      2302 |      13524 |               pkg_resources.extern.packaging
import time:      4601 |       4601 |                 pkg_resources.extern.packaging._structures
import time:     59215 |      63815 |               pkg_resources.extern.packaging.version
import time:      4204 |       4204 |                 pkg_resources.extern.packaging._compat
import time:    139595 |     143799 |               pkg_resources.extern.packaging.specifiers
import time:      7551 |       7551 |                     pprint
import time:    311312 |     318863 |                   pkg_resources._vendor.pyparsing
import time:      2946 |     321809 |                 pkg_resources.extern.pyparsing
import time:      1308 |       1308 |                 pkg_resources.extern.six.moves.urllib
import time:     31070 |      31070 |                 pkg_resources.extern.packaging.markers
import time:    165819 |     520004 |               pkg_resources.extern.packaging.requirements
import time:      9141 |       9141 |               sysconfig
import time:    200681 |    1548139 |             pkg_resources
import time:     28287 |    1576426 |           can.interfaces
import time:      4552 |       4552 |           _bootlocale
import time:     23699 |    1708975 |         can.util
import time:      7968 |    1763556 |       can.io.asc
import time:      7741 |       7741 |       can.io.blf
import time:      6031 |       6031 |       can.io.canutils
import time:      5459 |       5459 |       can.io.csv
import time:     38224 |      38224 |             _sqlite3
import time:      7119 |      45342 |           sqlite3.dbapi2
import time:      6950 |      52291 |         sqlite3
import time:      6643 |      58934 |       can.io.sqlite
import time:      4848 |       4848 |       can.io.printer
import time:     10972 |    1862066 |     can.io.logger
import time:      7141 |       7141 |     can.io.player
import time:      7074 |    1876279 |   can.io
import time:     79854 |      79854 |     aenum
import time:      6683 |       6683 |     can.broadcastmanager
import time:     13407 |      99943 |   can.bus
import time:      8590 |       8590 |         wrapt._wrappers
import time:     13930 |      22519 |       wrapt.wrappers
import time:      7162 |       7162 |       wrapt.decorators
import time:      8163 |       8163 |       wrapt.importer
import time:      8280 |      46122 |     wrapt
import time:     19123 |      19123 |             _ctypes
import time:      6669 |       6669 |             ctypes._endian
import time:     23153 |      48945 |           ctypes
import time:      5154 |       5154 |           ctypes.util
import time:      5562 |       5562 |           fcntl
import time:      3932 |       3932 |           can.interfaces.socketcan.constants
import time:      6830 |       6830 |           can.interfaces.socketcan.utils
import time:     14206 |      84626 |         can.interfaces.socketcan.socketcan
import time:      7103 |      91728 |       can.interfaces.socketcan
import time:      6487 |      98215 |     can.interface
import time:      6262 |     150598 |   can.thread_safe_bus
import time:      5260 |       5260 |   can.notifier
import time:     13508 |    3066974 | can

[christiansandberg]

One thing that could be done is to load the logger modules on demand similar to how we only load interfaces when needed. But that could affect the official API.

[hardbyte]

Hmm that is annoyingly slow but I'm not sure what to do about it. Do you mind uploading the import profile?

If a blank user display is the main concern is there anything preventing you from initializing it first, showing a splash screen/progress screen etc before importing can?

[christiansandberg]

It seems pkg_resources takes 1,5 s to load alone. You could comment out imports that you don't need to make it load faster. But I don't think we can do it without changing the API completely.

[kjngineering]

So this is all very new to me, I don't have much experience with python (or any interpreted languages really).

Happy to profile the runtime: I tried to run cProfiler but it hang mid execution - I'm not sure why either because of threading or some other issue. I will have another go later.

Definitely willing to try commenting out some dependencies if you have any recommendations on where to start.

This was an interesting read, but didn't really give me an avenue to cut out anything (particularly pkg_resources). https://dev.to/methane/how-to-speed-up-python-application-startup-time-nkf

Edit: Buildroot (by default) installs all python libs in a compiled *.pyc format - would that have any material impact?

[kjngineering]

@hardbyte @christiansandberg

Any suggestions on what I can try to selectively load modules? Happy to do some testing if there is some direction available.

Thank you.

[felixdivo]

But I don't think we can do it without changing the API completely.

Yes, it seems to be the case that we can't do much here. Sorry.

[felixdivo]

I'm closing this for now since I don't see what we should change here.

[christiansandberg]

Maybe we could use importlib instead. It is for 3.8 and newer only so a fallback to setuptools would probably be needed.

[felixdivo]

I think this is completely covered by #1234