From c417ddef6760fcad27baba34e6e1dbe92d5708b9 Mon Sep 17 00:00:00 2001 From: Shri Javadekar Date: Mon, 9 Jun 2014 15:10:49 -0700 Subject: [PATCH] JCLOUDS-589: Reauthenticate on Keystone HTTP 401 This commit ports the Keystone 2.0 fix from JCLOUDS-178 to Keystone 1.1. --- .../handlers/RetryOnRenewExpectTest.java | 33 ++++++++++-- .../openstack/handlers/RetryOnRenew.java | 53 ++++++++++++++++--- .../keystone/v1_1/handlers/RetryOnRenew.java | 45 ++++++++++++++-- .../openstack/handlers/RetryOnRenewTest.java | 53 ++++++++++++++++++- .../v1_1/handlers/RetryOnRenewTest.java | 37 +++++++++++++ 5 files changed, 204 insertions(+), 17 deletions(-) diff --git a/apis/cloudservers/src/test/java/org/jclouds/cloudservers/handlers/RetryOnRenewExpectTest.java b/apis/cloudservers/src/test/java/org/jclouds/cloudservers/handlers/RetryOnRenewExpectTest.java index 7ba3198272..435b2181f7 100644 --- a/apis/cloudservers/src/test/java/org/jclouds/cloudservers/handlers/RetryOnRenewExpectTest.java +++ b/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); } diff --git a/common/openstack/src/main/java/org/jclouds/openstack/handlers/RetryOnRenew.java b/common/openstack/src/main/java/org/jclouds/openstack/handlers/RetryOnRenew.java index 411c367776..1d71d7f038 100644 --- a/common/openstack/src/main/java/org/jclouds/openstack/handlers/RetryOnRenew.java +++ b/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 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 retryCountMap = CacheBuilder + .newBuilder().expireAfterWrite(5, TimeUnit.MINUTES).build(); + @Inject protected RetryOnRenew(LoadingCache authenticationResponseCache) { this.authenticationResponseCache = authenticationResponseCache; @@ -61,16 +84,34 @@ 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 { - retry = false; + // 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; + break; } return retry; diff --git a/common/openstack/src/main/java/org/jclouds/openstack/keystone/v1_1/handlers/RetryOnRenew.java b/common/openstack/src/main/java/org/jclouds/openstack/keystone/v1_1/handlers/RetryOnRenew.java index fae7a9d01e..47eb259701 100644 --- a/common/openstack/src/main/java/org/jclouds/openstack/keystone/v1_1/handlers/RetryOnRenew.java +++ b/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 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 { - retry = false; + // 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; diff --git a/common/openstack/src/test/java/org/jclouds/openstack/handlers/RetryOnRenewTest.java b/common/openstack/src/test/java/org/jclouds/openstack/handlers/RetryOnRenewTest.java index 89e65614c8..be813295d0 100644 --- a/common/openstack/src/test/java/org/jclouds/openstack/handlers/RetryOnRenewTest.java +++ b/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 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); + } } diff --git a/common/openstack/src/test/java/org/jclouds/openstack/keystone/v1_1/handlers/RetryOnRenewTest.java b/common/openstack/src/test/java/org/jclouds/openstack/keystone/v1_1/handlers/RetryOnRenewTest.java index 164d9810e1..c7126dfb9f 100644 --- a/common/openstack/src/test/java/org/jclouds/openstack/keystone/v1_1/handlers/RetryOnRenewTest.java +++ b/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 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);