Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Unable to push to harbor image with http #1917

Closed
riyaz opened this issue Aug 20, 2019 · 26 comments
Closed

Unable to push to harbor image with http #1917

riyaz opened this issue Aug 20, 2019 · 26 comments

Comments

@riyaz
Copy link

riyaz commented Aug 20, 2019

Environment:

  • Jib version: 1.5.0
  • Build tool: Gradle
  • OS: Mac OSX
  • Repository: Harbor

Description of the issue:

I have insecure harbor registry for now and trying to push it and pushing it with property sendCredentialsOverHttp=true but push always times out

Expected behavior:

Should be able to push

Steps to reproduce:

/gradlew jib -DsendCredentialsOverHttp=true -Djib.to.image=dockerhub-1003850024.ap-south-1.elb.amazonaws.com/sample -Djib.console=plain

jib-gradle-plugin Configuration:

jib {
    to {
        allowInsecureRegistries = true        
        tags = ['latest', '1.0.0-SNAPSHOT']
        auth {
            username = 'xyz'
            password = 'xyz'
        }
    }
    container {
        ports = ['8080']
        mainClass = "$mainClassName"
        args = ["run", mainVerticleName, "-conf staging.json"]
        jvmFlags = ['-Dvertx.logger-delegate-factory-class-name=io.vertx.core.logging.Log4j2LogDelegateFactory']
    }

}

Log output:

➜ ./gradlew jib -DsendCredentialsOverHttp=true -Djib.to.image=dockerhub-1003850024.ap-south-1.elb.amazonaws.com/sample -Djib.console=plain
Starting a Gradle Daemon, 1 busy and 1 incompatible Daemons could not be reused, use --status for details

> Task :jib
Authentication over HTTP is enabled. It is strongly recommended that you do not enable this on a public network!

Containerizing application to dockerhub-1003850024.ap-south-1.elb.amazonaws.com/sample, dockerhub-1003850024.ap-south-1.elb.amazonaws.com/sample, dockerhub-1003850024.ap-south-1.elb.amazonaws.com/sample:1.0.0-SNAPSHOT...
Retrieving registry credentials for dockerhub-1003850024.ap-south-1.elb.amazonaws.com...
Getting base image gcr.io/distroless/java:8...
Building dependencies layer...
Building project dependencies layer...
Building resources layer...
Building classes layer...

> Task :jib FAILED

FAILURE: Build failed with an exception.

* What went wrong:
Execution failed for task ':jib'.
> com.google.cloud.tools.jib.plugins.common.BuildStepsExecutionException: Connect to dockerhub-1003850024.ap-south-1.elb.amazonaws.com:443 [dockerhub-1003850024.ap-south-1.elb.amazonaws.com/35.154.123.120, dockerhub-1003850024.ap-south-1.elb.amazonaws.com/13.234.102.169] failed: Operation timed out (Connection timed out)

* Try:
Run with --stacktrace option to get the stack trace. Run with --info or --debug option to get more log output. Run with --scan to get full insights.

* Get more help at https://help.gradle.org

Deprecated Gradle features were used in this build, making it incompatible with Gradle 6.0.
Use '--warning-mode all' to show the individual deprecation warnings.
See https://docs.gradle.org/5.5.1/userguide/command_line_interface.html#sec:command_line_warnings

BUILD FAILED in 2m 40s
8 actionable tasks: 1 executed, 7 up-to-date

Additional Information:

Push works fine with docker command-line

docker tag xyz:1.0.0-SNAPSHOT dockerhub-1003850024.ap-south-1.elb.amazonaws.com/sample/xyz:1.0.0-SNAPSHOT

docker push dockerhub-1003850024.ap-south-1.elb.amazonaws.com/sample/xyz:1.0.0-SNAPSHOT
@briandealwis
Copy link
Member

Your total build time is reported as 2m40s which doesn't seem long! Here's a few things to try:

  • Now that you've pushed with docker, does a jib build succeed? Jib will now only need to push the unchanged layers, which should generally be much smaller.
  • Could you try with Jib 1.4.0? We upgraded our underlying HTTP library, and this would help to identify if there were some other change there.
  • Lastly, could you please obtain a network trace and post it here?

@riyaz
Copy link
Author

riyaz commented Aug 20, 2019

  • Now that you've pushed with docker, does a jib build succeed? Jib will now only need to push the unchanged layers, which should generally be much smaller.

You mean jibDockerBuild yes it does succeeded

  • Could you try with Jib 1.4.0? We upgraded our underlying HTTP library, and this would help to identify if there were some other change there.

I have tried, same issue

Below is the command i have used

./gradlew jib -DsendCredentialsOverHttp=true -Djib.to.image=dockerhub-1003850024.ap-south-1.elb.amazonaws.com/sample -Djib.console=plain -Djava.util.logging.config.file=logging.properties -DjibSerialize=true -Djib.serialize=true --debug

it produces too much logs posting here few which I feel is relevant

20:24:50.127 [DEBUG] [org.gradle.api.Task] TIMING       Building and pushing image
20:24:50.127 [LIFECYCLE] [org.gradle.api.Task] Getting base image gcr.io/distroless/java:8...
20:24:50.127 [DEBUG] [org.gradle.api.Task] TIMING       Pulling base image manifest
20:24:52.332 [DEBUG] [org.gradle.api.Task] TIMED        Pulling base image manifest : 2208.0 ms
20:24:52.332 [DEBUG] [org.gradle.api.Task] TIMING       Preparing base image layer pullers
20:24:52.332 [DEBUG] [org.gradle.api.Task] TIMED        Preparing base image layer pullers : 0.0 ms
20:24:52.332 [DEBUG] [org.gradle.api.Task] TIMING       Pulling base image layer sha256:e8d8785a314f385d3675a017f4e2df1707c528c06e7a7989663fdab4900bd8ff
20:24:52.332 [DEBUG] [org.gradle.api.Task] TIMED        Pulling base image layer sha256:e8d8785a314f385d3675a017f4e2df1707c528c06e7a7989663fdab4900bd8ff : 0.0 ms
20:24:52.332 [DEBUG] [org.gradle.api.Task] TIMING       Pulling base image layer sha256:e005d777a298a3529b1c8cf890883359e050cc966089ce84fea4d17b111907db
20:24:52.332 [DEBUG] [org.gradle.api.Task] TIMED        Pulling base image layer sha256:e005d777a298a3529b1c8cf890883359e050cc966089ce84fea4d17b111907db : 0.0 ms
20:24:52.333 [DEBUG] [org.gradle.api.Task] TIMING       Pulling base image layer sha256:3e010093287c245d72a774033b4cddd6451a820bfbb1948c97798e1838858dd2
20:24:52.334 [DEBUG] [org.gradle.api.Task] TIMED        Pulling base image layer sha256:3e010093287c245d72a774033b4cddd6451a820bfbb1948c97798e1838858dd2 : 1.0 ms
20:24:52.334 [DEBUG] [org.gradle.api.Task] TIMING       Pulling base image layer sha256:4348a160a40abb580b131736924d2f8044f54de5424897885a966c3225a913a2
20:24:52.334 [DEBUG] [org.gradle.api.Task] TIMED        Pulling base image layer sha256:4348a160a40abb580b131736924d2f8044f54de5424897885a966c3225a913a2 : 0.0 ms
20:24:52.334 [DEBUG] [org.gradle.api.Task] TIMING       Preparing application layer builders
20:24:52.335 [DEBUG] [org.gradle.api.Task] TIMED        Preparing application layer builders : 0.0 ms
20:24:52.335 [LIFECYCLE] [org.gradle.api.Task] Building dependencies layer...
20:24:52.335 [DEBUG] [org.gradle.api.Task] TIMING       Building dependencies layer
20:24:52.337 [DEBUG] [org.gradle.api.Task] TIMED        Building dependencies layer : 2.0 ms
20:24:52.337 [LIFECYCLE] [org.gradle.api.Task] Building project dependencies layer...
20:24:52.337 [DEBUG] [org.gradle.api.Task] TIMING       Building project dependencies layer
20:24:52.338 [DEBUG] [org.gradle.api.Task] TIMED        Building project dependencies layer : 1.0 ms
20:24:52.338 [LIFECYCLE] [org.gradle.api.Task] Building resources layer...
20:24:52.338 [DEBUG] [org.gradle.api.Task] TIMING       Building resources layer
20:24:52.339 [DEBUG] [org.gradle.api.Task] TIMED        Building resources layer : 1.0 ms
20:24:52.339 [LIFECYCLE] [org.gradle.api.Task] Building classes layer...
20:24:52.339 [DEBUG] [org.gradle.api.Task] TIMING       Building classes layer
20:24:52.341 [DEBUG] [org.gradle.api.Task] TIMED        Building classes layer : 1.0 ms
20:24:52.341 [DEBUG] [org.gradle.api.Task] TIMING       Building container configuration
20:24:52.341 [LIFECYCLE] [org.gradle.api.Task]
20:24:52.341 [LIFECYCLE] [org.gradle.api.Task] Container entrypoint set to [java, -Dvertx.logger-delegate-factory-class-name=io.vertx.core.logging.Log4j2LogDelegateFactory, -cp, /app/resources:/app/classes:/app/libs/*, io.vertx.core.Launcher]
20:24:52.341 [LIFECYCLE] [org.gradle.api.Task] Container program arguments set to [run, future.auth.MainVerticle, -conf staging.json]
20:24:52.341 [DEBUG] [org.gradle.api.Task] TIMED        Building container configuration : 0.0 ms
20:24:52.342 [LIFECYCLE] [org.gradle.api.Task] Retrieving registry credentials for dockerhub-1003850024.ap-south-1.elb.amazonaws.com...
20:24:52.342 [DEBUG] [org.gradle.api.Task] TIMING       Retrieving registry credentials for dockerhub-1003850024.ap-south-1.elb.amazonaws.com
20:24:52.342 [INFO] [org.gradle.api.Task] Using to.auth for dockerhub-1003850024.ap-south-1.elb.amazonaws.com
20:24:52.342 [DEBUG] [org.gradle.api.Task] TIMED        Retrieving registry credentials for dockerhub-1003850024.ap-south-1.elb.amazonaws.com : 0.0 ms
20:24:52.342 [DEBUG] [org.gradle.api.Task] TIMING       Authenticating push to dockerhub-1003850024.ap-south-1.elb.amazonaws.com
20:24:52.713 [LIFECYCLE] [org.gradle.process.internal.health.memory.MemoryManager]
20:24:52.713 [DEBUG] [org.gradle.process.internal.health.memory.MemoryManager] Emitting OS memory status event {Total: 17179869184, Free: 6100467712}
20:24:52.713 [DEBUG] [org.gradle.launcher.daemon.server.health.LowMemoryDaemonExpirationStrategy] Received memory status update: {Total: 17179869184, Free: 6100467712}
20:24:52.714 [DEBUG] [org.gradle.process.internal.health.memory.MemoryManager] Emitting JVM memory status event {Maximum: 477626368, Committed: 335544320}
20:24:54.594 [DEBUG] [org.gradle.launcher.daemon.server.Daemon] DaemonExpirationPeriodicCheck running
20:24:54.595 [DEBUG] [org.gradle.cache.internal.DefaultFileLockManager] Waiting to acquire shared lock on daemon addresses registry.
20:24:54.595 [DEBUG] [org.gradle.cache.internal.DefaultFileLockManager] Lock acquired on daemon addresses registry.
20:24:54.596 [DEBUG] [org.gradle.cache.internal.DefaultFileLockManager] Releasing lock on daemon addresses registry.
20:24:54.596 [DEBUG] [org.gradle.cache.internal.DefaultFileLockManager] Waiting to acquire shared lock on daemon addresses registry.
20:24:54.596 [DEBUG] [org.gradle.cache.internal.DefaultFileLockManager] Lock acquired on daemon addresses registry.
20:24:54.597 [DEBUG] [org.gradle.cache.internal.DefaultFileLockManager] Releasing lock on daemon addresses registry.
20:24:57.712 [DEBUG] [org.gradle.process.internal.health.memory.MemoryManager] Emitting OS memory status event {Total: 17179869184, Free: 6178791424}
20:24:57.712 [DEBUG] [org.gradle.launcher.daemon.server.health.LowMemoryDaemonExpirationStrategy] Received memory status update: {Total: 17179869184, Free: 6178791424}
20:24:57.712 [DEBUG] [org.gradle.process.internal.health.memory.MemoryManager] Emitting JVM memory status event {Maximum: 477626368, Committed: 335544320}
20:25:02.712 [DEBUG] [org.gradle.process.internal.health.memory.MemoryManager] Emitting OS memory status event {Total: 17179869184, Free: 6213652480}
20:25:02.712 [DEBUG] [org.gradle.launcher.daemon.server.health.LowMemoryDaemonExpirationStrategy] Received memory status update: {Total: 17179869184, Free: 6213652480}
20:25:02.712 [DEBUG] [org.gradle.process.internal.health.memory.MemoryManager] Emitting JVM memory status event {Maximum: 477626368, Committed: 335544320}
20:25:04.593 [DEBUG] [org.gradle.launcher.daemon.server.Daemon] DaemonExpirationPeriodicCheck running
20:25:04.594 [DEBUG] [org.gradle.cache.internal.DefaultFileLockManager] Waiting to acquire shared lock on daemon addresses registry.
20:25:04.594 [DEBUG] [org.gradle.cache.internal.DefaultFileLockManager] Lock acquired on daemon addresses registry.
20:25:04.594 [DEBUG] [org.gradle.cache.internal.DefaultFileLockManager] Releasing lock on daemon addresses registry.
20:25:04.595 [DEBUG] [org.gradle.cache.internal.DefaultFileLockManager] Waiting to acquire shared lock on daemon addresses registry.
20:25:04.595 [DEBUG] [org.gradle.cache.internal.DefaultFileLockManager] Lock acquired on daemon addresses registry.
20:25:04.596 [DEBUG] [org.gradle.cache.internal.DefaultFileLockManager] Releasing lock on daemon addresses registry.
20:25:07.716 [DEBUG] [org.gradle.process.internal.health.memory.MemoryManager] Emitting OS memory status event {Total: 17179869184, Free: 6210473984}
20:25:07.716 [DEBUG] [org.gradle.launcher.daemon.server.health.LowMemoryDaemonExpirationStrategy] Received memory status update: {Total: 17179869184, Free: 6210473984}
20:25:07.716 [DEBUG] [org.gradle.process.internal.health.memory.MemoryManager] Emitting JVM memory status event {Maximum: 477626368, Committed: 335544320}
20:24:52.333 [LIFECYCLE] [class org.gradle.internal.buildevents.TaskExecutionLogger]
20:24:52.333 [LIFECYCLE] [class org.gradle.internal.buildevents.TaskExecutionLogger] > Task :jib FAILED
20:25:12.347 [DEBUG] [org.gradle.api.Task] TIMED        Authenticating push to dockerhub-1003850024.ap-south-1.elb.amazonaws.com : 20005.0 ms
20:25:12.348 [DEBUG] [org.gradle.api.Task] TIMED        Building and pushing image : 22225.0 ms
20:25:12.348 [DEBUG] [org.gradle.internal.operations.DefaultBuildOperationExecutor] Completing Build operation 'Execute buildImage for :jib'
20:25:12.349 [DEBUG] [org.gradle.internal.operations.DefaultBuildOperationExecutor] Build operation 'Execute buildImage for :jib' completed
20:25:12.349 [DEBUG] [org.gradle.api.internal.tasks.execution.ResolveTaskExecutionModeExecuter] Removed task artifact state for {} from context.
20:25:12.349 [DEBUG] [org.gradle.internal.operations.DefaultBuildOperationExecutor] Completing Build operation 'Task :jib'
20:25:12.350 [DEBUG] [org.gradle.internal.operations.DefaultBuildOperationExecutor] Build operation 'Task :jib' completed
20:25:12.350 [INFO] [org.gradle.execution.plan.DefaultPlanExecutor] :jib (Thread[Execution worker for ':' Thread 4,5,main]) completed. Took 22.287 secs.
20:25:12.350 [DEBUG] [org.gradle.internal.resources.AbstractTrackedResourceLock] Execution worker for ':' Thread 4: released lock on :
20:25:12.350 [DEBUG] [org.gradle.internal.work.DefaultWorkerLeaseService] Worker lease root.1.16 completed (1 worker(s) in use)
20:25:12.350 [DEBUG] [org.gradle.internal.resources.AbstractTrackedResourceLock] Execution worker for ':' Thread 4: released lock on root.1.16
20:25:12.350 [DEBUG] [org.gradle.execution.plan.DefaultPlanExecutor] Execution worker [Thread[Execution worker for ':' Thread 4,5,main]] finished, busy: 22.294 secs, idle: 0.28 secs
20:25:12.351 [DEBUG] [org.gradle.execution.plan.DefaultPlanExecutor] Execution worker [Thread[Execution worker for ':' Thread 3,5,main]] finished, busy: 0.0 secs, idle: 22.575 secs
20:25:12.351 [DEBUG] [org.gradle.execution.plan.DefaultPlanExecutor] Execution worker [Thread[Execution worker for ':',5,main]] finished, busy: 0.208 secs, idle: 22.367 secs
20:25:12.351 [DEBUG] [org.gradle.execution.plan.DefaultPlanExecutor] Execution worker [Thread[Execution worker for ':' Thread 5,5,main]] finished, busy: 0.0 secs, idle: 22.575 secs
20:25:12.350 [DEBUG] [org.gradle.execution.plan.DefaultPlanExecutor] Execution worker [Thread[Execution worker for ':' Thread 6,5,main]] finished, busy: 0.0 secs, idle: 22.574 secs
20:25:12.350 [DEBUG] [org.gradle.execution.plan.DefaultPlanExecutor] Execution worker [Thread[Execution worker for ':' Thread 7,5,main]] finished, busy: 0.0 secs, idle: 22.574 secs
20:25:12.350 [DEBUG] [org.gradle.execution.plan.DefaultPlanExecutor] Execution worker [Thread[Daemon worker Thread 2,5,main]] finished, busy: 0.0 secs, idle: 22.574 secs
20:25:12.350 [DEBUG] [org.gradle.execution.plan.DefaultPlanExecutor] Execution worker [Thread[Execution worker for ':' Thread 2,5,main]] finished, busy: 0.049 secs, idle: 22.526 secs
20:25:12.354 [DEBUG] [org.gradle.execution.taskgraph.DefaultTaskExecutionGraph] Timing: Executing the DAG took 22.58 secs
20:25:12.356 [DEBUG] [org.gradle.internal.operations.DefaultBuildOperationExecutor] Completing Build operation 'Run tasks'
20:25:12.356 [DEBUG] [org.gradle.internal.operations.DefaultBuildOperationExecutor] Build operation 'Run tasks' completed
20:25:12.358 [DEBUG] [org.gradle.internal.work.DefaultWorkerLeaseService] Worker lease root.1 completed (0 worker(s) in use)
20:25:12.358 [DEBUG] [org.gradle.internal.resources.AbstractTrackedResourceLock] Daemon worker Thread 2: released lock on root.1
20:25:12.358 [ERROR] [org.gradle.internal.buildevents.BuildExceptionReporter]
20:25:12.358 [ERROR] [org.gradle.internal.buildevents.BuildExceptionReporter] FAILURE: Build failed with an exception.
20:25:12.358 [ERROR] [org.gradle.internal.buildevents.BuildExceptionReporter]
20:25:12.358 [ERROR] [org.gradle.internal.buildevents.BuildExceptionReporter] * What went wrong:
20:25:12.358 [ERROR] [org.gradle.internal.buildevents.BuildExceptionReporter] Execution failed for task ':jib'.
20:25:12.358 [ERROR] [org.gradle.internal.buildevents.BuildExceptionReporter] > com.google.cloud.tools.jib.plugins.common.BuildStepsExecutionException: connect timed out
20:25:12.358 [ERROR] [org.gradle.internal.buildevents.BuildExceptionReporter]
20:25:12.358 [ERROR] [org.gradle.internal.buildevents.BuildExceptionReporter] * Try:
20:25:12.358 [ERROR] [org.gradle.internal.buildevents.BuildExceptionReporter] Run with --stacktrace option to get the stack trace.  Run with --scan to get full insights.
20:25:12.358 [ERROR] [org.gradle.internal.buildevents.BuildExceptionReporter]
20:25:12.358 [ERROR] [org.gradle.internal.buildevents.BuildExceptionReporter] * Get more help at https://help.gradle.org
20:25:12.358 [WARN] [org.gradle.internal.featurelifecycle.LoggingDeprecatedFeatureHandler]
Deprecated Gradle features were used in this build, making it incompatible with Gradle 6.0.
Use '--warning-mode all' to show the individual deprecation warnings.
See https://docs.gradle.org/5.5.1/userguide/command_line_interface.html#sec:command_line_warnings
20:25:12.358 [ERROR] [org.gradle.internal.buildevents.BuildResultLogger]
20:25:12.359 [ERROR] [org.gradle.internal.buildevents.BuildResultLogger] BUILD FAILED in 23s

@chanseokoh
Copy link
Member

chanseokoh commented Aug 20, 2019

The network trace wasn't captured. It should have logged HTTP requests and responses like the sample below. Double-check the path to the logging.properties file and its content.

[DEBUG] TIMED   Authenticating push to gcr.io : 683.0 ms
[INFO] Getting base image mcr.microsoft.com/dotnet/core/aspnet:2.1-stretch-slim...
[DEBUG] TIMING  Pulling base image manifest
Aug 19, 2019 4:01:29 PM com.google.api.client.http.HttpRequest execute
CONFIG: -------------- REQUEST  --------------
GET https://mcr.microsoft.com/v2/dotnet/core/aspnet/manifests/2.1-stretch-slim
Accept: application/vnd.oci.image.manifest.v1+json,application/vnd.docker.distribution.manifest.v2+json,application/vnd.docker.distribution.manifest.v1+json
Accept-Encoding: gzip
User-Agent: jib 1.5.0 jib-maven-plugin Google-HTTP-Java-Client/1.30.0 (gzip)

Aug 19, 2019 4:01:29 PM com.google.api.client.http.HttpRequest execute
CONFIG: curl -v --compressed -H 'Accept: application/vnd.oci.image.manifest.v1+json,application/vnd.docker.distribution.manifest.v2+json,application/vnd.docker.distribution.manifest.v1+json' -H 'Accept-Encoding: gzip' -H 'User-Agent: jib 1.5.0 jib-maven-plugin Google-HTTP-Java-Client/1.30.0 (gzip)' -- 'https://mcr.microsoft.com/v2/dotnet/core/aspnet/manifests/2.1-stretch-slim'
Aug 19, 2019 4:01:29 PM com.google.api.client.http.HttpResponse <init>
CONFIG: -------------- RESPONSE --------------
HTTP/1.1 200 OK
Server: nginx
Date: Mon, 19 Aug 2019 20:01:29 GMT
Content-Type: application/vnd.docker.distribution.manifest.v2+json
Content-Length: 1164
Connection: keep-alive
Access-Control-Expose-Headers: Docker-Content-Digest
Access-Control-Expose-Headers: WWW-Authenticate
Access-Control-Expose-Headers: Link
Access-Control-Expose-Headers: X-Ms-Correlation-Request-Id
Docker-Content-Digest: sha256:8877c07647e44ecac2a38de638d1bcc0ad98f2a44aa0fd01a9a1bc04f7be4f18
Docker-Distribution-Api-Version: registry/2.0
Etag: "sha256:8877c07647e44ecac2a38de638d1bcc0ad98f2a44aa0fd01a9a1bc04f7be4f18"
Strict-Transport-Security: max-age=31536000; includeSubDomains
X-Content-Type-Options: nosniff
X-Ms-Client-Request-Id:
X-Ms-Correlation-Request-Id: 3bda3686-b091-42de-8f85-0faeabbd3f7d
X-Ms-Request-Id: 6ded8c7c-0c69-44a9-8840-16ac09262845
Strict-Transport-Security: max-age=31536000; includeSubDomains

Aug 19, 2019 4:01:29 PM com.google.api.client.util.LoggingByteArrayOutputStream close
CONFIG: Total: 1,164 bytes
Aug 19, 2019 4:01:29 PM com.google.api.client.util.LoggingByteArrayOutputStream close
CONFIG: {

it produces too much logs posting here few which I feel is relevant

You can attach a file to a comment. Just drag and drop.

Lastly,

        tags = ['latest', '1.0.0-SNAPSHOT']

In your case, latest in jib.to.tags is redundant. jib.to.tags is for additional tags, and the jib.to.image=dockerhub-1003850024.ap-south-1.elb.amazonaws.com/sample already implicitly points to latest.

@raizoor
Copy link

raizoor commented Aug 20, 2019

It's strange a HTTP using 443 port:

Execution failed for task :jib.

com.google.cloud.tools.jib.plugins.common.BuildStepsExecutionException: Connect to dockerhub-1003850024.ap-south-1.elb.amazonaws.com:443 [dockerhub-1003850024.ap-south-1.elb.amazonaws.com/35.154.123.120, dockerhub-1003850024.ap-south-1.elb.amazonaws.com/13.234.102.169] failed: Operation timed out (Connection timed out)

To my harbor (on premisses) aways works (https and http), but i'm using a robot account. I'm sending robotAccount and token out of POM (my case), in gitlab-ci command line.
If you pull any base image from this repository, have you the same error?

@riyaz
Copy link
Author

riyaz commented Aug 20, 2019

The network trace wasn't captured. It should have logged HTTP requests and responses like the sample below. Double-check the path to the logging.properties file and its content.

In your case, latest in jib.to.tags is redundant. jib.to.tags is for additional tags, and the jib.to.image=dockerhub-1003850024.ap-south-1.elb.amazonaws.com/sample already implicitly points to latest.

I double checked and triple checked the path and logging.properties but still i'm not getting network logs, below is the properties

handlers = java.util.logging.ConsoleHandler
java.util.logging.ConsoleHandler.level=ALL

# CONFIG hides authentication data
# ALL includes authentication data
com.google.api.client.http.level=CONFIG

below is the gradle command i'm using

./gradlew jib -DsendCredentialsOverHttp=true -Djib.to.image=dockerhub-1003850024.ap-south-1.elb.amazonaws.com/sample -Djava.util.logging.config.file=/path/logging.properties -DjibSerialize=true -Djib.serialize=true --debug

Also to isolate the issue, i have downloaded starter project from https://start.vertx.io/ and added jib, even in the starter project no network logs and push is failing.

Attached the sample project, only diff is i have removed username/password, if any of you want to try out i can share my username password privately.

jib-demo.zip

@chanseokoh

This comment has been minimized.

@chanseokoh
Copy link
Member

It must be a misconfiguration. Make sure the file is accessible and readable. Also try an absolute path. For example, you can place the file at /tmp/logging.properties.

Hmm... Gradle seems weird. I am trying it too, but often I don't get network traces either.

@riyaz
Copy link
Author

riyaz commented Aug 20, 2019

BTW, I just noticed that you used a different image reference when tried with docker. The repository in this case was .../sample/xyz.

That was a paste error, i did try with /sample/xyz

./gradlew jib -DsendCredentialsOverHttp=true -Djib.to.image=dockerhub-1003850024.ap-south-1.elb.amazonaws.com/sample/xyz -Djib.console=plain -Djava.util.logging.config.file=/tmp/logging.properties -DjibSerialize=true -Djib.serialize=true --debug

Also yes i have tried wit absolute path for logging.properties, still no network logs.

@riyaz
Copy link
Author

riyaz commented Aug 20, 2019

Also to note, when I try with AWS ECR it works fine, so it looks like some bug with my harbor instance and maybe because its using http.

@riyaz
Copy link
Author

riyaz commented Aug 20, 2019

Found the issue with network logs, gradle generates log only if i add --no-daemon

./gradlew --no-daemon -Djava.util.logging.config.file=/tmp/logging.properties -DjibSerialize=true -Djib.serialize=true jib -Djib.to.image=dockerhub-1003850024.ap-south-1.elb.amazonaws.com/sample/auth -Djib.console=plain --info

Attaching the logs, from the logs found 401 errors, so tried removing auth block and used helper from docker even that's giving 401, however push in docker works fine.

jib-1.4.log
jib-cred-helper.log
jib.log

@briandealwis
Copy link
Member

briandealwis commented Aug 20, 2019

@raizoor correctly identified the problem: your registry is serving across HTTP on port 80, and not HTTPS on port 443:

$ curl -i --connect-timeout 10 'https://dockerhub-1003850024.ap-south-1.elb.amazonaws.com/v2/'
curl: (7) Failed to connect to dockerhub-1003850024.ap-south-1.elb.amazonaws.com port 443: Operation timed out
$ curl -i --connect-timeout 10 'http://dockerhub-1003850024.ap-south-1.elb.amazonaws.com/v2/'
HTTP/1.1 401 Unauthorized
Date: Tue, 20 Aug 2019 18:42:02 GMT
Content-Type: application/json; charset=utf-8
Content-Length: 87
Connection: keep-alive
Server: nginx
Docker-Distribution-Api-Version: registry/2.0
Set-Cookie: sid=b482a0cf516f1e78fdaa64ed8ef40228; Path=/; HttpOnly
Www-Authenticate: Bearer realm="http://dockerhub-1003850024.ap-south-1.elb.amazonaws.com/service/token",service="harbor-registry"

{"errors":[{"code":"UNAUTHORIZED","message":"authentication required","detail":null}]}

I guess your firewall is configured to leave connections dangling.

See the docs for allowInsecureRegistries though we do not recommend this setting on the open internet!

@chanseokoh
Copy link
Member

chanseokoh commented Aug 20, 2019

@riyaz Thanks for the logs. (I prefer raw logs though. You don't have to cut them down yourself.) BTW, I was also facing issues in obtaining network logs with Gradle, so thanks for the tip. But it is still very unpredictable with --no-daemon, so it's puzzling.

Anyways, the reason you get 401 now is probably because you didn't put -DsendCredentialsOverHttp=true this time. However, -DsendCredentialsOverHttp=true is a very bad idea, because anyone on the Internet will be able to see and steal your credentials (unless amazonaws.com is in your local internal network, which I don't think is the case). In any case, I'd be curious to see the logs with -DsendCredentialsOverHttp=true (if you think you are OK with people on the Internet to be able to capture your auth info during experimentation).

@briandealwis the user has been using allowInsecureRegistries, and I do see that Jib automatically falls back to port 80 after trying 443.

@raizoor
Copy link

raizoor commented Aug 20, 2019

@riyaz Run again with -DsendCredentialsOverHttp=true and attach the same logs.
If jib automatically falls back to 80, it's not a firewall or network problem, unless your edge firewall force the requests to AMAZON outbound with HTTPS

@riyaz
Copy link
Author

riyaz commented Aug 21, 2019

I have attached logs again, below is the command i have used to build

./gradlew --no-daemon -Djava.util.logging.config.file=/tmp/logging.properties -DjibSerialize=true -Djib.serialize=true -Djib.to.image=dockerhub-1003850024.ap-south-1.elb.amazonaws.com/sample/auth -Djib.console=plain --info -DsendCredentialsOverHttp=true --info jib

jib2.log

@raizoor
Copy link

raizoor commented Aug 21, 2019

@chanseokoh see bellow, JIB only sent a HTTPS request

> Task :jib
-------------- REQUEST  --------------
GET https://dockerhub-1003850024.ap-south-1.elb.amazonaws.com/v2/
Accept:
Accept-Encoding: gzip
User-Agent: jib 1.4.0 jib-gradle-plugin Google-HTTP-Java-Client/1.27.0 (gzip)

curl -v --compressed -H 'Accept: ' -H 'Accept-Encoding: gzip' -H 'User-Agent: jib 1.4.0 jib-gradle-plugin Google-HTTP-Java-Client/1.27.0 (gzip)' -- 'https://dockerhub-1003850024.ap-south-1.elb.amazonaws.com/v2/'

> Task :jib FAILED
:jib (Thread[Task worker for ':' Thread 4,5,main]) completed. Took 23.379 secs.

FAILURE: Build failed with an exception.

* What went wrong:
Execution failed for task ':jib'.
> com.google.cloud.tools.jib.plugins.common.BuildStepsExecutionException: connect timed out

* Try:
Run with --stacktrace option to get the stack trace. Run with --debug option to get more log output. Run with --scan to get full insights.

* Get more help at https://help.gradle.org

@briandealwis
Copy link
Member

briandealwis commented Aug 21, 2019

Just a few follow-ups:

Now that you've pushed with docker, does a jib build succeed? Jib will now only need to push the unchanged layers, which should generally be much smaller.

You mean jibDockerBuild yes it does succeeded

I meant a second ./gradlew jib: I was wondering if the push was timing out during a layer push (#691). It's not (see below).

@briandealwis the user has been using allowInsecureRegistries, and I do see that Jib automatically falls back to port 80 after trying 443.

That's interesting because when I try reproducing the connection fails due to a java.net.SocketTimeoutException. Although the configuration is using allowInsecureRegistries, our HTTP fallback only happens on java.net.ConnectionException. But java.net.SocketTimeoutException is not a subclass of ConnectionException.

$ mvn -Djib.from.image=dockerhub-1003850024.ap-south-1.elb.amazonaws.com/foo jib:dockerBuild -Djib.console=plain -X  -Djib.allowInsecureRegistries=true
[INFO] ------------------------------------------------------------------------
[INFO] BUILD FAILURE
[INFO] ------------------------------------------------------------------------
[INFO] Total time: 21.019 s
[INFO] Finished at: 2019-08-21T10:54:27-04:00
[INFO] ------------------------------------------------------------------------
[ERROR] Failed to execute goal com.google.cloud.tools:jib-maven-plugin:1.2.0:buildTar (default-cli) on project first: connect timed out -> [Help 1]
org.apache.maven.lifecycle.LifecycleExecutionException: Failed to execute goal com.google.cloud.tools:jib-maven-plugin:1.2.0:buildTar (default-cli) on project first: connect timed out
[...]
Caused by: java.net.SocketTimeoutException: connect timed out
    at java.net.PlainSocketImpl.socketConnect (Native Method)
    at java.net.AbstractPlainSocketImpl.doConnect (AbstractPlainSocketImpl.java:350)
    at java.net.AbstractPlainSocketImpl.connectToAddress (AbstractPlainSocketImpl.java:206)
    at java.net.AbstractPlainSocketImpl.connect (AbstractPlainSocketImpl.java:188)
    at java.net.SocksSocketImpl.connect (SocksSocketImpl.java:392)
    at java.net.Socket.connect (Socket.java:589)
    at org.apache.http.conn.ssl.SSLSocketFactory.connectSocket (SSLSocketFactory.java:542)
    at org.apache.http.conn.ssl.SSLSocketFactory.connectSocket (SSLSocketFactory.java:414)
    at org.apache.http.conn.ssl.SSLSocketFactory.connectSocket (SSLSocketFactory.java:488)
    at org.apache.http.conn.scheme.SchemeSocketFactoryAdaptor.connectSocket (SchemeSocketFactoryAdaptor.java:66)
    at org.apache.http.impl.conn.DefaultClientConnectionOperator.openConnection (DefaultClientConnectionOperator.java:180)
    at org.apache.http.impl.conn.AbstractPoolEntry.open (AbstractPoolEntry.java:144)
    at org.apache.http.impl.conn.AbstractPooledConnAdapter.open (AbstractPooledConnAdapter.java:134)
    at org.apache.http.impl.client.DefaultRequestDirector.tryConnect (DefaultRequestDirector.java:610)
    at org.apache.http.impl.client.DefaultRequestDirector.execute (DefaultRequestDirector.java:445)
    at org.apache.http.impl.client.AbstractHttpClient.doExecute (AbstractHttpClient.java:835)
    at org.apache.http.impl.client.CloseableHttpClient.execute (CloseableHttpClient.java:83)
    at org.apache.http.impl.client.CloseableHttpClient.execute (CloseableHttpClient.java:108)
    at org.apache.http.impl.client.CloseableHttpClient.execute (CloseableHttpClient.java:56)
    at com.google.api.client.http.apache.ApacheHttpRequest.execute (ApacheHttpRequest.java:65)
    at com.google.api.client.http.HttpRequest.execute (HttpRequest.java:1011)
    at com.google.cloud.tools.jib.http.Connection.send (Connection.java:200)
    at com.google.cloud.tools.jib.registry.RegistryEndpointCaller.call (RegistryEndpointCaller.java:251)
    at com.google.cloud.tools.jib.registry.RegistryEndpointCaller.callWithAllowInsecureRegistryHandling (RegistryEndpointCaller.java:171)
    at com.google.cloud.tools.jib.registry.RegistryEndpointCaller.call (RegistryEndpointCaller.java:161)
    at com.google.cloud.tools.jib.registry.RegistryClient.callRegistryEndpoint (RegistryClient.java:356)
    at com.google.cloud.tools.jib.registry.RegistryClient.pullManifest (RegistryClient.java:202)
    at com.google.cloud.tools.jib.registry.RegistryClient.pullManifest (RegistryClient.java:210)
    at com.google.cloud.tools.jib.builder.steps.PullBaseImageStep.pullBaseImage (PullBaseImageStep.java:232)
    at com.google.cloud.tools.jib.builder.steps.PullBaseImageStep.call (PullBaseImageStep.java:144)
    at com.google.cloud.tools.jib.builder.steps.PullBaseImageStep.call (PullBaseImageStep.java:63)
[...]

@briandealwis
Copy link
Member

Jib currently always tries to connect via HTTPS and only then retries with HTTP when allowInsecureConnections=true. So @riyaz I think the workaround now is to configure your instance to use HTTPS, or to somehow configure your firewall to properly reject connections to port 443.

@chanseokoh this might be a motivating case for turning allowInsecureRegistries from a true/false to a list of registries as we could just immediately proceed to an HTTP connection.

@chanseokoh
Copy link
Member

@riyaz I noticed there is a difference between Jib 1.4.0 and 1.5.0 regarding <allowInsecureRegistries>. Can you try it again with 1.5.0 too and upload a log? This time, please use --stacktrace --debug instead of --info. (After all, I would end up suggesting the same as @briandealwis said to just set up an HTTPS registry, but I need to do some more investigation on 1.4.0 vs 1.5.0 and I need your help.)

@chanseokoh
Copy link
Member

@raizoor if you look at the jib-cred-helper.log and jib.log from #1917 (comment), we can check the HTTPS-to-HTTP fallback did happen. I suspect this happens only with 1.5.0 but not with 1.4.0.

Failed to connect to https://dockerhub-1003850024.ap-south-1.elb.amazonaws.com/v2/ over HTTPS. Attempting again with HTTP: http://dockerhub-1003850024.ap-south-1.elb.amazonaws.com/v2/

> Task :jib
-------------- REQUEST  --------------
GET http://dockerhub-1003850024.ap-south-1.elb.amazonaws.com/v2/
Accept:
Accept-Encoding: gzip
User-Agent: jib 1.5.0 jib-gradle-plugin Google-HTTP-Java-Client/1.30.0 (gzip)

curl -v --compressed -H 'Accept: ' -H 'Accept-Encoding: gzip' -H 'User-Agent: jib 1.5.0 jib-gradle-plugin Google-HTTP-Java-Client/1.30.0 (gzip)' -- 'http://dockerhub-1003850024.ap-south-1.elb.amazonaws.com/v2/'
-------------- RESPONSE --------------
HTTP/1.1 401 Unauthorized

@riyaz
Copy link
Author

riyaz commented Aug 21, 2019

Regarding no network logs with gradle, --no-daemon seems to work sometime only, if we downgrade the gradle version to 4.10.3 it always works.

I have requested our infra team to setup ssl, meanwhile i have switched to aws ecr for now.

Attached the log with 1.5,

./gradlew --no-daemon -Djava.util.logging.config.file=/tmp/logging.properties -DjibSerialize=true -Djib.serialize=true -Djib.to.image=dockerhub-1003850024.ap-south-1.elb.amazonaws.com/sample/starter -Djib.console=plain -DsendCredentialsOverHttp=true jib --stacktrace --debug

It was keep on trying for more than 20 mins so I had to abort, typically it takes max 30 seconds to upload my image using docker cli.

jib5.log

@briandealwis
Copy link
Member

My test above used Jib 1.2.0 and I had the same result on 1.4.0. With Jib 1.5.0 I do see Jib cascading from HTTPS to HTTP. I see lengthy timeouts though (1m15s or so) on any request though.

@chanseokoh
Copy link
Member

chanseokoh commented Aug 21, 2019

@riyaz looked at your last log. No wonder it takes > 20 minutes (with 1.5.0). At least it is indeed working but very inefficient because Jib first tries HTTPS (port 443) before trying HTTP (port 80) for every access to your registry. And this HTTPS-to-HTTP failover can happen only when the HTTPS attempt times out. The log shows that the timeout is about 75 seconds. That is, for every HTTP request Jib makes to your registry, it first has to wait for ~75 seconds. But I do see that the plain http:// is very fast.

22:11:01.880 [INFO] [com.google.api.client.http.HttpTransport] -------------- REQUEST  --------------
GET https://dockerhub-1003850024.ap-south-1.elb.amazonaws.com/v2/

22:12:17.265 [INFO] [org.gradle.api.Task] Failed to connect to https://dockerhub-1003850024.ap-south-1.elb.amazonaws.com/v2/ over HTTPS. Attempting again with HTTP: http://dockerhub-1003850024.ap-south-1.elb.amazonaws.com/v2/
22:12:17.269 [INFO] [com.google.api.client.http.HttpTransport] -------------- REQUEST  --------------

22:12:17.269 [INFO] [com.google.api.client.http.HttpTransport] curl -v --compressed -H 'Accept: ' -H 'Accept-Encoding: gzip' -H 'User-Agent: jib 1.5.0 jib-gradle-plugin Google-HTTP-Java-Client/1.30.0 (gzip)' -- 'http://dockerhub-1003850024.ap-south-1.elb.amazonaws.com/v2/'
22:12:17.484 [INFO] [com.google.api.client.http.HttpTransport] -------------- RESPONSE --------------
HTTP/1.1 401 Unauthorized
Date: Wed, 21 Aug 2019 16:42:17 GMT

22:12:17.500 [INFO] [com.google.api.client.http.HttpTransport] -------------- REQUEST  --------------
GET http://dockerhub-1003850024.ap-south-1.elb.amazonaws.com/service/token?service=harbor-registry&scope=repository:sample/starter:pull,push

22:12:17.500 [INFO] [com.google.api.client.http.HttpTransport] curl -v --compressed -H 'Accept: */*' -H 'Accept-Encoding: gzip' -H 'Authorization: <Not Logged>' -H 'User-Agent: jib 1.5.0 jib-gradle-plugin Google-HTTP-Java-Client/1.30.0 (gzip)' -- 'http://dockerhub-1003850024.ap-south-1.elb.amazonaws.com/service/token?service=harbor-registry&scope=repository:sample/starter:pull,push'
22:12:17.586 [INFO] [com.google.api.client.http.HttpTransport] -------------- RESPONSE --------------
HTTP/1.1 200 OK

That said, if you specify the port :80 in your image reference (e.g., ...elb.amazonaws.com:80/sample/...), I bet it will be very fast, as it will attempt the plain HTTP directly. Later you could add an additional tag using whatever means to have the correct name without the port part (:80). Another dirty hack would be to somehow configure your firewall or network so that any connection attempt to amazonaws.com:443 drops immediately as @briandealwis said.

But, I strongly recommend you make the port 443 work as a registry and close the insecure registry at port 80. I'm emphasizing again that by sending credentials over HTTP, anyone in the wild can capture and steal your username and password easily.

I have requested our infra team to setup ssl, meanwhile i have switched to aws ecr for now.

Given that you don't have a secure registry, ECR seems rather the right choice. I would continue using it, at least until you set up SSL.

Regarding no network logs with gradle, --no-daemon seems to work sometime only, if we downgrade the gradle version to 4.10.3 it always works.

Thanks for the info. It's good to know. We are baffled too.

@raizoor
Copy link

raizoor commented Aug 21, 2019

@chanseokoh this timeout (75s) has been returned by @riyaz network or JIB?

@chanseokoh
Copy link
Member

@raizoor both the default connection timeout and the read timeout are set to 20 seconds by default (configurable with -Djib.httpTimeout), so I'm actually confused why it isn't enforced.

@chanseokoh
Copy link
Member

@raizoor both the default connection timeout and the read timeout are set to 20 seconds by default (configurable with -Djib.httpTimeout), so I'm actually confused why it isn't enforced.

I did an investigation, and I think it is the bug in recent Google HTTP Client versions that does not honor the given connection timeout. (Haven't tested read timeout yet.) Jib 1.5.0 is affected, and I am positive that the timeout will work correctly on 1.4.0.

@chanseokoh
Copy link
Member

chanseokoh commented Sep 5, 2019

@riyaz we all know what exactly is happening and why. A few issues were identified:

  • Regression: starting with 1.5.0, -Djib.httpTimeout has no effect due to a bug in Google HTTP Client. I filed a new issue (Regression: jib.httpTimeout does not work with >= 1.5.0 #1954) in this repo to track.
  • Sometimes, network timeout causes Jib to fall back to non-HTTP requests if allowInsecureRegistries is enabled. This is what happened to you with 1.5.0 (triggered from the above HTTP library bug). We fixed this inconsistency, and the next Jib release will fail right away in case of timeout (Do not fall back to HTTP for connection timeout #1949); no more fail over for timeout. Therefore, you may be thinking Jib 1.5.0 somehow works with allowInsecureRegistries at the moment on your endpoint dockerhub-1003850024.ap-south-1.elb.amazonaws.com, but it will stop working at all in future releases.
  • Performance suffers when using allowInsecureRegistries due to repeated failover. We already have an issue (Optimize insecure registry failover #946). The issue is a low priority, as we discourage the use of allowInsecureRegistries.

I'll go ahead and close this issue. As I said, ECR seems the right choice at the moment. I would continue using it, at least until you set up SSL. And try to avoid using allowInsecureRegistries.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

4 participants