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

Jib should check and refresh access tokens as required #691

Closed
ghostbuster91 opened this issue Jul 22, 2018 · 21 comments · Fixed by #2233
Closed

Jib should check and refresh access tokens as required #691

ghostbuster91 opened this issue Jul 22, 2018 · 21 comments · Fixed by #2233
Milestone

Comments

@ghostbuster91
Copy link

Description of the issue:
Hi, I don't know why this happens but when I specify a larger image as base image the build fails.
Both images are in the same repository. The only difference is the size, smaller is something around 50 MB and bigger 500 MB. Maybe that's just a problem with my network, but again it is hard to tell based on the error message. Actually when I look at docker.hub interface, everything looks ok, I mean that the new image was uploaded.

Expected behavior:
Sometimes build passes but very rarely, so that would be the expected behavior.

Steps to reproduce:
It is hard for me to provide some steps since both images are in a private repository.

Environment:
Ubuntu 18.04, jdk 1.8

jib-gradle-plugin Configuration:

plugins {
    id 'com.google.cloud.tools.jib' version '0.9.6'
}
apply plugin: 'java'

group 'test-jib'
version '1.0-SNAPSHOT'

sourceCompatibility = 1.8

repositories {
    mavenCentral()
}

dependencies {
    testCompile group: 'junit', name: 'junit', version: '4.12'
}

jib {
    from {
        image = 'userfeeds/base-java-image'
    }
    to {
        image = 'ghostbuster91/test-jib'
    }
    container {
        mainClass = 'Main'
    }
}

Log output:

❯ ./gradlew jib --stacktrace
Starting a Gradle Daemon, 2 stopped Daemons could not be reused, use --status for details
Parallel execution with configuration on demand is an incubating feature.
warning: Base image 'userfeeds/base-java-image' does not use a specific image digest - build may not be reproducible

Containerizing application to ghostbuster91/test-jib...

Retrieving registry credentials for registry.hub.docker.com...
Getting base image userfeeds/base-java-image...
Building dependencies layer...
Building classes layer...
Building resources layer...
Retrieving registry credentials for registry.hub.docker.com...
Finalizing...

FAILURE: Build failed with an exception.

* What went wrong:
Execution failed for task ':jib'.
> Build image failed, perhaps you should set a credential helper name with the configuration 'from.credHelper' or from.auth

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

* Exception is:
org.gradle.api.tasks.TaskExecutionException: Execution failed for task ':jib'.
        at org.gradle.api.internal.tasks.execution.ExecuteActionsTaskExecuter.executeActions(ExecuteActionsTaskExecuter.java:103)
        at org.gradle.api.internal.tasks.execution.ExecuteActionsTaskExecuter.execute(ExecuteActionsTaskExecuter.java:73)
        at org.gradle.api.internal.tasks.execution.OutputDirectoryCreatingTaskExecuter.execute(OutputDirectoryCreatingTaskExecuter.java:51)
        at org.gradle.api.internal.tasks.execution.SkipUpToDateTaskExecuter.execute(SkipUpToDateTaskExecuter.java:59)
        at org.gradle.api.internal.tasks.execution.ResolveTaskOutputCachingStateExecuter.execute(ResolveTaskOutputCachingStateExecuter.java:54)
        at org.gradle.api.internal.tasks.execution.ValidatingTaskExecuter.execute(ValidatingTaskExecuter.java:59)
        at org.gradle.api.internal.tasks.execution.SkipEmptySourceFilesTaskExecuter.execute(SkipEmptySourceFilesTaskExecuter.java:101)
        at org.gradle.api.internal.tasks.execution.FinalizeInputFilePropertiesTaskExecuter.execute(FinalizeInputFilePropertiesTaskExecuter.java:44)
        at org.gradle.api.internal.tasks.execution.CleanupStaleOutputsExecuter.execute(CleanupStaleOutputsExecuter.java:91)
        at org.gradle.api.internal.tasks.execution.ResolveTaskArtifactStateTaskExecuter.execute(ResolveTaskArtifactStateTaskExecuter.java:62)
        at org.gradle.api.internal.tasks.execution.SkipTaskWithNoActionsExecuter.execute(SkipTaskWithNoActionsExecuter.java:59)
        at org.gradle.api.internal.tasks.execution.SkipOnlyIfTaskExecuter.execute(SkipOnlyIfTaskExecuter.java:54)
        at org.gradle.api.internal.tasks.execution.ExecuteAtMostOnceTaskExecuter.execute(ExecuteAtMostOnceTaskExecuter.java:43)
        at org.gradle.api.internal.tasks.execution.CatchExceptionTaskExecuter.execute(CatchExceptionTaskExecuter.java:34)
        at org.gradle.execution.taskgraph.DefaultTaskGraphExecuter$EventFiringTaskWorker$1.run(DefaultTaskGraphExecuter.java:256)
        at org.gradle.internal.progress.DefaultBuildOperationExecutor$RunnableBuildOperationWorker.execute(DefaultBuildOperationExecutor.java:336)
        at org.gradle.internal.progress.DefaultBuildOperationExecutor$RunnableBuildOperationWorker.execute(DefaultBuildOperationExecutor.java:328)
        at org.gradle.internal.progress.DefaultBuildOperationExecutor.execute(DefaultBuildOperationExecutor.java:199)
        at org.gradle.internal.progress.DefaultBuildOperationExecutor.run(DefaultBuildOperationExecutor.java:110)
        at org.gradle.execution.taskgraph.DefaultTaskGraphExecuter$EventFiringTaskWorker.execute(DefaultTaskGraphExecuter.java:249)
        at org.gradle.execution.taskgraph.DefaultTaskGraphExecuter$EventFiringTaskWorker.execute(DefaultTaskGraphExecuter.java:238)
        at org.gradle.execution.taskgraph.DefaultTaskPlanExecutor$TaskExecutorWorker.processTask(DefaultTaskPlanExecutor.java:123)
        at org.gradle.execution.taskgraph.DefaultTaskPlanExecutor$TaskExecutorWorker.access$200(DefaultTaskPlanExecutor.java:79)
        at org.gradle.execution.taskgraph.DefaultTaskPlanExecutor$TaskExecutorWorker$1.execute(DefaultTaskPlanExecutor.java:104)
        at org.gradle.execution.taskgraph.DefaultTaskPlanExecutor$TaskExecutorWorker$1.execute(DefaultTaskPlanExecutor.java:98)
        at org.gradle.execution.taskgraph.DefaultTaskExecutionPlan.execute(DefaultTaskExecutionPlan.java:663)
        at org.gradle.execution.taskgraph.DefaultTaskExecutionPlan.executeWithTask(DefaultTaskExecutionPlan.java:597)
        at org.gradle.execution.taskgraph.DefaultTaskPlanExecutor$TaskExecutorWorker.run(DefaultTaskPlanExecutor.java:98)
        at org.gradle.internal.concurrent.ExecutorPolicy$CatchAndRecordFailures.onExecute(ExecutorPolicy.java:63)
        at org.gradle.internal.concurrent.ManagedExecutorImpl$1.run(ManagedExecutorImpl.java:46)
        at org.gradle.internal.concurrent.ThreadFactoryImpl$ManagedThreadRunnable.run(ThreadFactoryImpl.java:55)
Caused by: org.gradle.api.GradleException: Build image failed, perhaps you should set a credential helper name with the configuration 'from.credHelper' or from.auth
        at com.google.cloud.tools.jib.gradle.BuildImageTask.buildImage(BuildImageTask.java:153)
        at org.gradle.internal.reflect.JavaMethod.invoke(JavaMethod.java:73)
        at org.gradle.api.internal.project.taskfactory.StandardTaskAction.doExecute(StandardTaskAction.java:46)
        at org.gradle.api.internal.project.taskfactory.StandardTaskAction.execute(StandardTaskAction.java:39)
        at org.gradle.api.internal.project.taskfactory.StandardTaskAction.execute(StandardTaskAction.java:26)
        at org.gradle.api.internal.AbstractTask$TaskActionWrapper.execute(AbstractTask.java:788)
        at org.gradle.api.internal.AbstractTask$TaskActionWrapper.execute(AbstractTask.java:755)
        at org.gradle.api.internal.tasks.execution.ExecuteActionsTaskExecuter$1.run(ExecuteActionsTaskExecuter.java:124)
        at org.gradle.internal.progress.DefaultBuildOperationExecutor$RunnableBuildOperationWorker.execute(DefaultBuildOperationExecutor.java:336)
        at org.gradle.internal.progress.DefaultBuildOperationExecutor$RunnableBuildOperationWorker.execute(DefaultBuildOperationExecutor.java:328)
        at org.gradle.internal.progress.DefaultBuildOperationExecutor.execute(DefaultBuildOperationExecutor.java:199)
        at org.gradle.internal.progress.DefaultBuildOperationExecutor.run(DefaultBuildOperationExecutor.java:110)
        at org.gradle.api.internal.tasks.execution.ExecuteActionsTaskExecuter.executeAction(ExecuteActionsTaskExecuter.java:113)
        at org.gradle.api.internal.tasks.execution.ExecuteActionsTaskExecuter.executeActions(ExecuteActionsTaskExecuter.java:95)
        ... 30 more
Caused by: com.google.cloud.tools.jib.registry.RegistryUnauthorizedException: Unauthorized for registry.hub.docker.com/ghostbuster91/test-jib
        at com.google.cloud.tools.jib.registry.RegistryEndpointCaller.call(RegistryEndpointCaller.java:200)
        at com.google.cloud.tools.jib.registry.RegistryEndpointCaller.call(RegistryEndpointCaller.java:139)
        at com.google.cloud.tools.jib.registry.RegistryClient.callRegistryEndpoint(RegistryClient.java:338)
        at com.google.cloud.tools.jib.registry.RegistryClient.pushBlob(RegistryClient.java:303)
        at com.google.cloud.tools.jib.builder.steps.PushBlobStep.call(PushBlobStep.java:87)
        at com.google.cloud.tools.jib.builder.steps.PushBlobStep.call(PushBlobStep.java:35)
        at com.google.common.util.concurrent.CombinedFuture$CallableInterruptibleTask.runInterruptibly(CombinedFuture.java:181)
        at com.google.common.util.concurrent.InterruptibleTask.run(InterruptibleTask.java:57)
Caused by: com.google.api.client.http.HttpResponseException: 401 Unauthorized
{"errors":[{"code":"UNAUTHORIZED","message":"authentication required","detail":[{"Type":"repository","Class":"","Name":"ghostbuster91/test-jib","Action":"pull"},{"Type":"repository","Class":"","Name":"ghostbuster91/test-jib","Action":"push"}]}]}

        at com.google.api.client.http.HttpRequest.execute(HttpRequest.java:1070)
        at com.google.cloud.tools.jib.http.Connection.send(Connection.java:124)
        at com.google.cloud.tools.jib.registry.RegistryEndpointCaller.call(RegistryEndpointCaller.java:169)
        ... 7 more


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

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

Additional Information:
What is common for this failures is that they always took around 8-10 minutes.

@coollog

This comment has been minimized.

@chanseokoh
Copy link
Member

Sometimes build passes but very rarely

What is common for this failures is that they always took around 8-10 minutes.

Does this mean if the build succeeds it takes a lot less than 8-10 minutes? Do you remember how long it took when it succeeded?

@ghostbuster91

This comment has been minimized.

@chanseokoh
Copy link
Member

Hmm... could it be that the credential we retrieve expires after a few minutes? However, this is just a completely wild guess.

@coollog

This comment has been minimized.

@chanseokoh
Copy link
Member

@ghostbuster91 is this still happening with 0.9.7? If that's the case, I think ./gradlew jib --info --stacktrace will give us more clues.

@chanseokoh
Copy link
Member

chanseokoh commented Jul 26, 2018

Hmm... could it be that the credential we retrieve expires after a few minutes? However, this is just a completely wild guess.

I think my suspicison was right. I can reproduce this locally with Docker Hub. In RegistryClient.pushBlob(), I put a couple of Thread.sleep().

The result is the 401 Unauthorized.

        Thread.sleep(3 * 60 * 1000);
        t2.lap("pushBlob PATCH " + blobDigest);

        // PATCH <Location> with BLOB
        URL putLocation = callRegistryEndpoint(blobPusher.writer(patchLocation));
        Preconditions.checkNotNull(putLocation);

        Thread.sleep(5 * 60 * 1000);
        t2.lap("pushBlob PUT " + blobDigest);

        // PUT <Location>?digest={blob.digest}
        callRegistryEndpoint(blobPusher.committer(putLocation));

Output:

[INFO] ------------------------------------------------------------------------
[INFO] BUILD FAILURE
[INFO] ------------------------------------------------------------------------
[INFO] Total time: 08:03 min
[INFO] Finished at: 2018-07-26T17:58:21-04:00
[INFO] Final Memory: 21M/487M
[INFO] ------------------------------------------------------------------------
[ERROR] Failed to execute goal com.google.cloud.tools:jib-maven-plugin:0.9.8-SNAPSHOT:build (default-cli) on project helloworld: Build image failed, perhaps you should set a credential helper name with the configuration '<to><credHelper>' or set credentials for 'registry.hub.docker.com' in your Maven settings: Unauthorized for registry.hub.docker.com/francium25/helloworld: 401 Unauthorized
[ERROR] {"errors":[{"code":"UNAUTHORIZED","message":"authentication required","detail":[{"Type":"repository","Class":"","Name":"francium25/helloworld","Action":"pull"},{"Type":"repository","Class":"","Name":"francium25/helloworld","Action":"push"}]}]}
[ERROR] -> [Help 1]
[ERROR] 
[ERROR] To see the full stack trace of the errors, re-run Maven with the -e switch.
[ERROR] Re-run Maven using the -X switch to enable full debug logging.
[ERROR] 
[ERROR] For more information about the errors and possible solutions, please read the following articles:
[ERROR] [Help 1] http://cwiki.apache.org/confluence/display/MAVEN/MojoExecutionException
Jul 26, 2018 5:58:21 PM com.google.common.util.concurrent.AggregateFuture$RunningState handleException
SEVERE: Got more than one input Future failure. Logging failures after the first
com.google.cloud.tools.jib.registry.RegistryUnauthorizedException: Unauthorized for registry.hub.docker.com/francium25/helloworld
        at com.google.cloud.tools.jib.registry.RegistryEndpointCaller.call(RegistryEndpointCaller.java:199)
        at com.google.cloud.tools.jib.registry.RegistryEndpointCaller.call(RegistryEndpointCaller.java:128)
        at com.google.cloud.tools.jib.registry.RegistryClient.callRegistryEndpoint(RegistryClient.java:349)
        at com.google.cloud.tools.jib.registry.RegistryClient.pushBlob(RegistryClient.java:310)
        at com.google.cloud.tools.jib.builder.steps.PushBlobStep.call(PushBlobStep.java:87)
        at com.google.cloud.tools.jib.builder.steps.PushBlobStep.call(PushBlobStep.java:35)
        at com.google.common.util.concurrent.CombinedFuture$CallableInterruptibleTask.runInterruptibly(CombinedFuture.java:181)
        at com.google.common.util.concurrent.InterruptibleTask.run(InterruptibleTask.java:57)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
        at java.lang.Thread.run(Thread.java:748)
Caused by: com.google.api.client.http.HttpResponseException: 401 Unauthorized
{"errors":[{"code":"UNAUTHORIZED","message":"authentication required","detail":[{"Type":"repository","Class":"","Name":"francium25/helloworld","Action":"pull"},{"Type":"repository","Class":"","Name":"francium25/helloworld","Action":"push"}]}]}

        at com.google.api.client.http.HttpRequest.execute(HttpRequest.java:1070)
        at com.google.cloud.tools.jib.http.Connection.send(Connection.java:161)
        at com.google.cloud.tools.jib.registry.RegistryEndpointCaller.call(RegistryEndpointCaller.java:160)
        ... 10 more

My previous analysis that I didn't post as a comment, as I wasn't sure:

Analysis (click the arrow to expand)

The error goes through RegistryClient.java:303.

        at com.google.cloud.tools.jib.registry.RegistryClient.callRegistryEndpoint(RegistryClient.java:338)
        at com.google.cloud.tools.jib.registry.RegistryClient.pushBlob(RegistryClient.java:303)
        at com.google.cloud.tools.jib.builder.steps.PushBlobStep.call(PushBlobStep.java:87)

It's when contacting putLocation.

        // POST /v2/<name>/blobs/uploads/?mount={blob.digest}
        URL patchLocation = callRegistryEndpoint(blobPusher.initializer());
        if (patchLocation == null) {
          return true;  // The BLOB exists already.
        }

        // PATCH <Location> with BLOB
        URL putLocation = callRegistryEndpoint(blobPusher.writer(patchLocation));
        Preconditions.checkNotNull(putLocation);

        // PUT <Location>?digest={blob.digest}
        callRegistryEndpoint(blobPusher.committer(putLocation));  // <--- here is 304

        return false;

Note that there are three registry API calls (callRegistryEndoing) in sequence:

  1. Sending POST, which returns the patchLocation endpoint
  2. Sending PATCH at patchLocation, which returns putLocation
  3. Sending PUT at putLocation, which is the failing invocation

Given that

  • the previous two callRegistryEndpoint() succeeded;
  • it is unlikely that putLocation is on a different domain, especially given that PUT is to complete a Blob upload;
  • the operation in the user's environment was taking several minutes;
  • the same credential (an Authorization instance, see PushBlobStep.call()) set before initiating the first API call is used for all the three API calls;
  • putLocation responded with 401 Unauthorized; and
  • the user said

    when I specify a larger image as base image the build fails.
    Sometimes build passes but very rarely,

I'm leaning toward the possibility that the credential Authorization is expiring.

@chanseokoh
Copy link
Member

BTW, to reproduce this continuously, you'll need to keep modifying your test project to create fresh new blob digests, since it looks like blobs pushed to Docker Hub are retained at least for some time even if you delete the image on Docker Hub.

@chanseokoh
Copy link
Member

@ghostbuster91 one possible workaround is to do ./gradlew jibDockerBuild (./mvnw jib:dockerBuild for Maven) to save the image to the local Docker daemon (need to install docker locally, of course), and then do docker push <image> to have Docker push it to slow registries.

@briandealwis
Copy link
Member

Enabling tracing, I see the docker OAuth response provides a 300s timeout on the access-token:

GET https://auth.docker.io/token?service=registry.docker.io&scope=repository:library/openjdk:pull
[…]
HTTP/1.1 200 OK
[…]
{"token":"…","expires_in":300,"issued_at":"2018-07-27T15:59:03.973148921Z"}

So we fetch the authorization once and then use it for all subsequent operations. We should instead pull the auth and check for each operation.

@coollog
Copy link
Contributor

coollog commented Jul 27, 2018

@chanseokoh @briandealwis Nice finds! Yea, we should re-authenticate a token if a request fails with unauthorized.

@coollog coollog added this to the v0.9.9 milestone Jul 27, 2018
@coollog coollog modified the milestones: v0.9.9, v0.10.0 Aug 8, 2018
@coollog coollog modified the milestones: v0.10.0, 0.10.1 Oct 2, 2018
@coollog
Copy link
Contributor

coollog commented Oct 31, 2018

Hi @ghostbuster91 , just checking back in to see if this is still a problem you are experiencing? Does anyone else experience this issue?

@coollog

This comment has been minimized.

@danimeko
Copy link

im now facing the same kind of problem.is there any way to get rid off it

@chanseokoh
Copy link
Member

Hi @danimeko,

If you are facing the same problem where it takes a very long time to push a large base image and your credentials expire during the long push, do #691 (comment) once and leave at least one image in your target repository. That should make Jib skip pushing the base image layers because they already exist in your repository.

@briandealwis
Copy link
Member

Another point: Jib 1.4.0 now supports cross-repository mounts which will speed up pushing images to the same registry (e.g., from Docker Hub and to Docker Hub).

@danimeko
Copy link

danimeko commented Aug 1, 2019

thank you for responses. ./gradlew jibDockerBuild need docker daemon running which is not allowed in our system. That is why we use ./gradlew jib

@chanseokoh
Copy link
Member

Then you can just push the base image (no Jib involved) to the target repository by any means, like running skopeo on your laptop which doesn't need Docker.

@briandealwis briandealwis changed the title Jib fails when large base image is specified Jib should check and refresh access tokens as required Sep 23, 2019
@chanseokoh
Copy link
Member

FYI @iocanel

@chanseokoh
Copy link
Member

@ghostbuster91 @danimeko @nithinkota @iocanel we've released 2.0.0 with the fix. Jib will now automatically refresh expired bearer auth tokens. This fixes build failures with "401 Unauthorized", for example, when pushing to Docker Hub takes more than 5 minutes due to slow network.

@ghostbuster91
Copy link
Author

Awesome, thank you very much for this great work!

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

Successfully merging a pull request may close this issue.

6 participants