pipenv: Running `pipenv --completion` is very slow

Running pipenv --completion is consistently slow (it takes about 1 second to run), even after the command has been run multiple times and everything has been loaded into memory.

This means including eval $(pipenv --completion) in a .bashrc file makes the user wait for a second until the shell prompt comes up.

Describe your environment
  1. OS: Kubuntu 17.04
  2. Python version: 2.7.13
  3. Pipenv version: 9.0.1

My shell is bash.

Expected result

The command shouldn’t take so long to run.

Actual result

When running in bash, the command takes a whole second to run.

$ time pipenv --completion

_pipenv_completion() {
    local IFS=$'\t'
    COMPREPLY=( $( env COMP_WORDS="${COMP_WORDS[*]}" \
                   COMP_CWORD=$COMP_CWORD \
                   _PIPENV_COMPLETE=complete-bash $1 ) )
    return 0
}

complete -F _pipenv_completion -o default pipenv


real    0m0.987s
user    0m0.888s
sys     0m0.080s
Steps to replicate

Run time pipenv --completion in a bash shell.

P.S. This is a great project.

About this issue

  • Original URL
  • State: closed
  • Created 7 years ago
  • Reactions: 19
  • Comments: 31 (12 by maintainers)

Most upvoted comments

@eli-schwartz click handles much of the overhead so it saves us from having to be experts on this specific thing most of the time

Yes, but I sort of wish click generated proper completions. 😃 There are tools which generate “proper” completions thereby saving every application developer the effort of knowing how it works, while still not recursively calling the tool itself for every little thing.

Anyway, not understanding how to write completions is one thing, not knowing how to install them is another.

@eli-schwartz though this doesn’t stay up-to-date when you upgrade. i have far too many things in my completions to remember to re-export their completion script every time up upgrade.

But it does. The current completion simply executes pipenv every time you try to complete anything; this doesn’t need to be checked for updates to the completion definition…

Either way it does not stop the completion from being delivered in data_files to share/bash-completion/completions, which should work, and be upgraded, whether installed via sudo pip (😢), pip install --user (since https://github.com/scop/bash-completion/commit/1d25d72ca8633c19cb089dff447d08c531379c59 it will be loaded from ~/.local), or python setup.py install --root="$package_manager_install_root". (It will not work for wheels, in which case oh well, you’re certainly not worse off than if you didn’t use data_files at all. Also IMHO wheels suck.)

This would save on one initial call to pipenv on every single new interactive shell, which while not quite as significant as one call on every single pipenv <TAB> is still not insignificant. It’s why bash-completion created the idea of lazy-loaded completions and tries to encourage people to use that over the “COMPAT_DIR” in /etc/bash_completion.d.

you should not assume that people don’t know much at all about thing x. it’s better to assume that their workflow, use-case, or tolerance is different to yours.

In the ideal case, users do not know, because it is automagically handled by developers or distro packagers. For example, https://git.archlinux.org/svntogit/community.git/commit/trunk?h=packages/python-pipenv&id=484eec9eabad806654fea29801577dc2cbe4188a

At the very least, put your eval thing into the lazy-load directory, so it doesn’t execute on every single new shell init but only gets executed the first time you try to tab-complete this specific tool.

Also, even 0.4s is so slow.

I’m guessing you’re getting that super, super fast 0.4s time because you’re not running on a Raspberry Pi 3? I’m currently getting 6 seconds on v11.8.0.

[me@piserver ~]$ time pipenv --completion

_pipenv_completion() {
    local IFS=$'\t'
    COMPREPLY=( $( env COMP_WORDS="${COMP_WORDS[*]}" \
                   COMP_CWORD=$COMP_CWORD \
                   _PIPENV_COMPLETE=complete-bash $1 ) )
    return 0
}

complete -F _pipenv_completion -o default pipenv

real	0m6.283s
user	0m6.199s
sys	0m0.080s

This might be a naive question, but is there any reason we can’t cache the output of the command for the current Pipenv version?

tldr: PR incoming to ~halve the time pipenv --completion takes, at least for me.

(click to expand, if somehow you're interested in what are basically random notes I was making while doing this :P)

Even with a hot cache, it’s still over a second here. It seems to take an inordinate amount of processing power to essentially just print some text (yes, that’s briefly 60% on one core):

image

The actual completion itself is ok, it’s just outputting the setup that takes way longer than it should.

Let’s try to work out why!

Here’s some data from my (admittedly somewhat old) machine, gathered via sprinkling print(..., time.time()) around in interesting places:

__init__: startup 1520456183.8500586
__init__: importing .cli: 1520456183.8503625
cli: startup 1520456183.8590631
cli: stdlib imports done 1520456183.8704586
cli: 3rd-party imports done 1520456183.9269598
cli: 1st-party imports done 1520456183.9281874
cli: end of module reached 1520456183.9306123
__init__: imported .cli: 1520456183.9306629
__main__: importing cli 1520456183.9308915
__main__: imported cli 1520456183.930915
__main__: running cli() 1520456183.9309256
cli: start of cli() 1520456183.9327562
cli: imported .core 1520456184.3628652
cli: not doing update check 1520456184.3629308
cli: started doing completion 1520456184.3629456
cli: beginning process 1520456184.3629816
cli: started process 1520456184.8666577

_pipenv_completion() {
    local IFS=$'\t'
    COMPREPLY=( $( env COMP_WORDS="${COMP_WORDS[*]}" \
                   COMP_CWORD=$COMP_CWORD \
                   _PIPENV_COMPLETE=complete-bash $1 ) )
    return 0
}

complete -F _pipenv_completion -o default pipenv

cli: printed process output 1520456184.8668966

Conclusions:

  • it takes about 50ms to import all the 3rd-party libraries used in pipenv.cli
  • importing pipenv.cli itself takes about 80ms (~10ms to start actually executing cli.py, 50ms of 3rd-party imports, a little more here and there)
  • importing pipenv.core takes about 420ms
  • running pipenv again via delegator.py takes about 480ms (in comparison, running true by the same method takes only about 4ms)
  • printing the actual output from the child pipenv takes about 1ms

Pain points:

  • from . import core
  • delegator.run('pipenv')

Profiling pipenv.core

core: startup 1520456888.883466
core: done import section 1 1520456888.8928788
core: done import section 2 1520456889.2973905
core: done import section 3 1520456889.2974393
core: done all imports 1520456889.317209
core: end of module reached 1520456889.3178222

Looks like the second group of imports is taking 400ms (of 420ms for the whole core module to run)! Drilling down further:

core: done import section 1 1520457284.6354196
core: importing requests 1520457284.6517467
core: importing pipfile 1520457284.7360592
core: importing pipdeptree 1520457284.7379525
core: importing semver 1520457285.025176
core: imported those 1520457285.0279028
core: done import section 2 1520457285.0321164

Requests is taking ~100ms (it’s a big comprehensive library, not that surprising), but pipdeptree takes nearly 300ms all by itself!

I could probably try and work out why importing that takes so long, but I have to wonder – why is pipenv.core being imported before completion runs? If I move the if completion: block right up to the start of pipenv.cli.cli, that halves the amount of time pipenv --completion takes to run!

(I went and looked at why pipdeptree takes so long to import – it’s because pip takes a relatively long time to import (import pipdeptree + python overhead took about 500ms in testing, with import pip being 350ms of that).)

It’s ~0.9 for me:

pipenv --completion 0.92s user 0.13s system 99% cpu 1.062 total