Change access token validity and remove logging

The access token renewal on GCE is not what we expected. The metadata server always returns the same token as long as it is valid for 1699 to 3599 seconds and rolls over to the next token on its own schedule. Calling refresh on the GoogleCredential has no effect. We were caching the token for 30 min (1800 seconds), so in a rare case where we "refreshed" the token while its expiry is between 1699 and 1800 seconds, we will cache the token for longer than its validity. [] shorted the caching period to 10 min and added logging, which proved to be working. We no longer need the log any more now that the root cause has been identified. Also changed the cache period to 15 min (900 seconds) which should still be good.

-------------
Created by MOE: https://github.com/google/moe
MOE_MIGRATED_REVID=208888170

java/google/registry/proxy/ProxyConfig.java

@@ -38,7 +38,6 @@ public class ProxyConfig {
   public String projectId;
   public List<String> gcpScopes;
   public int accessTokenValidPeriodSeconds;
-  public int accessTokenRefreshBeforeExpirySeconds;
   public int serverCertificateCacheSeconds;
   public Gcs gcs;
   public Kms kms;

java/google/registry/proxy/ProxyModule.java

@@ -29,7 +29,6 @@ import com.google.api.services.cloudkms.v1.model.DecryptRequest;
 import com.google.api.services.storage.Storage;
 import com.google.common.collect.ImmutableMap;
 import com.google.common.collect.Maps;
-import com.google.common.flogger.FluentLogger;
 import com.google.common.flogger.LoggerConfig;
 import com.google.monitoring.metrics.MetricReporter;
 import dagger.Component;
@@ -72,8 +71,6 @@ import javax.inject.Singleton;
 @Module
 public class ProxyModule {
 
-  private static final FluentLogger logger = FluentLogger.forEnclosingClass();
-
   @Parameter(names = "--whois", description = "Port for WHOIS")
   private Integer whoisPort;
 
@@ -133,8 +130,6 @@ public class ProxyModule {
       // Log source IP information if --log parameter is passed. This is considered PII and should
       // only be used in non-production environment for debugging purpose.
       LoggerConfig.getConfig(ProxyProtocolHandler.class).setLevel(Level.FINE);
-      // Log at debug level what is the refreshed access token.
-      LoggerConfig.getConfig(ProxyModule.class).setLevel(Level.FINE);
     }
   }
 
@@ -241,12 +236,9 @@ public class ProxyModule {
           } catch (IOException e) {
             throw new RuntimeException("Cannot refresh access token.", e);
           }
-          // TODO (jianglai): Remove access token refresh logging.
+          return credential.getAccessToken();
-          String token = credential.getAccessToken();
-          logger.atFine().log("Access token refreshed: %s", token);
-          return token;
         },
-        config.accessTokenValidPeriodSeconds - config.accessTokenRefreshBeforeExpirySeconds,
+        config.accessTokenValidPeriodSeconds,
         SECONDS);
   }
 

java/google/registry/proxy/config/default-config.yaml

@@ -20,23 +20,22 @@ gcpScopes:
   # to authenticate.
   - https://www.googleapis.com/auth/userinfo.email
 
-# Access token is valid for 10 minutes.
+# Access token is cached for 15 minutes.
 #
-# Document says that the token should be good for 60 minutes, but in practice
+# Depending on how the credential is obtained, its renewal behavior is
-# we've run into problems with token becoming invalid before supposed expiration
+# different. A credential backed by a private key (like the ADC obtained
-# time. This used to be set to 30 min but we still observe very rare occurrence
+# locally) will get a different token when #refreshToken() is called. On GCE,
-# of INVALID_TOKEN response (not even EXPIRED_TOKEN, which is also a possible
+# the credential is just a wrapper around tokens sent from the metadata server,
-# response). Set it to 10 minutes so that the tokens can be refreshed more
+# which is valid from 3599 seconds to 1699 seconds (this is no documentation on
-# frequently.
+# this, I got this number by logging in a GCE VM, calling curl on the metatdata
-# See also: Data store
+# server every minute, and check the expiration time of the response). Calling
-# (https://developers.google.com/api-client-library/java/google-api-java-client/oauth2#data_store).
+# refreshToken() does *not* get a new token. The token is only refreshed by
-accessTokenValidPeriodSeconds: 600
+# metadata server itself (every 3599 - 1699 = 1900 seconds). We cache the token
-
+# for 900 seconds, which should be good for both cases. The private key
-# Access token is refreshed 1 minutes before expiry.
+# generated token is in theory valid for 1h, and the token obtained from the
-#
+# metadata token is at least valid for 1699 seconds, so we can know for sure
-# This is the default refresh time used by
+# that during the period that it is cached, the token will not expire.
-# com.google.api.client.auth.oauth2.Credential#intercept.
+accessTokenValidPeriodSeconds: 900
-accessTokenRefreshBeforeExpirySeconds: 60
 
 # Server certificate is cached for 30 minutes.
 #

java/google/registry/proxy/handler/RelayHandler.java

@@ -77,7 +77,7 @@ public class RelayHandler<I> extends SimpleChannelInboundHandler<I> {
   public void exceptionCaught(ChannelHandlerContext ctx, Throwable cause) {
     if (cause instanceof OverQuotaException) {
       logger.atWarning().withCause(cause).log(
-          "Channel %s closed due to quota exceeded", ctx.channel());
+          "Channel %s closed due to quota exceeded.", ctx.channel());
       ChannelFuture unusedFuture = ctx.close();
     } else {
       ctx.fireExceptionCaught(cause);