Significant slowdown since isort 4.3.5

[WolfgangFellger]

isort 4.3.5 is a factor of twenty slower for me than 4.3.4 (a run now takes 30s instead of 1.5s, CPU is at 100%). isort 4.3.7 still exhibits the same problem.

Is anybody else seeing that? What diagnostics can I run? Python version is 3.6.8, if that matters.

[jamescooke]

@WolfgangFellger Yes I completely agree. I was just about to post the same issue.

I'm not sure what's the best way to diagnose the issue, this is just a speed run comparison on a project I'm working on today:

Approx 2 seconds with isort 4.3.4:

isort==4.3.4
Python 3.6.7
Tue 26 Feb 11:51:57 GMT 2019
isort --quiet --recursive --diff . > isort.out
Tue 26 Feb 11:51:59 GMT 2019

Approx 30 seconds with isort 4.3.9:

isort==4.3.9
Python 3.6.7
Tue 26 Feb 11:53:01 GMT 2019
isort --quiet --recursive --diff . > isort.out
Tue 26 Feb 11:53:31 GMT 2019

[PiDelport]

Same here: there's a dramatic slowdown as of isort 4.3.5.

My current project goes from ~1 to ~30 seconds:

$ pip install 'isort==4.3.4'
$ time isort --check
real	0m1.241s
user	0m1.169s
sys	0m0.072s

$ pip install 'isort==4.3.5'
$ time isort --check 
real	0m27.233s
user	0m25.657s
sys	0m1.572s

(Full CPU usage in both cases.)

I use isort as a continuous interactive tool and a pre-commit check, so this has a major impact on its usability for me.

[jamescooke]

@pjdelport It looks like a fix is coming here: #852

[PiDelport]

python -m cProfile -s cumtime $(which isort) shows a dramatic difference in execution profile:

isort 4.3.4:

         3440229 function calls (3430973 primitive calls) in 1.707 seconds

   Ordered by: cumulative time

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
    319/1    0.046    0.000    1.710    1.710 {built-in method builtins.exec}
        1    0.000    0.000    1.710    1.710 isort:3(<module>)
        1    0.004    0.004    1.522    1.522 main.py:292(main)
      148    0.048    0.000    1.340    0.009 isort.py:58(__init__)
      146    0.094    0.001    0.902    0.006 isort.py:841(_parse)
…

isort 4.3.5:

         66976327 function calls (65504084 primitive calls) in 42.357 seconds

   Ordered by: cumulative time

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
    713/1    0.054    0.000   42.462   42.462 {built-in method builtins.exec}
        1    0.000    0.000   42.462   42.462 isort:3(<module>)
        1    0.000    0.000   42.011   42.011 main.py:303(main)
      150    0.004    0.000   42.007    0.280 main.py:346(<genexpr>)
      149    0.002    0.000   41.857    0.281 main.py:84(sort_imports)
      149    0.013    0.000   41.855    0.281 isort.py:49(__init__)
      147    0.001    0.000   40.819    0.278 finders.py:323(__init__)
     1176    0.001    0.000   40.818    0.035 finders.py:326(<genexpr>)
      294    0.001    0.000   40.573    0.138 finders.py:179(__init__)
      147    0.027    0.000   40.572    0.276 finders.py:201(_load_names)
    22050    0.056    0.000   40.456    0.002 finders.py:283(_get_names)
    22050    0.043    0.000   22.236    0.001 req_file.py:73(parse_requirements)
    42924    0.185    0.000   21.993    0.001 req_file.py:131(process_line)
      735    0.013    0.000   17.916    0.024 download.py:336(__init__)
      735    0.046    0.000   17.802    0.024 download.py:75(user_agent)
      735    0.004    0.000   17.597    0.024 misc.py:894(get_installed_version)
     5912    0.091    0.000   17.395    0.003 __init__.py:609(add_entry)
      737    0.004    0.000   17.357    0.024 __init__.py:554(__init__)
   114545    0.231    0.000   16.187    0.000 __init__.py:1940(find_on_path)
    21315    0.190    0.000   12.033    0.001 constructors.py:194(install_req_from_line)
    22050    0.159    0.000   10.695    0.000 requirements.py:91(__init__)
    23082    0.052    0.000   10.380    0.000 pyparsing.py:1766(parseString)
1101325/23082    2.448    0.000   10.266    0.000 pyparsing.py:1516(_parseNoCache)
258301/23082    0.684    0.000   10.157    0.000 pyparsing.py:3702(parseImpl)
    21609    0.469    0.000    8.828    0.000 req_file.py:276(build_parser)
     8268    0.403    0.000    7.631    0.001 {built-in method builtins.sorted}
     5173    0.003    0.000    7.608    0.001 __init__.py:1914(_by_version_descending)
   218744    0.472    0.000    7.480    0.000 __init__.py:2027(distributions_from_metadata)
86018/57781    0.220    0.000    7.329    0.000 pyparsing.py:3866(parseImpl)
   109372    0.177    0.000    5.425    0.000 __init__.py:1929(_by_version)
   109372    0.175    0.000    4.879    0.000 __init__.py:1935(<listcomp>)
   327226    0.401    0.000    4.707    0.000 version.py:21(parse)
   109372    0.463    0.000    4.539    0.000 __init__.py:2481(from_location)
   345747    0.971    0.000    4.342    0.000 optparse.py:564(__init__)
156432/135103    0.123    0.000    4.257    0.000 pyparsing.py:4065(parseImpl)
   436302    1.618    0.000    4.175    0.000 version.py:217(__init__)
66744/66155    0.103    0.000    3.525    0.000 pyparsing.py:4425(parseImpl)
   109372    0.143    0.000    3.440    0.000 __init__.py:2468(__init__)
   109372    0.209    0.000    2.950    0.000 __init__.py:1323(safe_version)
    21609    0.089    0.000    2.679    0.000 optparse.py:1178(__init__)
    21609    0.020    0.000    2.261    0.000 optparse.py:1264(set_usage)
    21612    0.012    0.000    2.242    0.000 gettext.py:626(gettext)
    21612    0.035    0.000    2.230    0.000 gettext.py:587(dgettext)
    21612    0.037    0.000    2.186    0.000 gettext.py:521(translation)
    21612    0.322    0.000    2.148    0.000 gettext.py:466(find)
   218152    0.173    0.000    2.133    0.000 version.py:69(__init__)
   218152    0.716    0.000    1.960    0.000 version.py:152(_legacy_cmpkey)
857122/834480    1.118    0.000    1.701    0.000 pyparsing.py:483(__init__)
   115505    1.631    0.000    1.631    0.000 {built-in method posix.listdir}
78206/44542    0.152    0.000    1.476    0.000 pyparsing.py:4359(parseImpl)
    22051    0.074    0.000    1.403    0.000 pyparsing.py:3778(parseImpl)
   345747    0.904    0.000    1.398    0.000 optparse.py:613(_set_attrs)
78208/44544    0.107    0.000    1.387    0.000 pyparsing.py:4280(parseImpl)
   323116    0.758    0.000    1.168    0.000 posixpath.py:75(join)
   333387    1.118    0.000    1.118    0.000 {built-in method posix.stat}
   109372    0.526    0.000    1.086    0.000 __init__.py:683(add)
    42925    0.226    0.000    1.050    0.000 pyparsing.py:4702(postParse)
  1000109    0.588    0.000    1.020    0.000 version.py:135(_parse_version_parts)
   345744    0.681    0.000    1.005    0.000 optparse.py:995(add_option)
7189529/7189527    0.979    0.000    0.982    0.000 {built-in method builtins.isinstance}
    64408    0.247    0.000    0.968    0.000 pyparsing.py:3038(parseImpl)
    44102    0.049    0.000    0.909    0.000 pyparsing.py:1599(tryParse)
   157455    0.355    0.000    0.906    0.000 pyparsing.py:781(__iadd__)
   356634    0.634    0.000    0.878    0.000 pyparsing.py:531(__setitem__)
   218150    0.741    0.000    0.840    0.000 version.py:378(_cmpkey)
  1277958    0.478    0.000    0.780    0.000 version.py:61(_compare)
   462609    0.760    0.000    0.760    0.000 {method 'search' of '_sre.SRE_Pattern' objects}
   109076    0.321    0.000    0.734    0.000 version.py:248(__str__)
   132842    0.119    0.000    0.718    0.000 genericpath.py:39(isdir)
   241783    0.238    0.000    0.714    0.000 posixpath.py:121(splitext)
      147    0.086    0.001    0.694    0.005 isort.py:817(_parse)
…

[Tenzer]

I have made another patch which speeds up the finders instead of disabling them: #856.

[timothycrosley]

I've packaged up @Tenzer's improvement in the latest 4.3.10 release.
https://github.com/timothycrosley/isort/releases/tag/4.3.10

Thank you!

~Timothy

[Tenzer]

Having just tried out the 4.3.10 release I can't see the performance improvements I saw when making the patches. I'll have to dig into why that is, as I can see my code changes are part of the release.

[di]

Going from 4.3.10 to 4.3.16 resolved this for me.