JCLOUDS-589: Reauthenticate on Keystone HTTP 401

This commit ports the Keystone 2.0 fix from JCLOUDS-178 to Keystone
1.1.

apis/cloudservers/src/test/java/org/jclouds/cloudservers/handlers/RetryOnRenewExpectTest.java

@@ -65,10 +65,10 @@ public class RetryOnRenewExpectTest extends BaseCloudServersRestClientExpectTest
       assert clientWhenImageExists.deleteImage(11);
    }
 
-   @Test(expectedExceptions = AuthorizationException.class)
-   public void testDoesNotReauthenticateOnFatal401() {
+   public void testReauthenticateOn401ForFailedCommand() {
+      String requestUrl = "https://lon.servers.api.rackspacecloud.com/v1.0/10001786/images/11?now=1257695648897";
       HttpRequest deleteImage = HttpRequest.builder().method("DELETE")
-            .endpoint("https://lon.servers.api.rackspacecloud.com/v1.0/10001786/images/11?now=1257695648897")
+            .endpoint(requestUrl)
             .addHeader("X-Auth-Token", authToken).build();
 
       HttpResponse unauthResponse = HttpResponse
@@ -78,8 +78,31 @@ public class RetryOnRenewExpectTest extends BaseCloudServersRestClientExpectTest
             .payload("[{\"unauthorized\":{\"message\":\"Fatal unauthorized.\",\"code\":401}}]")
             .build();
 
-      CloudServersClient client = orderedRequestsSendResponses(initialAuth, responseWithAuth, deleteImage,
-            unauthResponse);
+      // second auth uses same creds as initial one
+      HttpRequest redoAuth = initialAuth;
+
+      String authToken2 = "12345678-9012-47c0-9770-2c5097da25fc";
+      HttpResponse responseWithUrls2 = responseWithAuth.toBuilder()
+            .payload(responseWithAuth.getPayload().getRawContent().toString()
+                     .replace(authToken, authToken2)).build();
+
+      HttpRequest deleteImage2 = HttpRequest
+            .builder().method("DELETE")
+            .endpoint(requestUrl).addHeader("X-Auth-Token", authToken2).build();
+
+      HttpResponse imageDeleted = HttpResponse.builder().statusCode(204)
+            .message("HTTP/1.1 204 No Content").build();
+
+      // The sequence of events simulated here is as follows:
+      // 1. First auth succeeds.
+      // 2. The token returned in #1 is used in the deleteImage command.
+      // 3. The deleteImage command fails with a 401 error.
+      // 4. This should result in a new auth request which succeeds.
+      // 5. The new token is used in the next deleteImage command.
+      // 6. Succeed that command.
+      CloudServersClient client = orderedRequestsSendResponses(initialAuth,
+            responseWithAuth, deleteImage, unauthResponse, redoAuth,
+            responseWithUrls2, deleteImage2, imageDeleted);
 
       client.deleteImage(11);
    }

common/openstack/src/main/java/org/jclouds/openstack/handlers/RetryOnRenew.java

@@ -19,8 +19,12 @@ package org.jclouds.openstack.handlers;
 import static org.jclouds.http.HttpUtils.closeClientButKeepContentStream;
 import static org.jclouds.http.HttpUtils.releasePayload;
 
-import javax.annotation.Resource;
+import java.util.concurrent.TimeUnit;
 
+import javax.annotation.Resource;
+import javax.inject.Named;
+
+import org.jclouds.Constants;
 import org.jclouds.domain.Credentials;
 import org.jclouds.http.HttpCommand;
 import org.jclouds.http.HttpResponse;
@@ -29,8 +33,12 @@ import org.jclouds.logging.Logger;
 import org.jclouds.openstack.domain.AuthenticationResponse;
 import org.jclouds.openstack.reference.AuthHeaders;
 
+import com.google.common.annotations.VisibleForTesting;
+import com.google.common.cache.Cache;
+import com.google.common.cache.CacheBuilder;
 import com.google.common.cache.LoadingCache;
 import com.google.common.collect.Multimap;
+import com.google.common.util.concurrent.Uninterruptibles;
 import com.google.inject.Inject;
 import com.google.inject.Singleton;
 
@@ -42,8 +50,23 @@ public class RetryOnRenew implements HttpRetryHandler {
    @Resource
    protected Logger logger = Logger.NULL;
 
+   @VisibleForTesting
+   @Inject(optional = true)
+   @Named(Constants.PROPERTY_MAX_RETRIES)
+   static int NUM_RETRIES = 5;
+
    private final LoadingCache<Credentials, AuthenticationResponse> authenticationResponseCache;
 
+   /*
+    * The reason retries need to be tracked is that it is possible that a token
+    * can be expired at any time. The reason we track by request is that only
+    * some requests might return a 401 (such as temporary URLs). However
+    * consistent failures of the magnitude this code tracks should indicate a
+    * problem.
+    */
+   private static final Cache<HttpCommand, Integer> retryCountMap = CacheBuilder
+         .newBuilder().expireAfterWrite(5, TimeUnit.MINUTES).build();
+
    @Inject
    protected RetryOnRenew(LoadingCache<Credentials, AuthenticationResponse> authenticationResponseCache) {
       this.authenticationResponseCache = authenticationResponseCache;
@@ -61,13 +84,31 @@ public class RetryOnRenew implements HttpRetryHandler {
                         && headers.containsKey(AuthHeaders.AUTH_KEY) && !headers.containsKey(AuthHeaders.AUTH_TOKEN)) {
                   retry = false;
                } else {
-                  byte[] content = closeClientButKeepContentStream(response);
-                  if (content != null && new String(content).contains("lease renew")) {
-                     logger.debug("invalidating authentication token");
+                  closeClientButKeepContentStream(response);
+                  // This is not an authentication request returning 401
+                  // Check if we already had seen this request
+                  Integer count = retryCountMap.getIfPresent(command);
+
+                  if (count == null) {
+                     // First time this non-authentication request failed
+                     logger.debug("invalidating authentication token - first time for %s", command);
+                     retryCountMap.put(command, 1);
                      authenticationResponseCache.invalidateAll();
                      retry = true;
                   } else {
+                     // This request has failed before
+                     if (count + 1 >= NUM_RETRIES) {
+                        logger.debug("too many 401s - giving up after: %s for %s", count, command);
                         retry = false;
+                     } else {
+                        // Retry just in case
+                        logger.debug("invalidating authentication token - retry %s for %s", count, command);
+                        retryCountMap.put(command, count + 1);
+                        // Wait between retries
+                        authenticationResponseCache.invalidateAll();
+                        Uninterruptibles.sleepUninterruptibly(5, TimeUnit.SECONDS);
+                        retry = true;
+                     }
                   }
                }
             break;

common/openstack/src/main/java/org/jclouds/openstack/keystone/v1_1/handlers/RetryOnRenew.java

@@ -19,6 +19,8 @@ package org.jclouds.openstack.keystone.v1_1.handlers;
 import static org.jclouds.http.HttpUtils.closeClientButKeepContentStream;
 import static org.jclouds.http.HttpUtils.releasePayload;
 
+import java.util.concurrent.TimeUnit;
+
 import javax.annotation.Resource;
 import javax.inject.Named;
 
@@ -32,8 +34,12 @@ import org.jclouds.logging.Logger;
 import org.jclouds.openstack.keystone.v1_1.domain.Auth;
 import org.jclouds.openstack.reference.AuthHeaders;
 
+import com.google.common.annotations.VisibleForTesting;
+import com.google.common.cache.Cache;
+import com.google.common.cache.CacheBuilder;
 import com.google.common.cache.LoadingCache;
 import com.google.common.collect.Multimap;
+import com.google.common.util.concurrent.Uninterruptibles;
 import com.google.inject.Inject;
 import com.google.inject.Singleton;
 
@@ -42,9 +48,10 @@ import com.google.inject.Singleton;
  */
 @Singleton
 public class RetryOnRenew implements HttpRetryHandler {
+   @VisibleForTesting
    @Inject(optional = true)
    @Named(Constants.PROPERTY_MAX_RETRIES)
-   private int retryCountLimit = 5;
+   static int NUM_RETRIES = 5;
 
    @Resource
    protected Logger logger = Logger.NULL;
@@ -60,6 +67,16 @@ public class RetryOnRenew implements HttpRetryHandler {
       this.backoffHandler = backoffHandler;
    }
 
+   /*
+    * The reason retries need to be tracked is that it is possible that a token
+    * can be expired at any time. The reason we track by request is that only
+    * some requests might return a 401 (such as temporary URLs). However
+    * consistent failures of the magnitude this code tracks should indicate a
+    * problem.
+    */
+   private static final Cache<HttpCommand, Integer> retryCountMap = CacheBuilder
+         .newBuilder().expireAfterWrite(5, TimeUnit.MINUTES).build();
+
    @Override
    public boolean shouldRetryRequest(HttpCommand command, HttpResponse response) {
       boolean retry = false; // default
@@ -72,13 +89,31 @@ public class RetryOnRenew implements HttpRetryHandler {
                         && headers.containsKey(AuthHeaders.AUTH_KEY) && !headers.containsKey(AuthHeaders.AUTH_TOKEN)) {
                   retry = false;
                } else {
-                  byte[] content = closeClientButKeepContentStream(response);
-                  if (content != null && new String(content).contains("lease renew")) {
-                     logger.debug("invalidating authentication token");
+                  closeClientButKeepContentStream(response);
+                  // This is not an authentication request returning 401
+                  // Check if we already had seen this request
+                  Integer count = retryCountMap.getIfPresent(command);
+
+                  if (count == null) {
+                     // First time this non-authentication request failed
+                     logger.debug("invalidating authentication token - first time for %s", command);
+                     retryCountMap.put(command, 1);
                      authenticationResponseCache.invalidateAll();
                      retry = true;
                   } else {
+                     // This request has failed before
+                     if (count + 1 >= NUM_RETRIES) {
+                        logger.debug("too many 401s - giving up after: %s for %s", count, command);
                         retry = false;
+                     } else {
+                        // Retry just in case
+                        logger.debug("invalidating authentication token - retry %s for %s", count, command);
+                        retryCountMap.put(command, count + 1);
+                        // Wait between retries
+                        authenticationResponseCache.invalidateAll();
+                        Uninterruptibles.sleepUninterruptibly(5, TimeUnit.SECONDS);
+                        retry = true;
+                     }
                   }
                }
                break;

common/openstack/src/test/java/org/jclouds/openstack/handlers/RetryOnRenewTest.java

@@ -21,6 +21,7 @@ import static org.easymock.EasyMock.expect;
 import static org.easymock.EasyMock.expectLastCall;
 import static org.easymock.EasyMock.replay;
 import static org.easymock.EasyMock.verify;
+import static org.testng.Assert.assertFalse;
 import static org.testng.Assert.assertTrue;
 
 import org.jclouds.domain.Credentials;
@@ -51,7 +52,8 @@ public class RetryOnRenewTest {
       cache.invalidateAll();
       expectLastCall();
 
-      expect(response.getPayload()).andReturn(Payloads.newStringPayload("token expired, please renew")).anyTimes();
+      expect(response.getPayload()).andReturn(Payloads.newStringPayload(""))
+            .anyTimes();
       expect(response.getStatusCode()).andReturn(401).atLeastOnce();
 
       replay(command);
@@ -66,4 +68,53 @@ public class RetryOnRenewTest {
       verify(response);
       verify(cache);
    }
+
+   /**
+    * We have three types of authentication failures: a) When the session
+    * (token) expires b) When you hit a URL you don't have access to (because of
+    * permissions) c) When you attempt to authenticate to the service (with bad
+    * credentials)
+    *
+    * In case c), which is detectable, we do not retry, as usually this means
+    * your credentials are broken. Case a) and b) cannot be distinguished easily
+    * at this point. Different providers will request token re-authentication in
+    * different ways (but usually preceded or by an authentication failure). To
+    * attempt to distinguish between case a) and b) this code tracks failures
+    * for specific calls. Multiple failures for the same call almost certainly
+    * indicates a permissions issue. A success results in a successful
+    * re-authentication.
+    */
+   @Test
+   public void test401ShouldRetry4Times() {
+      HttpCommand command = createMock(HttpCommand.class);
+      HttpRequest request = createMock(HttpRequest.class);
+      HttpResponse response = createMock(HttpResponse.class);
+
+      @SuppressWarnings("unchecked")
+      LoadingCache<Credentials, AuthenticationResponse> cache = createMock(LoadingCache.class);
+
+      expect(command.getCurrentRequest()).andReturn(request).anyTimes();
+      expect(request.getHeaders()).andStubReturn(null);
+
+      cache.invalidateAll();
+      expectLastCall().anyTimes();
+
+      expect(response.getPayload()).andReturn(Payloads.newStringPayload(""))
+            .anyTimes();
+      expect(response.getStatusCode()).andReturn(401).anyTimes();
+
+      replay(command, request, response, cache);
+
+      RetryOnRenew retry = new RetryOnRenew(cache);
+
+      for (int n = 0; n < RetryOnRenew.NUM_RETRIES - 1; n++) {
+         assertTrue(retry.shouldRetryRequest(command, response),
+               "Expected retry to succeed");
+      }
+
+      assertFalse(retry.shouldRetryRequest(command, response),
+            "Expected retry to fail on attempt 5");
+
+      verify(command, response, cache);
+   }
 }

common/openstack/src/test/java/org/jclouds/openstack/keystone/v1_1/handlers/RetryOnRenewTest.java

@@ -21,6 +21,7 @@ import static org.easymock.EasyMock.expect;
 import static org.easymock.EasyMock.expectLastCall;
 import static org.easymock.EasyMock.replay;
 import static org.easymock.EasyMock.verify;
+import static org.testng.Assert.assertFalse;
 import static org.testng.Assert.assertTrue;
 
 import org.jclouds.domain.Credentials;
@@ -30,6 +31,7 @@ import org.jclouds.http.HttpResponse;
 import org.jclouds.http.handlers.BackoffLimitedRetryHandler;
 import org.jclouds.io.Payloads;
 import org.jclouds.openstack.keystone.v1_1.domain.Auth;
+import org.jclouds.openstack.keystone.v1_1.handlers.RetryOnRenew;
 import org.testng.annotations.Test;
 
 import com.google.common.cache.LoadingCache;
@@ -71,6 +73,41 @@ public class RetryOnRenewTest {
       verify(backoffHandler);
    }
 
+   @Test
+   public void test401ShouldRetry4Times() {
+      HttpCommand command = createMock(HttpCommand.class);
+      HttpRequest request = createMock(HttpRequest.class);
+      HttpResponse response = createMock(HttpResponse.class);
+
+      @SuppressWarnings("unchecked")
+      LoadingCache<Credentials, Auth> cache = createMock(LoadingCache.class);
+      BackoffLimitedRetryHandler backoffHandler = createMock(BackoffLimitedRetryHandler.class);
+
+      expect(command.getCurrentRequest()).andReturn(request).anyTimes();
+      expect(request.getHeaders()).andStubReturn(null);
+
+      cache.invalidateAll();
+      expectLastCall().anyTimes();
+
+      expect(response.getPayload()).andReturn(Payloads.newStringPayload(""))
+            .anyTimes();
+      expect(response.getStatusCode()).andReturn(401).anyTimes();
+
+      replay(command, request, response, cache);
+
+      RetryOnRenew retry = new RetryOnRenew(cache, backoffHandler);
+
+      for (int i = 0; i < RetryOnRenew.NUM_RETRIES - 1; ++i) {
+         assertTrue(retry.shouldRetryRequest(command, response),
+               "Expected retry to succeed");
+      }
+
+      assertFalse(retry.shouldRetryRequest(command, response),
+            "Expected retry to fail on attempt " + RetryOnRenew.NUM_RETRIES);
+
+      verify(command, response, cache);
+   }
+
    @Test
    public void test408ShouldRetry() {
       HttpCommand command = createMock(HttpCommand.class);