Closed bmuschko closed 5 years ago
Hi @bmuschko,
I'm really intrigued. I assume you use build.gradle
as-is in your environment.
Could you run with --debug -Djib.console=plain
? It will spit out a lot of garbage, but it will print out Jib's timing information like below. (You may want to grep TIMED
and TIMING
.)
23:30:03.539 [DEBUG] [org.gradle.api.Task] TIMED Pulling base image manifest : 1835.0 ms
23:30:03.541 [DEBUG] [org.gradle.api.Task] TIMING Preparing base image layer pullers
23:30:03.541 [DEBUG] [org.gradle.api.Task] TIMED Preparing base image layer pullers : 0.0 ms
23:30:03.542 [DEBUG] [org.gradle.api.Task] TIMING Pulling base image layer sha256:f033c4f65cdbf0bfa21d5543e56c0c41645eca4d893494bb4f0661b0f19ccc79
23:30:03.542 [DEBUG] [org.gradle.api.Task] TIMING Pulling base image layer sha256:a6dcb6c468dd5f798b89cc811a0cfd60e49eea1be68dac6d467296afa9d4e197
23:30:03.542 [DEBUG] [org.gradle.api.Task] TIMING Pulling base image layer sha256:7405f9e6a7ae2c7f99927a0f681ca0d1ae12352d809a9dc507d34a16f7399628
23:30:03.542 [DEBUG] [org.gradle.api.Task] TIMING Pulling base image layer sha256:9fc222b64b0a005c742f1b50f03986a7f768d41434994430718917d88fefe567
...
23:30:17.733 [DEBUG] [org.gradle.api.Task] TIMED Pulling base image layer sha256:7405f9e6a7ae2c7f99927a0f681ca0d1ae12352d809a9dc507d34a16f7399628 : 14191.0 ms
...
Can you also try Jib 1.4.0 to see if there's any difference?
Hi, I have been struggling with this issue for the last two days. I tried the same maven build with 1.4.0 and it worked! The problem only occurs if we tag our docker images with a release. If the docker image has a tag that ends with "SNAPSHOT" it pushes just fine even with versions 1.5.1 or 1.5.0. I hope that information helps. Thank you!
@kalapraveen-mi are you using <allowInsecureRegistries>
by any chance? If that is the case, I worry that 1.4.0 might be the last version that may seem to "work" (in a very inefficient way) in your case. I could be wrong about your case though.
And the "SNAPSHOT" tag is really weird and interesting.
@kalapraveen-mi The issue you are describing is likely not related to my issue. I'd suggest opening a new GitHub issue. I have no problems with pushing images. It's about the execution time needed to perform the operation.
@chanseokoh Please see the output below. Potentially a memory contention issue on the Gradle daemon process when you are trying to upload the Docker image?
@bmuschko the log shows that, e.g., a fairly small Blob of size ~34MB is taking a few minutes to push.
17:39:25.778 [DEBUG] [org.gradle.api.Task] TIMING Pushing BLOB digest: sha256:1c648a33eb366146d2588f06095637dc9858b4965bfb6e05f0e8776fc5ab9080, size: 34012012
...
17:43:32.124 [DEBUG] [org.gradle.api.Task] TIMED pushBlob PUT sha256:1c648a33eb366146d2588f06095637dc9858b4965bfb6e05f0e8776fc5ab9080 : 245695.0 ms
I'd like to check first if pushing a BLOb manually on the command line is slow as well. To do so, you need to make three HTTP calls (curl commands) like the script below. This is basically what Jib does. Edit some variables at the top (Docker Hub account and BLOb path).
#!/bin/sh
set -o errexit
set -o pipefail
# Your Docker Hub image repository
REPO=bmuschko/todo-web-service
USERNAME="your Docker Hub account"
PASSWORD="your password"
# BLOb to push. You can just use any large file. The name, path, and contents
# don't matter at all. For example, you can generate a 40MB file by
# $ dd if=/dev/urandom of=./path/to/40mb-file bs=1048576 count=40
BLOB_PATH=./path/to/40mb-file
#VERBOSE=-v
if [ ! -f "${BLOB_PATH}" ]; then
echo "Halting: ${BLOB_PATH} does not exist."
exit 1
fi
echoGreen() {
echo "$(tput setaf 2; tput bold)$1$(tput sgr0)"
}
################################################################################
# STEP 1: Auth with Docker Hub for push
################################################################################
AUTH=$( echo -n "${USERNAME}:${PASSWORD}" | base64 - )
JSON_OUTPUT=$( curl ${VERBOSE} --compressed \
-H 'Accept: */*' -H 'Accept-Encoding: gzip' \
-H "Authorization: Basic ${AUTH}" \
-H 'User-Agent: jib 1.5.1 jib-maven-plugin Google-HTTP-Java-Client/1.30.0 (gzip)' \
-- "https://auth.docker.io/token?service=registry.docker.io&scope=repository:${REPO}:pull,push" )
# The above will return an auth token in JSON. For example:
# {
# "token": "THIS TOKEN IS WHAT WE WANT TO EXTRACT",
# "access_token": "...",
# "expires_in": 300,
# "issued_at": "2019-09-11T15:26:24.113210766Z"
# }
# (Seems like Docker Hub tokens expire in 5 minutes.)
# Extract the "token" field.
TOKEN=$( echo "${JSON_OUTPUT}" | jq -r '.token' )
echo
echoGreen ">>> Got token (don't reveal this in public): ${TOKEN}"
echo
################################################################################
# STEP 2: Ask Docker Hub where I can push a layer (HTTP POST)
################################################################################
HEADER_OUTPUT=$( curl ${VERBOSE} -I --compressed -X POST \
-H 'Accept: ' -H 'Accept-Encoding: gzip' \
-H "Authorization: Bearer ${TOKEN}" \
-H 'User-Agent: jib 1.5.1 jib-maven-plugin Google-HTTP-Java-Client/1.30.0 (gzip)' \
-- "https://registry-1.docker.io/v2/${REPO}/blobs/uploads/" )
# Server will return where to push a BLOb. For example,
# < Location: https://registry-1.docker.io/v2/<your repo>/blobs/uploads/...
PUSH_LOCATION=$( echo "${HEADER_OUTPUT}" \
| grep '^Location: ' | tr -d '\r' | sed 's/Location: //' )
echo
echoGreen ">>> Got push location: "${PUSH_LOCATION}
echo
################################################################################
# STEP 3: Push a BLOb (HTTP PATCH)
###############################################################################
echo "Now pushing a BLOb: ${BLOB_PATH}"
echo
# Now we are actually going to push a large BLOb (layer). Let's time it.
time curl ${VERBOSE} --compressed -X PATCH \
-H 'Accept: ' -H 'Accept-Encoding: gzip' \
-H "Authorization: Bearer ${TOKEN}" \
-H 'User-Agent: jib 1.5.1 jib-maven-plugin Google-HTTP-Java-Client/1.30.0 (gzip)' \
-H 'Content-Type: application/octet-stream' \
--data-binary "@${BLOB_PATH}" \
-- "${PUSH_LOCATION}"
The output should be like below, showing that it took about 3 seconds for me.
chanseok$ ./push_blob_test.sh
% Total % Received % Xferd Average Speed Time Time Time Current
Dload Upload Total Spent Left Speed
100 4309 0 4309 0 0 34198 0 --:--:-- --:--:-- --:--:-- 33929
>>> Got token (don't reveal this in public): eyJhbGciOiJSUzI1NiIsIn...
% Total % Received % Xferd Average Speed Time Time Time Current
Dload Upload Total Spent Left Speed
0 0 0 0 0 0 0 0 --:--:-- --:--:-- --:--:-- 0
>>> Got push location: https://registry-1.docker.io/v2/< ... >/blobs/uploads/2d343581-e9d6-40e7-bd0c-3a04c271dd96?_state=AI8eI0uJJvMy53NMd1J7dYRz2nc5RwIr-uPTzf5F6yx7Ik5hbWUiOiJmcmFuY2l1bTI1L3Rlc3QyIiwiVVVJRCI6IjJkMzQzNTgxLWU5ZDYtNDBlNy1iZDBjLTNhMDRjMjcxZGQ5NiIsIk9mZnNldCI6MCwiU3RhcnRlZEF0IjoiMjAxOS0wOS0xMVQxNzo0OToxOS41NTMzMTc2ODdaIn0%3D
Now pushing a BLOb: ./path/to/40mb-file
real 0m2.314s
user 0m0.096s
sys 0m0.066s
chanseok$
Oh, actually, try to run the script with different BLObs in parallel (maybe run 4~5 at once) to simulate concurrent pushing to Docker Hub.
Seems like I am having issues with generating the access token. It says incorrect username or password
. I tried logging with those credentials again and know that they work. I can come back to this in a week or so. At the moment I just don't have any more time to spend on it.
BTW the same upload process is much faster with the Gradle plugin version 1.4.0 though I wouldn't expect it to take a minute.
./gradlew jib
Starting a Gradle Daemon, 1 incompatible Daemon could not be reused, use --status for details
> Task :jib
Containerizing application to bmuschko/todo-web-service:1.0.0...
Container entrypoint set to [java, -cp, /app/resources:/app/classes:/app/libs/*, com.bmuschko.todo.webservice.Application]
Built and pushed image as bmuschko/todo-web-service:1.0.0
Executing tasks:
[==============================] 100.0% complete
BUILD SUCCESSFUL in 1m 10s
3 actionable tasks: 2 executed, 1 up-to-date
I believe I can reproduce this at home where my network is very slow. With both Maven and Gradle.
I've spent quite some time, monitoring network throughput on my laptop. I am reasonably sure the problem starts to happen right after the commit to upgrade the underlying Google HTTP Client library to the new v2 world. The commit is after the 1.4.0 release, so 1.4.0 should work fine as before. Multiple users already reported 1.4.0 works.
Forgot to mention that most of the time, I'm hitting worse than slow. Almost all the time, my builds hang indefinitely.
Just joining the train of folks reporting that a downgrade to 1.4.0 fixed slow transfer speeds.
Thanks, everyone! Glad we collectively cracked this one!
@chanseokoh I have experienced that when i need to use a new base image for my old containers (1.5.0). I changed to trace an leak memory with jstack: openjdk:11-minimal (16MB) -> full openjdk (167MB), using my internal registry ( Jfrog Artifactory - HTTP) as a proxy.
@kalapraveen-mi are you using
<allowInsecureRegistries>
by any chance? If that is the case, I worry that 1.4.0 might be the last version that may seem to "work" (in a very inefficient way) in your case. I could be wrong about your case though.
@chanseokoh No, I am not using any such tag and logged into Docker container on Mac. We are using Jib plugin and is run as part of "deploy" phase in the following way:
<plugin>
<groupId>com.google.cloud.tools</groupId>
<artifactId>jib-maven-plugin</artifactId>
<version>1.4.0</version>
<configuration>
<from>
<image>BASE_IMAGE_NAME</image>
</from>
<to>
<image>TARGET_IMAGE_NAME:${project.version}</image>
</to>
<container>
<ports>
<port>8085</port>
<port>9085</port>
</ports>
<environment>
<MAIN_CLASS>APP_CLASS</MAIN_CLASS>
</environment>
<entrypoint>/usr/local/bin/entrypoint.sh</entrypoint>
</container>
</configuration>
<executions>
<execution>
<phase>deploy</phase>
<goals>
<goal>build</goal>
</goals>
</execution>
</executions>
</plugin>
Now, when I run the build of the project version contains SNAPSHOT it gets pushed effortlessly as it always does. However, if the ${project.version} contains a release it struggles and ends up with a credentials error. The same code works if I explicitly specify the version 1.4.0.
We push to dockerhub by the way. Hope this info helps. Thank you very much!
@kalapraveen-mi please open your issue in a new issue, as it does not appear to be directly related to this issue.
The slow network operation issue should be fixed by #1980. We will release 1.6.0, probably tomorrow.
@bmuschko @ndarilek @raizoor @kalapraveen-mi v1.6.0 has been released, which should fix this issue.
@TadCordle Thanks. I tried it out and its close to the numbers I see with version 1.4.0.
Environment:
Description of the issue:
Push the image to Docker Hub initially takes extremely long (almost 5 mins). Subsequent push operations are much faster (seconds).
Expected behavior:
Pushing an image to Docker Hub should match the execution time when using Docker Engine.
Steps to reproduce:
./gradlew jib
Log output: