Nitrokey / pynitrokey

Python client for Nitrokey devices
Apache License 2.0
98 stars 27 forks source link

nitropy slow on Librem5 #463

Open chri2 opened 11 months ago

chri2 commented 11 months ago

The Librem5 is a linux mobile phone based on NXP® i.MX 8M Quad core Cortex A53, 64bit ARM @max 1.5GHz . nitropy works fine on the phone running PureOS Byzantium (Debian Bullseye derivate), but it is slow:

purism@pureos:~$ time nitropy --help
Usage: nitropy [OPTIONS] COMMAND [ARGS]...

Options:
  --help  Show this message and exit.

Commands:
  fido2    Interact with Nitrokey FIDO2 devices, see subcommands.
  list     List Nitrokey devices (in firmware or bootloader mode)
  nethsm   Interact with NetHSM devices, see subcommands.
  nk3      Interact with Nitrokey 3 devices, see subcommands.
  pro      Interact with Nitrokey Pro devices, see subcommands.
  start    Interact with Nitrokey Start devices, see subcommands.
  storage  Interact with Nitrokey Storage devices, see subcommands.
  version  Version of pynitrokey library and tool.

real    0m8,038s
user    0m7,388s
sys 0m0,632s

8 seconds to show help?

purism@pureos:~$ time nitropy nk3 list
Command line tool to interact with Nitrokey devices 0.4.41
:: 'Nitrokey 3' keys
/dev/hidraw0: Nitrokey 3 XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX

real    0m11,314s
user    0m10,327s
sys 0m0,853s
purism@pureos:~$ cat /proc/cpuinfo
processor   : 0
BogoMIPS    : 16.66
Features    : fp asimd evtstrm aes pmull sha1 sha2 crc32 cpuid
CPU implementer : 0x41
CPU architecture: 8
CPU variant : 0x0
CPU part    : 0xd03
CPU revision    : 4

processor   : 1
BogoMIPS    : 16.66
Features    : fp asimd evtstrm aes pmull sha1 sha2 crc32 cpuid
CPU implementer : 0x41
CPU architecture: 8
CPU variant : 0x0
CPU part    : 0xd03
CPU revision    : 4

processor   : 2
BogoMIPS    : 16.66
Features    : fp asimd evtstrm aes pmull sha1 sha2 crc32 cpuid
CPU implementer : 0x41
CPU architecture: 8
CPU variant : 0x0
CPU part    : 0xd03
CPU revision    : 4

processor   : 3
BogoMIPS    : 16.66
Features    : fp asimd evtstrm aes pmull sha1 sha2 crc32 cpuid
CPU implementer : 0x41
CPU architecture: 8
CPU variant : 0x0
CPU part    : 0xd03
CPU revision    : 4

purism@pureos:~$ free
               total        used        free      shared  buff/cache   available
Mem:         3037532      939120     1370096       78328      728316     1934092
Swap:        1518588           0     1518588
robin-nitrokey commented 10 months ago

Could you please try to just run import pynitrokey in python3? Is it also that slow?

nitropy is unfortunately a bit unresponsive even on regular systems – nitropy --help takes nearly 1 s for me – so this might just be exaggerated on less powerful systems. 8 s is a lot though.

I suspect that the reason for this behavior is that we have all imports on the top level. This means that in order to load the command definitions, Python needs to resolve all imports for all commands. I think we could improve this by moving the imports into the commands, but that would require a major refactoring.

chri2 commented 10 months ago
purism@pureos:~$ source .local/pipx/venvs/pynitrokey/bin/activate
(pynitrokey) purism@pureos:~$ time python3 -c 'import pynitrokey'

real    0m0,740s
user    0m0,649s
sys 0m0,093s

Looked up how to profile a python script and found …

(pynitrokey) purism@pureos:~$ time python3 -m cProfile -s cumtime -o nitropy-cProfile-stats /home/purism/.local/pipx/venvs/pynitrokey/bin/nitropy --help
Usage: python -m nitropy [OPTIONS] COMMAND [ARGS]...

Options:
  --help  Show this message and exit.

Commands:
  fido2    Interact with Nitrokey FIDO2 devices, see subcommands.
  list     List Nitrokey devices (in firmware or bootloader mode)
  nethsm   Interact with NetHSM devices, see subcommands.
  nk3      Interact with Nitrokey 3 devices, see subcommands.
  pro      Interact with Nitrokey Pro devices, see subcommands.
  start    Interact with Nitrokey Start devices, see subcommands.
  storage  Interact with Nitrokey Storage devices, see subcommands.
  version  Version of pynitrokey library and tool.

real    0m10,266s
user    0m9,641s
sys 0m0,625s
(pynitrokey) purism@pureos:~$ python3
iPython 3.9.2 (default, Feb 28 2021, 17:03:44) 
[GCC 10.2.1 20210110] on linux
Type "help", "copyright", "credits" or "license" for more information.
>>> import pstats
>>> from pstats import SortKey
>>> p = pstats.Stats('nitropy-cProfile-stats')
>>> p.strip_dirs().sort_stats('cumtime').print_stats(10)
Wed Nov  8 10:14:23 2023    nitropy-cProfile-stats.txt

         824401 function calls (804555 primitive calls) in 6.934 seconds

   Ordered by: cumulative time
   List reduced from 3555 to 10 due to restriction <10>

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
   4333/1    1.406    0.000    6.947    6.947 {built-in method builtins.exec}
        1    0.000    0.000    6.946    6.946 nitropy:3(<module>)
   1527/2    0.049    0.000    6.932    3.466 <frozen importlib._bootstrap>:1002(_find_and_load)
   1526/2    0.035    0.000    6.931    3.466 <frozen importlib._bootstrap>:967(_find_and_load_unlocked)
   2369/3    0.008    0.000    6.928    2.309 <frozen importlib._bootstrap>:220(_call_with_frames_removed)
   1486/3    0.042    0.000    6.925    2.308 <frozen importlib._bootstrap>:659(_load_unlocked)
   1448/3    0.022    0.000    6.924    2.308 <frozen importlib._bootstrap_external>:784(exec_module)
        2    0.001    0.000    6.920    3.460 __init__.py:11(<module>)
  852/526    0.028    0.000    5.538    0.011 {built-in method builtins.__import__}
        3    0.002    0.001    5.044    1.681 __init__.py:9(<module>)

<pstats.Stats object at 0xffff9b4db730>

…hope it helps - output is attached.

nitropy-cProfile-stats.log

robin-nitrokey commented 10 months ago

Thank you! The delay could be caused by this issue: https://github.com/Nitrokey/nethsm-sdk-py/pull/67 I will let you know once there is an updated pynitrokey version for you to test.

robin-nitrokey commented 10 months ago

@chri2 Can you please test the changes in https://github.com/Nitrokey/pynitrokey/pull/469? For me, this reduces the execution time to one third on a regular PC.

chri2 commented 10 months ago
purism@pureos:~$ rm -rf /home/purism/.local/pipx/venvs/pynitrokey
purism@pureos:~$ pipx install --verbose 'git+https://github.com/Nitrokey/pynitrokey@nethsm'
purism@pureos:~$ . .local/pipx/venvs/pynitrokey/bin/activate
(pynitrokey) purism@pureos:~$ time python3 -m cProfile -s cumtime -o nitropy-cProfile-stats.txt /home/purism/.local/pipx/venvs/pynitrokey/bin/nitropy --help
Usage: python -m nitropy [OPTIONS] COMMAND [ARGS]...

Options:
  --help  Show this message and exit.

Commands:
  fido2    Interact with Nitrokey FIDO2 devices, see subcommands.
  list     List Nitrokey devices (in firmware or bootloader mode)
  nethsm   Interact with NetHSM devices, see subcommands.
  nk3      Interact with Nitrokey 3 devices, see subcommands.
  pro      Interact with Nitrokey Pro devices, see subcommands.
  start    Interact with Nitrokey Start devices, see subcommands.
  storage  Interact with Nitrokey Storage devices, see subcommands.
  version  Version of pynitrokey library and tool.

real    0m2,915s
user    0m2,609s
sys 0m0,277s

nitropy-cProfile-stats.txt

I'd say this looks a lot better :+1: !

robin-nitrokey commented 10 months ago

Nice! Still slow though. We could probably make similar optimizations in pynitrokey, but that would take much more effort.

By the way, you can use the --suffix argument for pipx to install multiple versions, e. g. --suffix -git would create nitropy-git.