docker builds are slow, hanging on docker-credential-gcloud get

[danslinky]

Docker builds when using gcloud credential helper take a long time to start.

Steps to reproduce:

I have a simple Dockerfile and no existing credentials configured.

➜  /tmp cat Dockerfile
FROM debian
RUN echo hello
➜  /tmp cat ~/.docker/config.json
cat: /Users/user/.docker/config.json: No such file or directory

I build it and it's very quick as one would expect.

➜  /tmp time docker build -t myimage:latest . --compress --no-cache
Sending build context to Docker daemon     486B
Step 1/2 : FROM debian
 ---> 874e27b628fd
Step 2/2 : RUN echo hello
 ---> Running in 57fcb43c274a
hello
 ---> d74e283f31eb
Removing intermediate container 57fcb43c274a
Successfully built d74e283f31eb
Successfully tagged myimage:latest
docker build -t myimage:latest . --compress --no-cache  0.02s user 0.05s system 3% cpu 1.655 total

I then use credential helper:

➜  /tmp gcloud alpha auth configure-docker
The following settings will be added to your Docker config file
located at [/Users/user/.docker/config.json]:
 {
  "credHelpers": {
    "gcr.io": "gcloud",
    "us.gcr.io": "gcloud",
    "eu.gcr.io": "gcloud",
    "asia.gcr.io": "gcloud",
    "l.gcr.io": "gcloud",
    "launcher.gcr.io": "gcloud",
    "us-mirror.gcr.io": "gcloud",
    "eu-mirror.gcr.io": "gcloud",
    "asia-mirror.gcr.io": "gcloud",
    "mirror.gcr.io": "gcloud"
  }
}

Do you want to continue (Y/n)?  y

Docker configuration file updated.
➜  /tmp cat ~/.docker/config.json
{
  "credHelpers": {
    "gcr.io": "gcloud",
    "us.gcr.io": "gcloud",
    "eu.gcr.io": "gcloud",
    "asia.gcr.io": "gcloud",
    "l.gcr.io": "gcloud",
    "launcher.gcr.io": "gcloud",
    "us-mirror.gcr.io": "gcloud",
    "eu-mirror.gcr.io": "gcloud",
    "asia-mirror.gcr.io": "gcloud",
    "mirror.gcr.io": "gcloud"
  }
}

Builds now take a loooong time start:

Sending build context to Docker daemon     486B
Step 1/2 : FROM debian
 ---> 874e27b628fd
Step 2/2 : RUN echo hello
 ---> Running in 8c2337496ef2
hello
 ---> d7fc72cb2fa1
Removing intermediate container 8c2337496ef2
Successfully built d7fc72cb2fa1
Successfully tagged myimage:latest
docker build -t myimage:latest . --compress --no-cache  42.60s user 22.68s system 26% cpu 4:04.47 total

I observe this when waiting for docker build:

~ ps auwx | grep gcloud
user           50991  20.6  0.2  4321284  31996 s009  S+    4:43pm   0:00.39 /System/Library/Frameworks/Python.framework/Versions/2.7/Resources/Python.app/Contents/MacOS/Python -S /Users/user/workspace/google-cloud-sdk/lib/gcloud.py auth docker-helper get
user           50980   0.0  0.0  4277552   1256 s009  S+    4:43pm   0:00.00 /bin/sh /Users/user/workspace/google-cloud-sdk/bin/docker-credential-gcloud get

I have yet to get much from tracing docker-credential-gcloud get but will update when I find more.

[dekkagaijin]

docker-credential-gcloud is actually specific to the gcloud SDK and is independent from this cred helper.

Please try running gcloud feedback to submit an issue related to the -gcloud helper.

[gsf]

I found that changing those credHelpers from "gcloud" to "gcr" gets things back up to normal build speeds. Whatever is causing this issue is only present in docker-credential-gcloud, not docker-credential-gcr.

[gsf]

Issue filed: https://issuetracker.google.com/issues/78632439

[dekkagaijin]

There was also a bug in Docker, fixed in 18.03, which made the credential gathering step of docker builds potentially take O(n^2) time rather than O(n) when credHelpers were configured (as is the case for GCR).

Apologies for not swinging around and adding a note to this bug.

[dekkagaijin]

@gsf are you using docker-credential-gcrto retrieve gcloud's access token? Running it on GCE/GKE? Manually running gcr-login? Part of the issue may be that gcloud needs to spin up the Python runtime for each registry it needs to generate credentials for (currently gcr.io, us.gcr.io, eu.gcr.io, staging-k8s.gcr.io), whereas `docker-credential-gcr is binary.

[dekkagaijin]

A general tip for those that find their way here:
If you only host images under a single GCR hostname, e.g. gcr.io/my-project, you can remove the extra credHelpers entries in the Docker config in order to speed up docker builds.

Docker's client config default location is %USERPROFILE%\.docker\config.json and $HOME/.docker/config.json on Windows and OSX/Linux, respectively. For the example above, your credHelpers entries could potentially be pruned down to:

  "credHelpers": {
    "gcr.io": "gcr"
  }

[gsf]

I'm running on Cloud Shell, and you're right that removing all credHelpers but "gcr.io" speeds things up but in my case that would only be necessary when the credHelper is gcloud. With gcr as the credHelper the delay is not enough to be noticeable. See my update on the Cloud SDK issue I filed.

[gsf]

Not sure what changed (or exactly when) but on Cloud Shell the gcr credHelper is now as slow as gcloud.

[dekkagaijin]

They recently updated to v1.5.0 in the cloud shell. I'll explore and see if they can do this as default, but for now you can run docker-credential-gcr config --token-source="env, gcloud" to restore the previous behavior.

[gsf]

I think I was hitting some general networking issues with GCR when I commented before. Aside from the slowdown, there were also periods when I couldn't authenticate to push new images. But things are snappy and happy today.

Also, while troubleshooting I noticed the following is now in /google/devshell/bashrc.google on Cloud Shell, so GCR hostnames like asia.gcr.io, eu.gcr.io, etc. are restored in ~/.docker/config.json each time I log in:

# Setup docker env
export DOCKER_HOST=unix:///var/run/docker.sock

(docker-credential-gcr configure-docker &>/dev/null &)

That list of hostnames isn't a problem as long as the conversation with each registry is quick, but when builds start to hesitate the first thing I do is trim it down.

[kbl]

I had similar issue. It disappeared after executing

 docker login gcr.io

After that auths section was added to ~/.docker/config.json and build time went back to normal.

[chaudharisuresh997]

There was also a bug in Docker, fixed in 18.03, which made the credential gathering step of docker builds potentially take O(n^2) time rather than O(n) when credHelpers were configured (as is the case for GCR).

Apologies for not swinging around and adding a note to this bug.

waw writing complexity of isue awesome bro