sonic cli commands take more time to show output on arm CPUs.

[rajkumar38]

Description

Root cause is that for any show/config cli command, all python modules are imported. Some modules are not related for current executed command, but still loaded by default. Pls check below importtime output.

We faced similar issue with 202012 and raised a below PR to move some python imports inside specific commands. https://github.com/sonic-net/sonic-utilities/pull/1202

Since then a lot of new commands and python modules have been introduced to sonic-utilities repository and we are facing similar performance issue with latest master.

SONIC version : master Platform : arm64, armhf

Steps to reproduce the issue

1. 2. 3.

Describe the results you received

admin@sonic:~$ time show interfaces status
: 
:
**real    0m5.007s**
user    0m3.664s
sys     0m0.746s

admin@sonic:~$ time show acl table
Name    Type    Binding    Description    Stage
------  ------  ---------  -------------  -------

**real    0m4.918s**
user    0m3.546s
sys     0m0.762s

admin@sonic:~$ time show ipv6 interfaces
:
:
**real    0m6.256s**
user    0m3.752s
sys     0m2.504s

Describe the results you expected

Additional information you deem important (e.g. issue happens only occasionally)

admin@sonic:/usr/local/lib/python3.9/dist-packages/show$ python3 -X importtime -c "import main"
import time: self [us] | cumulative | imported package
import time:      3924 |       3924 | _frozen_importlib_external
import time:       721 |        721 |   time
import time:      1562 |       2283 | zipimport
import time:       379 |        379 |     _codecs
import time:      2773 |       3152 |   codecs
import time:      3522 |       3522 |   encodings.aliases
import time:      4185 |      10858 | encodings
import time:      1868 |       1868 | encodings.utf_8
import time:      1782 |       1782 | _signal
import time:      1951 |       1951 | encodings.latin_1
import time:       290 |        290 |     _abc
import time:      1904 |       2193 |   abc
import time:      2271 |       4464 | io
import time:      1420 |       1420 |       _stat
import time:      2409 |       3828 |     stat
import time:      7179 |       7179 |     _collections_abc
import time:      1628 |       1628 |       genericpath
import time:      2440 |       4067 |     posixpath
import time:      4900 |      19973 |   os
import time:      1898 |       1898 |   _sitebuiltins
import time:       719 |        719 |     _locale
import time:      1265 |       1983 |   _bootlocale
import time:      2984 |       2984 |     apport_python_hook
import time:      1814 |       4797 |   sitecustomize
import time:       846 |        846 |   usercustomize
import time:     11709 |      41204 | site
import time:      2813 |       2813 |           types
import time:      5661 |       8473 |         enum
import time:       491 |        491 |           _sre
import time:      2196 |       2196 |             sre_constants
import time:     11624 |      13819 |           sre_parse
import time:      3787 |      18096 |         sre_compile
import time:       315 |        315 |               _heapq
import time:      2991 |       3306 |             heapq
import time:       729 |        729 |             itertools
import time:      1572 |       1572 |             keyword
import time:       501 |        501 |               _operator
import time:      3126 |       3626 |             operator
import time:      1772 |       1772 |             reprlib
import time:       976 |        976 |             _collections
import time:      6583 |      18560 |           collections
import time:       432 |        432 |           _functools
import time:      4762 |      23754 |         functools
import time:      2549 |       2549 |         copyreg
import time:      6631 |      59500 |       re
import time:      1468 |       1468 |         _json
import time:      3780 |       5247 |       json.scanner
import time:      3715 |      68461 |     json.decoder
import time:      3355 |       3355 |     json.encoder
import time:      2397 |      74212 |   json
import time:       544 |        544 |     errno
import time:      5747 |       5747 |     signal
import time:      1691 |       1691 |       _weakrefset
import time:      5130 |       6820 |     threading
import time:      2053 |       2053 |     warnings
import time:      3176 |       3176 |     contextlib
import time:       427 |        427 |     pwd
import time:       384 |        384 |     grp
import time:       981 |        981 |     msvcrt
import time:       351 |        351 |     _posixsubprocess
import time:       417 |        417 |     select
import time:      1330 |       1330 |       collections.abc
import time:      1453 |       1453 |       math
import time:      3738 |       6520 |     selectors
import time:      5825 |      33241 |   subprocess
import time:      5866 |       5866 |           _ast
import time:      7334 |      13200 |         ast
import time:      1146 |       1146 |             _opcode
import time:      1981 |       3126 |           opcode
import time:      3300 |       6425 |         dis
import time:      1682 |       1682 |           importlib
import time:      1757 |       3439 |         importlib.machinery
import time:      2588 |       2588 |             token
import time:      5424 |       8012 |           tokenize
import time:      1476 |       9488 |         linecache
import time:     11105 |      43654 |       inspect
import time:       645 |        645 |           _datetime
import time:      5568 |       6212 |         datetime
import time:     11403 |      11403 |           weakref
import time:      3656 |      15059 |         click._compat
import time:       917 |        917 |             click.globals
import time:      1930 |       2847 |           click.utils
import time:      2467 |       5313 |         click.exceptions
import time:      4039 |      30622 |       click.types
import time:       784 |        784 |           _struct
import time:      1779 |       2563 |         struct
import time:      1988 |       4550 |       click.termui
import time:      1736 |       1736 |         click.parser
import time:      1826 |       3561 |       click.formatting
import time:      1465 |       1465 |       click._unicodefun
import time:      1776 |       1776 |       click.decorators
import time:      7123 |      92748 |     click.core
import time:      2225 |      94973 |   click
import time:       664 |        664 |     copy_reg
import time:      2499 |       2499 |     lazy_object_proxy.utils
import time:      1441 |       1441 |     lazy_object_proxy.cext
import time:      1185 |       1185 |     lazy_object_proxy._version
import time:      2179 |       7966 |   lazy_object_proxy
import time:      1509 |       1509 |     utilities_common
import time:     12376 |      12376 |     configparser
import time:      1620 |       1620 |       fnmatch
import time:       644 |        644 |       zlib
import time:      1561 |       1561 |         _compression
import time:      1843 |       1843 |         _bz2
import time:      3263 |       6665 |       bz2
import time:      2025 |       2025 |         _lzma
import time:      2198 |       4223 |       lzma
import time:      4108 |      17258 |     shutil
import time:      2259 |       2259 |         pprint
import time:     11765 |      11765 |               typing
import time:      4435 |      16200 |             importlib.abc
import time:       755 |        755 |                   nt
import time:       649 |        649 |                   nt
import time:       655 |        655 |                   nt
import time:       667 |        667 |                   nt
import time:      2234 |       4957 |                 ntpath
import time:      1190 |       1190 |                   urllib
import time:      7600 |       8790 |                 urllib.parse
import time:      5056 |      18801 |               pathlib
import time:       573 |        573 |                 binascii
import time:      2144 |       2144 |                 importlib.util
import time:      6003 |       8718 |               zipfile
import time:       304 |        304 |                     _bisect
import time:      1257 |       1560 |                   bisect
import time:       276 |        276 |                   _random
import time:       285 |        285 |                   _sha512
import time:      2808 |       4928 |                 random
import time:      2986 |       7914 |               tempfile
import time:      2013 |      37445 |             importlib._common
import time:      2283 |      55927 |           importlib.resources
import time:      1528 |      57454 |         netaddr.compat
import time:      2967 |      62679 |       netaddr.core
import time:      3597 |       3597 |         netaddr.strategy
import time:      1099 |       1099 |             _socket
import time:       439 |        439 |             array
import time:     13319 |      14856 |           socket
import time:      2579 |      17435 |         netaddr.strategy.ipv4
import time:      3474 |       3474 |         netaddr.strategy.ipv6
import time:     17879 |      42383 |       netaddr.ip
import time:      2566 |       2566 |       netaddr.ip.sets
import time:      1637 |       1637 |       netaddr.ip.glob
import time:      1274 |       1274 |       netaddr.ip.nmap
import time:      1458 |       1458 |       netaddr.ip.rfc1924
import time:     13254 |      13254 |         netaddr.strategy.eui48
import time:     11431 |      11431 |         netaddr.strategy.eui64
import time:      2997 |      27681 |       netaddr.eui
import time:      1512 |       1512 |         netaddr.contrib
import time:      2585 |       4097 |       netaddr.contrib.subnet_splitter
import time:      2820 |     146590 |     netaddr
import time:      1304 |       1304 |       __future__
import time:      1044 |       1044 |           natsort.compat
import time:      1073 |       1073 |           natsort.compat.py23
import time:       794 |        794 |           icu
import time:      4729 |       4729 |           locale
import time:      2530 |      10168 |         natsort.compat.locale
import time:       383 |        383 |           unicodedata
import time:      1040 |       1040 |               distutils
import time:      4438 |       5478 |             distutils.version
import time:       989 |        989 |             fastnumbers
import time:      1111 |       1111 |                 natsort.unicode_numeric_hex
import time:     10688 |      11798 |               natsort.unicode_numbers
import time:      1877 |      13674 |             natsort.compat.fake_fastnumbers
import time:      2980 |      23119 |           natsort.compat.fastnumbers
import time:      1354 |       1354 |           natsort.compat.pathlib
import time:      3128 |       3128 |           natsort.ns_enum
import time:      3187 |      31168 |         natsort.utils
import time:     63947 |     105282 |       natsort.natsort
import time:      2064 |     108649 |     natsort
import time:      1672 |       1672 |     sonic_py_common
import time:      2175 |       2175 |       glob
import time:      1665 |       1665 |       swsscommon
import time:      1020 |       1020 |           swig_runtime_data4
import time:     31584 |      32603 |         swsscommon._swsscommon
import time:     19127 |      51730 |       swsscommon.swsscommon
import time:      2459 |       2459 |           yaml.error
import time:      2346 |       2346 |           yaml.tokens
import time:      2037 |       2037 |           yaml.events
import time:      1508 |       1508 |           yaml.nodes
import time:     33753 |      33753 |             yaml.reader
import time:      3721 |       3721 |             yaml.scanner
import time:      1994 |       1994 |             yaml.parser
import time:      1658 |       1658 |             yaml.composer
import time:      1685 |       1685 |               base64
import time:      8438 |      10123 |             yaml.constructor
import time:     14030 |      14030 |             yaml.resolver
import time:      2743 |      68019 |           yaml.loader
import time:      2061 |       2061 |             yaml.emitter
import time:      1672 |       1672 |             yaml.serializer
import time:      2326 |       2326 |             yaml.representer
import time:      1980 |       8036 |           yaml.dumper
import time:       522 |        522 |               yaml.yaml
import time:      2207 |       2729 |             yaml._yaml
import time:     13320 |      16048 |           yaml.cyaml
import time:      3147 |     103596 |         yaml
import time:      1893 |       1893 |         sonic_py_common.general
import time:      3676 |     109164 |       sonic_py_common.device_info
import time:      2701 |     167433 |     sonic_py_common.multi_asic
import time:      1249 |       1249 |       utilities_common.constants
import time:     10269 |      10269 |           gettext
import time:      5989 |      16257 |         argparse
import time:      1801 |       1801 |         netifaces
import time:      1178 |       1178 |               platform
import time:      2257 |       3434 |             pyroute2.config
import time:       165 |       3599 |           pyroute2.config.version
import time:      1877 |       5476 |         pyroute2
import time:      1922 |      25456 |       utilities_common.multi_asic
import time:      2292 |      28996 |     utilities_common.db
import time:      3652 |     488130 |   utilities_common.cli
import time:      6176 |     704694 | main
Traceback (most recent call last):
  File "<string>", line 1, in <module>
  File "/usr/local/lib/python3.9/dist-packages/show/main.py", line 9, in <module>
    import utilities_common.cli as clicommon
  File "/usr/local/lib/python3.9/dist-packages/utilities_common/cli.py", line 16, in <module>
    from utilities_common.db import Db
  File "/usr/local/lib/python3.9/dist-packages/utilities_common/db.py", line 4, in <module>
    from utilities_common.multi_asic import multi_asic_ns_choices
  File "/usr/local/lib/python3.9/dist-packages/utilities_common/multi_asic.py", line 6, in <module>
    import pyroute2
  File "/usr/local/lib/python3.9/dist-packages/pyroute2/__init__.py", line 13, in <module>
    from pyroute2.config.version import __version__
  File "/usr/local/lib/python3.9/dist-packages/pyroute2/config/__init__.py", line 2, in <module>
    import platform
  File "/usr/local/lib/python3.9/dist-packages/show/platform.py", line 43, in <module>
    @click.group(cls=clicommon.AliasedGroup)
AttributeError: partially initialized module 'utilities_common.cli' has no attribute 'AliasedGroup' (most likely due to a circular import)
admin@sonic:/usr/local/lib/python3.9/dist-packages/show$

Output of show version

root@sonic:/home/admin# show ver

SONiC Software Version: SONiC.HEAD.0-dirty-20230217.082601
Distribution: Debian 11.6
Kernel: 5.10.0-18-2-arm64
Build commit: 5e4a866e3
Build date: Fri Feb 17 09:03:26 UTC 2023
Built by: marvell@cpss-arm-vm03

Platform: arm64-marvell_rd98DX35xx-r0
HwSKU: arm64-marvell_rd98DX35xx-r0
ASIC: marvell
ASIC Count: 1
Serial Number: NA
Model Number: NA
Hardware Revision: N/A
Uptime: 21:28:23 up  2:33,  1 user,  load average: 0.64, 0.63, 0.68
Date: Sun 07 Aug 2022 21:28:23

Docker images:
REPOSITORY                    TAG                            IMAGE ID       SIZE
docker-syncd-mrvl             HEAD.0-dirty-20230217.082601   c0ac8090d6d1   580MB
docker-syncd-mrvl             latest                         c0ac8090d6d1   580MB
docker-macsec                 latest                         649309665aa0   469MB
docker-dhcp-relay             latest                         ce8adb55287a   461MB
docker-sonic-telemetry        HEAD.0-dirty-20230217.082601   0d7056ab29f8   720MB
docker-sonic-telemetry        latest                         0d7056ab29f8   720MB
docker-teamd                  HEAD.0-dirty-20230217.082601   d08923f4a6ef   467MB
docker-teamd                  latest                         d08923f4a6ef   467MB
docker-snmp                   HEAD.0-dirty-20230217.082601   c48fa27fc9ec   492MB
docker-snmp                   latest                         c48fa27fc9ec   492MB
docker-router-advertiser      HEAD.0-dirty-20230217.082601   ebffe9653ff3   452MB
docker-router-advertiser      latest                         ebffe9653ff3   452MB
docker-platform-monitor       HEAD.0-dirty-20230217.082601   977e32a4f5b6   727MB
docker-platform-monitor       latest                         977e32a4f5b6   727MB
docker-orchagent              HEAD.0-dirty-20230217.082601   8968825d0f69   479MB
docker-orchagent              latest                         8968825d0f69   479MB
docker-mux                    HEAD.0-dirty-20230217.082601   27aafdf07c5a   466MB
docker-mux                    latest                         27aafdf07c5a   466MB
docker-lldp                   HEAD.0-dirty-20230217.082601   fcdf9847cc21   458MB
docker-lldp                   latest                         fcdf9847cc21   458MB
docker-fpm-frr                HEAD.0-dirty-20230217.082601   37d6b8933eb2   496MB
docker-fpm-frr                latest                         37d6b8933eb2   496MB
docker-eventd                 HEAD.0-dirty-20230217.082601   28bd8def170b   451MB
docker-eventd                 latest                         28bd8def170b   451MB
docker-database               HEAD.0-dirty-20230217.082601   83cb6a77bac9   452MB
docker-database               latest                         83cb6a77bac9   452MB
docker-sonic-mgmt-framework   HEAD.0-dirty-20230217.082601   0756f37f9ecb   844MB
docker-sonic-mgmt-framework   latest                         0756f37f9ecb   844MB
docker-sflow                  HEAD.0-dirty-20230217.082601   6ed53b5494e4   446MB
docker-sflow                  latest                         6ed53b5494e4   446MB
docker-nat                    HEAD.0-dirty-20230217.082601   0d513eddd031   447MB
docker-nat                    latest                         0d513eddd031   447MB

root@sonic:/home/admin#

[wait2035]

Agree, for arm device whose cpu not so good, it's really slow.