pip hangs on all commands

[nick-robo]

Description

Every pip command takes way too long to run on my server.

main@box ~> time pip -V
pip 22.0.4 from /home/main/.asdf/installs/python/3.10.2/lib/python3.10/site-packages/pip (python 3.10)

________________________________________________________
Executed in    6.39 secs    fish           external
   usr time    2.93 secs    1.19 millis    2.93 secs
   sys time    0.38 secs    0.41 millis    0.38 secs

This command was run with a fresh installation of python done with asdf.

main@box ~> time pip list
Package    Version
---------- -------
pip        22.0.4
setuptools 58.1.0

________________________________________________________
Executed in   17.83 secs    fish           external
   usr time    4.02 secs    0.00 millis    4.02 secs
   sys time    0.54 secs    1.62 millis    0.53 secs

I get the same issue with the system installation. Python seems to be fine.

main@box ~> time python -c "print('Hello world!')"
Hello world!

________________________________________________________
Executed in  837.90 millis    fish           external
   usr time  204.28 millis    1.47 millis  202.81 millis
   sys time  219.48 millis    0.48 millis  219.00 millis

But import pkg_resources is quite slow despite there being only 2 packages.

main@box ~> time python -c "import pkg_resources"

________________________________________________________
Executed in    6.20 secs      fish           external
   usr time  905.45 millis    1.88 millis  903.57 millis
   sys time  311.53 millis    0.63 millis  310.90 millis

Expected behavior

Same command on my local computer: < 1 second.

❯ time pip -V
pip 22.0.3 from /home/main/.local/lib/python3.10/site-packages/pip (python 3.10)

________________________________________________________
Executed in  708,31 millis    fish           external
   usr time  577,45 millis  255,00 micros  577,20 millis
   sys time   69,96 millis  175,00 micros   69,79 millis

pip version

pip 22.0.4

Python version

pip 22.0.4

OS

Linux box 4.19.0-12-amd64 #1 SMP Debian 4.19.152-1 (2020-10-18) x86_64 GNU/Linux

How to Reproduce

1. Fresh install python with asdf
2. Run pip -V

Output

No response

Code of Conduct

• I agree to follow the PSF Code of Conduct.

[q0w]

Related: #8485?

[nick-robo]

Related: #8485?

Keychain does not seem to be the culprit. The biggest time consumers when running are below (ran python3 -X importtime -m pip list)

self [us]	cumulative	imported package
39939	14840439	pip._internal.cli.main
2085	14448301	pip._internal.cli.autocompletion
2344	12810246	pip._internal.cli.main_parser
7267	12648770	pip._internal.cli.cmdoptions
3770	11172200	pip._internal.cli.parser
16802	10990426	pip._internal.configuration
9328	6230596	pip._internal.exceptions

Whole output: time.txt

[uranusjr]

But import pkg_resources is quite slow despite there being only 2 packages.

Unfortunately we are stuck with pkg_resources at the moment 😞 You could try filing this to setuptools (pkg_resources is a part of it; pip’s copy is vendored).

[nick-robo]

Correct me if I'm wrong, but from the importtime that I posted, it doesn't seem to be pkg_resources causing the issue.

[pfmoore]

I don't know how to read the output of those time commands, but (for example) the pip list case seems to say "Executed in 17.83 secs" but "usr time 4.02 secs". It doesn't look like a standard Unix "time" command output, but if I assume the 17sec is "real" and the 4sec is "usr", then it looks like a lot of the time is spent not actually in pip. From https://stackoverflow.com/questions/556405/what-do-real-user-and-sys-mean-in-the-output-of-time1, "Real is wall clock time - time from start to finish of the call. This is all elapsed time including time slices used by other processes and time the process spends blocked (for example if it is waiting for I/O to complete)." (my emphasis).

[nick-robo]

It's the fish time command, here is the bash one if you prefer.

main@box:~$ time pip -V
pip 18.1 from /usr/lib/python2.7/dist-packages/pip (python 2.7)

real	0m3.363s
user	0m2.908s
sys	0m0.586s

And

main@box:~$ time pip list 1> /dev/null 

real	0m3.484s
user	0m3.099s
sys	0m0.515s

[pfmoore]

So the bash one looks far better. So maybe it's fish that's at fault here?

Also, you appear to be running Python 2.7 (which we no longer support) in this output, but 3.10 in the original report. So the two aren't directly comparable.

[nick-robo]

Oops. 17 seconds was definitely one of the worst, but 3 seconds is hardly normal to print the version string.

Here is the python3 output

main@box:~$ time pip -V
pip 22.0.4 from /home/main/.asdf/installs/python/3.10.2/lib/python3.10/site-packages/pip (python 3.10)

real	0m2.968s
user	0m2.652s
sys	0m0.416s

and

main@box:~$ time pip list 1> /dev/null 

real	0m4.896s
user	0m3.464s
sys	0m0.563s

[uranusjr]

You’ll probably need to debug this more deeply to find the bottleneck. pip is known to be slow on startup, but not that slow. pip --version should still be under a second at least. There’s obviously some bottleneck on your system, but without more detailed breakdown it’s impossible to know what we can fix.

[nick-robo]

Any ideas on the best way to debug the problem?

[uranusjr]

I would probably start with using a flame graph tool to profile where pip is spending time on.

[ichard26]

Given all of the work that's happening to improve startup time in #4768, I don't believe we need this undiagnosed report laying around.