docker / cli

The Docker CLI
Apache License 2.0
4.94k stars 1.93k forks source link

Bash completion slows down bash login sessions #3889

Open hoxu opened 1 year ago

hoxu commented 1 year ago

Expected behavior

bash_completion.d/docker should be fast to execute. It probably should not make any docker calls until actually needed.

Actual behavior

Executing the bash completion script causes a noticeable pause when opening new bash sessions.

The slowest part is a call to docker:

+++ [[ -r /usr/local/etc/bash_completion.d/docker ]]
+++ . /usr/local/etc/bash_completion.d/docker
+++++ shopt -p extglob
++++ __docker_previous_extglob_setting='shopt -s extglob'
++++ shopt -s extglob
+++++ docker info --format '{{range .ClientInfo.Plugins}}{{if eq .Name "compose"}}{{.Path}}{{end}}{{end}}'

This seems to be:

COMPOSE_PLUGIN_PATH=$(docker info --format '{{range .ClientInfo.Plugins}}{{if eq .Name "compose"}}{{.Path}}{{end}}{{end}}')
$ time docker info --format '{{range .ClientInfo.Plugins}}{{if eq .Name "compose"}}{{.Path}}{{end}}{{end}}'
/usr/local/lib/docker/cli-plugins/docker-compose

real    0m2.538s
user    0m0.142s
sys     0m0.085s

Information

Output of /Applications/Docker.app/Contents/MacOS/com.docker.diagnose check

N/A

Steps to reproduce the behavior

Open a new bash login session.

To visually see what is taking up time:

bash -lx
thaJeztah commented 1 year ago

Thanks for reporting; this looks to be related to changes that were made in the completion script in https://github.com/docker/cli (https://github.com/docker/cli/pull/3752).

Let me transfer this ticket to the CLI issue tracker (I know some improvements were made after that, but not sure if they can be included in the 20.10 version)

thaJeztah commented 1 year ago

I know some improvements were made after that, but not sure if they can be included in the 20.10 version

Did a quick comparison;

# on docker 20.10;
time $(docker info --format '{{range .ClientInfo.Plugins}}{{if eq .Name "compose"}}{{.Path}}{{end}}{{end}}')
real    0m1.034s
user    0m0.130s
sys 0m0.094s

# on docker 23.0.0-dev
time $(docker info --format '{{range .ClientInfo.Plugins}}{{if eq .Name "compose"}}{{.Path}}{{end}}{{end}}')
real    0m0.196s
user    0m0.136s
sys 0m0.048s
hoxu commented 1 year ago

That's a big improvement, but 0.20 s is still pretty long. If every completion file took that long time, the result would be unbearable.

Could the call to docker be deferred until the information it prints is actually required in the bash session?

vegerot commented 1 year ago

💀

$ docker --version
Docker version 20.10.21, build baeda1f

$ hyperfine --warmup=1 /usr/local/etc/bash_completion.d/docker
Benchmark 1: /usr/local/etc/bash_completion.d/docker
  Time (mean ± σ):     342.8 ms ±  18.5 ms    [User: 161.4 ms, System: 124.2 ms]
  Range (min … max):   308.6 ms … 371.8 ms    10 runs
vegerot commented 1 year ago

☠️

$ docker --version
Docker version 23.0.5, build bc4487a

📁~/
$ hyperfine --warmup=1 /usr/local/etc/bash_completion.d/docker
Benchmark 1: /usr/local/etc/bash_completion.d/docker
  Time (mean ± σ):     223.4 ms ±  13.0 ms    [User: 247.5 ms, System: 200.1 ms]
  Range (min … max):   206.1 ms … 238.9 ms    13 runs
guss77 commented 1 year ago

The setting of $DOCKER_PLUGINS_PATH during bash completion initialization looks to be a cache for building the plugin commands during docker command completion.

Why is it done during initialization of every single session instead of only as needed?

If docker info --format '{{range .ClientInfo.Plugins}}{{.Path}}:{{end}}' is that fast that it doesn't slow down bash initialization, then it doesn't need to be cached: it can be run as needed when the user calls for docker command completion; OTOH If it is slow, then it definitely cannot be run during bash completion initialization as that unnecessarily slows down every new session.

Regardless, this should be removed.

guss77 commented 1 year ago

I offered a PR #4505 to move that plugins path reading to where it should be.