GoogleContainerTools / GoogleContainerTools/jib

Cannot invoke "com.google.auth.oauth2.AccessToken.getTokenValue()" because "accessToken" is null

Open
#4,140 19 comments 5 reactions 0 assignees View on GitHub
priority:p3 type:bug
Dominant language
Java
Stars
14.5k
Forks
1.5k
PR merge metrics
No merged PRs in 30d

Description

**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 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/containerbuilder@xxx.iam.gserviceaccount.com"
]
},
"methodName": "GenerateAccessToken",
"request": {
"@type": "type.googleapis.com/google.iam.credentials.v1.GenerateAccessTokenRequest",
"name": "projects/-/serviceAccounts/containerbuilder@xxxx.iam.gserviceaccount.com"
},
"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": "containerbuilder@xxx.iam.gserviceaccount.com",
"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]"
},

```

Contributor guide

Open the contributing guide

Assessment

This issue has not been assessed yet.

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.