jib
jib copied to clipboard
GoogleContainerTools
Cannot invoke "com.google.auth.oauth2.AccessToken.getTokenValue()" because "accessToken" is null
Environment:
- Jib version: v3.4.0
- Build tool: Maven 3.9.5
- OS: Linux, Kubernetes, GitLab Runner
Description of the issue: Every once in a while pushing a container fails with:
Failed to execute goal com.google.cloud.tools:jib-maven-plugin:3.4.0:build (default-cli) on project xxxx-app: Cannot invoke "com.google.auth.oauth2.AccessToken.getTokenValue()" because "accessToken" is null -> [Help 1]
This happens with multiple different applications, with no discernible pattern.
Full stack trace, with debug logging:
278403 [INFO] Getting manifest for base image europe-west4-docker.pkg.dev/xxxxx/images/xxx-runtime-jre...
278404 [DEBUG] TIMING Authenticating push to europe-west4-docker.pkg.dev
278406 [DEBUG] TIMING trying mirrors
278406 [DEBUG] TIMED trying mirrors : 0.237 ms
278412 [DEBUG] TIMING Preparing application layer builders
278412 [DEBUG] TIMED Preparing application layer builders : 0.571 ms
278417 [INFO] Building dependencies layer...
278417 [DEBUG] TIMING Building dependencies layer
278432 [INFO] Building resources layer...
278432 [DEBUG] TIMING Building resources layer
278437 [INFO] Building classes layer...
278437 [DEBUG] TIMING Building classes layer
278458 [INFO] Building jvm arg files layer...
278459 [DEBUG] TIMING Building jvm arg files layer
278470 [INFO] Building axle-build-metrics layer...
278471 [DEBUG] TIMING Building axle-build-metrics layer
278556 [DEBUG] Building axle-build-metrics layer built sha256:03de117a76e695557f8751bbfe0be5c5901dc75e0ca22c17921996f77cb0cfc6
278557 [DEBUG] TIMED Building axle-build-metrics layer : 86.564 ms
278562 [DEBUG] Building jvm arg files layer built sha256:f3e46ee7fd2d25740654fb5ac57d12b1eff5b9b485a8a217e4f81295b7f27bdc
278562 [DEBUG] TIMED Building jvm arg files layer : 103.838 ms
278665 [DEBUG] Google ADC found
278794 [INFO] The base image requires auth. Trying again for europe-west4-docker.pkg.dev/xxxx/images/xx-runtime-jre...
278801 [DEBUG] Google ADC found
278847 [INFO] Using Google Application Default Credentials for europe-west4-docker.pkg.dev/xxxx/images/xxx-runtime-jre
278847 [DEBUG] TIMED Pulling base image manifest : 443.66 ms
278847 [INFO] Using Google Application Default Credentials for europe-west4-docker.pkg.dev/xxx/images/xxx-app:3100628-main-9eb25e86
278849 [DEBUG] TIMED Building and pushing image : 634.652 ms
278849 [DEBUG] attempting bearer auth for europe-west4-docker.pkg.dev/xxx/images/xxx-app...
278849 [INFO]
278851 [INFO] ------------------------------------------------------------------------
278851 [INFO] Reactor Summary for xxx 3100628-main-9eb25e86:
278851 [INFO]
278852 [INFO] xxx ............................................. SUCCESS [ 3.964 s]
278852 [INFO] xxx-app ......................................... FAILURE [04:32 min]
278852 [INFO] ------------------------------------------------------------------------
278852 [INFO] BUILD FAILURE
278852 [INFO] ------------------------------------------------------------------------
278852 [INFO] Total time: 04:37 min
278852 [INFO] Finished at: 2023-11-13T11:45:45+01:00
278852 [INFO] ------------------------------------------------------------------------
278853 [ERROR] Failed to execute goal com.google.cloud.tools:jib-maven-plugin:3.4.0:build (default-cli) on project xxx-app: Cannot invoke "com.google.auth.oauth2.AccessToken.getTokenValue()" because "accessToken" is null -> [Help 1]
org.apache.maven.lifecycle.LifecycleExecutionException: Failed to execute goal com.google.cloud.tools:jib-maven-plugin:3.4.0:build (default-cli) on project xxx-app: Cannot invoke "com.google.auth.oauth2.AccessToken.getTokenValue()" because "accessToken" is null
at org.apache.maven.lifecycle.internal.MojoExecutor.doExecute2 (MojoExecutor.java:333)
at org.apache.maven.lifecycle.internal.MojoExecutor.doExecute (MojoExecutor.java:316)
at org.apache.maven.lifecycle.internal.MojoExecutor.execute (MojoExecutor.java:212)
at org.apache.maven.lifecycle.internal.MojoExecutor.execute (MojoExecutor.java:174)
at org.apache.maven.lifecycle.internal.MojoExecutor.access$000 (MojoExecutor.java:75)
at org.apache.maven.lifecycle.internal.MojoExecutor$1.run (MojoExecutor.java:162)
at org.apache.maven.plugin.DefaultMojosExecutionStrategy.execute (DefaultMojosExecutionStrategy.java:39)
at org.apache.maven.lifecycle.internal.MojoExecutor.execute (MojoExecutor.java:159)
at org.apache.maven.lifecycle.internal.LifecycleModuleBuilder.buildProject (LifecycleModuleBuilder.java:105)
at org.apache.maven.lifecycle.internal.LifecycleModuleBuilder.buildProject (LifecycleModuleBuilder.java:73)
at org.apache.maven.lifecycle.internal.builder.singlethreaded.SingleThreadedBuilder.build (SingleThreadedBuilder.java:53)
at org.apache.maven.lifecycle.internal.LifecycleStarter.execute (LifecycleStarter.java:118)
at org.apache.maven.DefaultMaven.doExecute (DefaultMaven.java:261)
at org.apache.maven.DefaultMaven.doExecute (DefaultMaven.java:173)
at org.apache.maven.DefaultMaven.execute (DefaultMaven.java:101)
at org.apache.maven.cli.MavenCli.execute (MavenCli.java:906)
at org.apache.maven.cli.MavenCli.doMain (MavenCli.java:283)
at org.apache.maven.cli.MavenCli.main (MavenCli.java:206)
at jdk.internal.reflect.DirectMethodHandleAccessor.invoke (DirectMethodHandleAccessor.java:103)
at java.lang.reflect.Method.invoke (Method.java:580)
at org.codehaus.plexus.classworlds.launcher.Launcher.launchEnhanced (Launcher.java:283)
at org.codehaus.plexus.classworlds.launcher.Launcher.launch (Launcher.java:226)
at org.codehaus.plexus.classworlds.launcher.Launcher.mainWithExitCode (Launcher.java:407)
at org.codehaus.plexus.classworlds.launcher.Launcher.main (Launcher.java:348)
at jdk.internal.reflect.DirectMethodHandleAccessor.invoke (DirectMethodHandleAccessor.java:103)
at java.lang.reflect.Method.invoke (Method.java:580)
at org.apache.maven.wrapper.BootstrapMainStarter.start (BootstrapMainStarter.java:52)
at org.apache.maven.wrapper.WrapperExecutor.execute (WrapperExecutor.java:161)
at org.apache.maven.wrapper.MavenWrapperMain.main (MavenWrapperMain.java:73)
Caused by: org.apache.maven.plugin.MojoExecutionException: Cannot invoke "com.google.auth.oauth2.AccessToken.getTokenValue()" because "accessToken" is null
at com.google.cloud.tools.jib.maven.BuildImageMojo.execute (BuildImageMojo.java:181)
at org.apache.maven.plugin.DefaultBuildPluginManager.executeMojo (DefaultBuildPluginManager.java:126)
at org.apache.maven.lifecycle.internal.MojoExecutor.doExecute2 (MojoExecutor.java:328)
at org.apache.maven.lifecycle.internal.MojoExecutor.doExecute (MojoExecutor.java:316)
at org.apache.maven.lifecycle.internal.MojoExecutor.execute (MojoExecutor.java:212)
at org.apache.maven.lifecycle.internal.MojoExecutor.execute (MojoExecutor.java:174)
at org.apache.maven.lifecycle.internal.MojoExecutor.access$000 (MojoExecutor.java:75)
at org.apache.maven.lifecycle.internal.MojoExecutor$1.run (MojoExecutor.java:162)
at org.apache.maven.plugin.DefaultMojosExecutionStrategy.execute (DefaultMojosExecutionStrategy.java:39)
at org.apache.maven.lifecycle.internal.MojoExecutor.execute (MojoExecutor.java:159)
at org.apache.maven.lifecycle.internal.LifecycleModuleBuilder.buildProject (LifecycleModuleBuilder.java:105)
at org.apache.maven.lifecycle.internal.LifecycleModuleBuilder.buildProject (LifecycleModuleBuilder.java:73)
at org.apache.maven.lifecycle.internal.builder.singlethreaded.SingleThreadedBuilder.build (SingleThreadedBuilder.java:53)
at org.apache.maven.lifecycle.internal.LifecycleStarter.execute (LifecycleStarter.java:118)
at org.apache.maven.DefaultMaven.doExecute (DefaultMaven.java:261)
at org.apache.maven.DefaultMaven.doExecute (DefaultMaven.java:173)
at org.apache.maven.DefaultMaven.execute (DefaultMaven.java:101)
at org.apache.maven.cli.MavenCli.execute (MavenCli.java:906)
at org.apache.maven.cli.MavenCli.doMain (MavenCli.java:283)
at org.apache.maven.cli.MavenCli.main (MavenCli.java:206)
at jdk.internal.reflect.DirectMethodHandleAccessor.invoke (DirectMethodHandleAccessor.java:103)
at java.lang.reflect.Method.invoke (Method.java:580)
at org.codehaus.plexus.classworlds.launcher.Launcher.launchEnhanced (Launcher.java:283)
at org.codehaus.plexus.classworlds.launcher.Launcher.launch (Launcher.java:226)
at org.codehaus.plexus.classworlds.launcher.Launcher.mainWithExitCode (Launcher.java:407)
at org.codehaus.plexus.classworlds.launcher.Launcher.main (Launcher.java:348)
at jdk.internal.reflect.DirectMethodHandleAccessor.invoke (DirectMethodHandleAccessor.java:103)
at java.lang.reflect.Method.invoke (Method.java:580)
at org.apache.maven.wrapper.BootstrapMainStarter.start (BootstrapMainStarter.java:52)
at org.apache.maven.wrapper.WrapperExecutor.execute (WrapperExecutor.java:161)
at org.apache.maven.wrapper.MavenWrapperMain.main (MavenWrapperMain.java:73)
Caused by: java.lang.NullPointerException: Cannot invoke "com.google.auth.oauth2.AccessToken.getTokenValue()" because "accessToken" is null
at com.google.cloud.tools.jib.frontend.CredentialRetrieverFactory.lambda$googleApplicationDefaultCredentials$3 (CredentialRetrieverFactory.java:284)
at com.google.cloud.tools.jib.builder.steps.RegistryCredentialRetriever.retrieve (RegistryCredentialRetriever.java:49)
at com.google.cloud.tools.jib.builder.steps.RegistryCredentialRetriever.getBaseImageCredential (RegistryCredentialRetriever.java:36)
at com.google.cloud.tools.jib.builder.steps.PullBaseImageStep.call (PullBaseImageStep.java:167)
at com.google.cloud.tools.jib.builder.steps.PullBaseImageStep.call (PullBaseImageStep.java:70)
at com.google.common.util.concurrent.TrustedListenableFutureTask$TrustedFutureInterruptibleTask.runInterruptibly (TrustedListenableFutureTask.java:131)
at com.google.common.util.concurrent.InterruptibleTask.run (InterruptibleTask.java:75)
at com.google.common.util.concurrent.TrustedListenableFutureTask.run (TrustedListenableFutureTask.java:82)
at java.util.concurrent.ThreadPoolExecutor.runWorker (ThreadPoolExecutor.java:1144)
at java.util.concurrent.ThreadPoolExecutor$Worker.run (ThreadPoolExecutor.java:642)
at java.lang.Thread.run (Thread.java:1583)
Retrying usually results in success.
No changes were made to the build setup, or any changes known about the underlying infrastructure (GitLab Runners).
Expected behavior:
Container is published.
Steps to reproduce:
The problem happens every once in awhile.
Additional Information:
Looking at the code:
public CredentialRetriever googleApplicationDefaultCredentials() {
return () -> {
try {
if (imageReference.getRegistry().endsWith("gcr.io")
|| imageReference.getRegistry().endsWith("docker.pkg.dev")) {
GoogleCredentials googleCredentials = googleCredentialsProvider.get();
logger.accept(LogEvent.info("Google ADC found"));
if (googleCredentials.createScopedRequired()) { // not scoped if service account
// The short-lived OAuth2 access token to be generated from the service account with
// refreshIfExpired() below will have one-hour expiry (as of Aug 2019). Instead of using
// an access token, it is technically possible to use the service account private key to
// auth with GCR, but it does not worth writing complex code to achieve that.
logger.accept(LogEvent.info("ADC is a service account. Setting GCS read-write scope"));
List<String> scope = Collections.singletonList(OAUTH_SCOPE_STORAGE_READ_WRITE);
googleCredentials = googleCredentials.createScoped(scope);
}
googleCredentials.refreshIfExpired();
logGotCredentialsFrom("Google Application Default Credentials");
AccessToken accessToken = googleCredentials.getAccessToken();
// https://cloud.google.com/container-registry/docs/advanced-authentication#access_token
return Optional.of(Credential.from("oauth2accesstoken", accessToken.getTokenValue()));
}
} catch (IOException ex) { // Includes the case where ADC is simply not available.
logger.accept(
LogEvent.info("ADC not present or error fetching access token: " + ex.getMessage()));
}
return Optional.empty();
};
}
It seems that for some reason googleCredentials.getAccessToken(); returns null. I don't know why, but at the very least it's probably a good idea to catch the NPE.
We also have some logs of how the request for authentication / the access token, was made:
{
"insertId": "1f2bp76dsb93",
"logName": "projects/xxx/logs/cloudaudit.googleapis.com%2Fdata_access",
"operation": {
"first": true,
"id": "4898467374120538801",
"last": true,
"producer": "iamcredentials.googleapis.com"
},
"protoPayload": {
"@type": "type.googleapis.com/google.cloud.audit.AuditLog",
"authenticationInfo": {
"principalSubject": "serviceAccount:xxx.svc.id.goog[xx/containerbuilder]",
"serviceAccountDelegationInfo": [
{}
]
},
"authorizationInfo": [
{
"granted": true,
"permission": "iam.serviceAccounts.getAccessToken",
"resourceAttributes": {}
}
],
"metadata": {
"identityDelegationChain": [
"projects/-/serviceAccounts/[email protected]"
]
},
"methodName": "GenerateAccessToken",
"request": {
"@type": "type.googleapis.com/google.iam.credentials.v1.GenerateAccessTokenRequest",
"name": "projects/-/serviceAccounts/[email protected]"
},
"requestMetadata": {
"callerIp": "gce-internal-ip",
"callerSuppliedUserAgent": "google-api-go-client/0.5 gke-metadata-server,gzip(gfe)",
"destinationAttributes": {},
"requestAttributes": {
"auth": {},
"time": "2023-11-13T10:45:45.816012913Z"
}
},
"resourceName": "projects/-/serviceAccounts/xxx",
"serviceName": "iamcredentials.googleapis.com",
"status": {}
},
"receiveTimestamp": "2023-11-13T10:45:47.137195471Z",
"resource": {
"labels": {
"email_id": "[email protected]",
"project_id": "xxx",
"unique_id": "xxx"
},
"type": "service_account"
},
"severity": "INFO",
"timestamp": "2023-11-13T10:45:45.806510333Z"
}
And the response, while I don't have the entire payload, we do have some metadata:
"authorizationInfo": [
{
"granted": true,
"resourceAttributes": {},
"permission": "iam.serviceAccounts.getAccessToken"
}
],
"requestMetadata": {
"callerIp": "gce-internal-ip",
"requestAttributes": {
"auth": {},
"time": "2023-11-13T10:45:45.816012913Z"
},
"destinationAttributes": {},
"callerSuppliedUserAgent": "google-api-go-client/0.5 gke-metadata-server,gzip(gfe)"
},
"@type": "type.googleapis.com/google.cloud.audit.AuditLog",
"authenticationInfo": {
"serviceAccountDelegationInfo": [
{}
],
"principalSubject": "serviceAccount:xxxx.svc.id.goog[xxxx/containerbuilder]"
},
Looking at the log snippets I posted, specifically:
"requestMetadata": {
"callerIp": "gce-internal-ip",
"requestAttributes": {
"auth": {},
"time": "2023-11-13T10:45:45.816012913Z"
},
"destinationAttributes": {},
"callerSuppliedUserAgent": "google-api-go-client/0.5 gke-metadata-server,gzip(gfe)"
},
.. in relation to jib-maven-plugin, I assume this is a transitive call triggered by jib authenticating, rather than a direct call, as evident from the callerSuppliedUserAgent. In other words, we have no clear record of the request jib-maven-plugin made.
We're having exactly the same issue running on Github with authorization via google-github-actions/auth@v1 workload identity. It happens every once in a while.
We're having exactly the same issue running on Github with authorization via
google-github-actions/auth@v1workload identity. It happens every once in a while.
+1 but for google-github-actions/auth@v2 and jib-maven-plugin:3.4.2
Thanks so much for the detailed explanation of the behavior! Trying to see if we can reproduce this locally. Do you happen to have a small reproducer or details on how you've configured you POM?
@wleese @Xander-Polishchuk Are you using OIDC as auth mechanism to GCP? We are.
Thanks so much for the detailed explanation of the behavior! Trying to see if we can reproduce this locally. Do you happen to have a small reproducer or details on how you've configured you POM?
@mpeddada1 I created a simple project to replicate the issue, but I have not been able to replicate it. Since it is a flaky error, it's hard to know why. We are still experiencing the error from time to time in our company CI, but have currently solved it with an automatic retry.
Anyone feel free to add to the project if you have ideas of what could increase the chance of replicating the issue.
Thanks for creating the sample @Wallman. I will try this out to see how often this can be replicated. Additionally, at the very least, a better error message instead of throwing a NullPointerException for when accessToken is null may be something we want to do here (as mentioned in the original description).
For the time being, the workaround would be set up retries as you are currently doing.
We are also experiencing this issue. Github actions with jib 3.4.3.
Note that we have a multi module build with two modules that are being containerised and pushed concurrently. We have examples of one of the pushes failing but the other succeeding.
