From 8922ac5243fcaa8b5ad276964e0ec55bb251078a Mon Sep 17 00:00:00 2001 From: Yogesh Gaikwad <902768+bizybot@users.noreply.github.com> Date: Fri, 15 Feb 2019 16:47:42 +1100 Subject: [PATCH] Fix intermittent failure in ApiKeyIntegTests (#38627) Few tests failed intermittently and most of the times due to invalidated or expired keys that were deleted were still reported in search results. This commit removes the test and adds enhancements to other tests testing different scenario's. When ExpiredApiKeysRemover is triggered, the tests did not await its termination thereby sometimes the results would be wrong for a search operation. DELETE_INTERVAL setting has been further reduced to 100ms so we can trigger ExpiredApiKeysRemover faster. Closes #38408 --- .../xpack/security/authc/ApiKeyService.java | 7 +- .../security/authc/ExpiredApiKeysRemover.java | 8 +- .../security/authc/ApiKeyIntegTests.java | 231 +++++++++++------- 3 files changed, 146 insertions(+), 100 deletions(-) diff --git a/x-pack/plugin/security/src/main/java/org/elasticsearch/xpack/security/authc/ApiKeyService.java b/x-pack/plugin/security/src/main/java/org/elasticsearch/xpack/security/authc/ApiKeyService.java index 6323a79fdc43a..9488e92b285d4 100644 --- a/x-pack/plugin/security/src/main/java/org/elasticsearch/xpack/security/authc/ApiKeyService.java +++ b/x-pack/plugin/security/src/main/java/org/elasticsearch/xpack/security/authc/ApiKeyService.java @@ -700,7 +700,6 @@ private void findApiKeys(final BoolQueryBuilder boolQuery, boolean filterOutInva expiredQuery.should(QueryBuilders.boolQuery().mustNot(QueryBuilders.existsQuery("expiration_time"))); boolQuery.filter(expiredQuery); } - final SearchRequest request = client.prepareSearch(SecurityIndexManager.SECURITY_INDEX_NAME) .setScroll(DEFAULT_KEEPALIVE_SETTING.get(settings)) .setQuery(boolQuery) @@ -860,10 +859,16 @@ private E traceLog(String action, E exception) { return exception; } + // pkg scoped for testing boolean isExpirationInProgress() { return expiredApiKeysRemover.isExpirationInProgress(); } + // pkg scoped for testing + long lastTimeWhenApiKeysRemoverWasTriggered() { + return lastExpirationRunMs; + } + private void maybeStartApiKeyRemover() { if (securityIndex.isAvailable()) { if (client.threadPool().relativeTimeInMillis() - lastExpirationRunMs > deleteInterval.getMillis()) { diff --git a/x-pack/plugin/security/src/main/java/org/elasticsearch/xpack/security/authc/ExpiredApiKeysRemover.java b/x-pack/plugin/security/src/main/java/org/elasticsearch/xpack/security/authc/ExpiredApiKeysRemover.java index b9430681d7f43..2cb9969337f0a 100644 --- a/x-pack/plugin/security/src/main/java/org/elasticsearch/xpack/security/authc/ExpiredApiKeysRemover.java +++ b/x-pack/plugin/security/src/main/java/org/elasticsearch/xpack/security/authc/ExpiredApiKeysRemover.java @@ -12,7 +12,6 @@ import org.elasticsearch.action.ActionListener; import org.elasticsearch.action.bulk.BulkItemResponse; import org.elasticsearch.client.Client; -import org.elasticsearch.common.Strings; import org.elasticsearch.common.settings.Settings; import org.elasticsearch.common.unit.TimeValue; import org.elasticsearch.common.util.concurrent.AbstractRunnable; @@ -25,8 +24,8 @@ import org.elasticsearch.threadpool.ThreadPool.Names; import org.elasticsearch.xpack.security.support.SecurityIndexManager; +import java.time.Duration; import java.time.Instant; -import java.time.temporal.ChronoUnit; import java.util.concurrent.atomic.AtomicBoolean; import static org.elasticsearch.action.support.TransportActions.isShardNotAvailableException; @@ -37,6 +36,8 @@ * Responsible for cleaning the invalidated and expired API keys from the security index. */ public final class ExpiredApiKeysRemover extends AbstractRunnable { + public static final Duration EXPIRED_API_KEYS_RETENTION_PERIOD = Duration.ofDays(7L); + private static final Logger logger = LogManager.getLogger(ExpiredApiKeysRemover.class); private final Client client; @@ -60,11 +61,10 @@ public void doRun() { .setQuery(QueryBuilders.boolQuery() .filter(QueryBuilders.termsQuery("doc_type", "api_key")) .should(QueryBuilders.termsQuery("api_key_invalidated", true)) - .should(QueryBuilders.rangeQuery("expiration_time").lte(now.minus(7L, ChronoUnit.DAYS).toEpochMilli())) + .should(QueryBuilders.rangeQuery("expiration_time").lte(now.minus(EXPIRED_API_KEYS_RETENTION_PERIOD).toEpochMilli())) .minimumShouldMatch(1) ); - logger.trace(() -> new ParameterizedMessage("Removing old api keys: [{}]", Strings.toString(expiredDbq))); executeAsyncWithOrigin(client, SECURITY_ORIGIN, DeleteByQueryAction.INSTANCE, expiredDbq, ActionListener.wrap(r -> { debugDbqResponse(r); diff --git a/x-pack/plugin/security/src/test/java/org/elasticsearch/xpack/security/authc/ApiKeyIntegTests.java b/x-pack/plugin/security/src/test/java/org/elasticsearch/xpack/security/authc/ApiKeyIntegTests.java index 80afadd805dad..c661bb6c2b47c 100644 --- a/x-pack/plugin/security/src/test/java/org/elasticsearch/xpack/security/authc/ApiKeyIntegTests.java +++ b/x-pack/plugin/security/src/test/java/org/elasticsearch/xpack/security/authc/ApiKeyIntegTests.java @@ -6,22 +6,26 @@ package org.elasticsearch.xpack.security.authc; +import com.google.common.collect.Sets; + import org.elasticsearch.ElasticsearchSecurityException; +import org.elasticsearch.action.DocWriteResponse; import org.elasticsearch.action.admin.cluster.health.ClusterHealthResponse; -import org.elasticsearch.action.search.SearchResponse; +import org.elasticsearch.action.admin.indices.refresh.RefreshResponse; import org.elasticsearch.action.support.PlainActionFuture; import org.elasticsearch.action.support.WriteRequest; +import org.elasticsearch.action.update.UpdateResponse; import org.elasticsearch.client.Client; import org.elasticsearch.common.Strings; import org.elasticsearch.common.settings.Settings; import org.elasticsearch.common.unit.TimeValue; -import org.elasticsearch.index.query.QueryBuilders; import org.elasticsearch.rest.RestStatus; -import org.elasticsearch.search.builder.SearchSourceBuilder; import org.elasticsearch.test.SecurityIntegTestCase; import org.elasticsearch.test.SecuritySettingsSource; import org.elasticsearch.test.SecuritySettingsSourceField; +import org.elasticsearch.threadpool.ThreadPool; import org.elasticsearch.xpack.core.XPackSettings; +import org.elasticsearch.xpack.core.security.action.ApiKey; import org.elasticsearch.xpack.core.security.action.CreateApiKeyResponse; import org.elasticsearch.xpack.core.security.action.GetApiKeyRequest; import org.elasticsearch.xpack.core.security.action.GetApiKeyResponse; @@ -46,24 +50,26 @@ import java.util.Set; import java.util.concurrent.ExecutionException; import java.util.concurrent.TimeUnit; -import java.util.concurrent.atomic.AtomicBoolean; -import java.util.concurrent.atomic.AtomicReference; import java.util.stream.Collectors; import static org.hamcrest.Matchers.containsInAnyOrder; import static org.hamcrest.Matchers.containsString; import static org.hamcrest.Matchers.equalTo; +import static org.hamcrest.Matchers.greaterThan; import static org.hamcrest.Matchers.is; +import static org.hamcrest.Matchers.isIn; import static org.hamcrest.Matchers.not; +import static org.hamcrest.Matchers.nullValue; public class ApiKeyIntegTests extends SecurityIntegTestCase { + private static final long DELETE_INTERVAL_MILLIS = 100L; @Override public Settings nodeSettings(int nodeOrdinal) { return Settings.builder() .put(super.nodeSettings(nodeOrdinal)) .put(XPackSettings.API_KEY_SERVICE_ENABLED_SETTING.getKey(), true) - .put(ApiKeyService.DELETE_INTERVAL.getKey(), TimeValue.timeValueMillis(200L)) + .put(ApiKeyService.DELETE_INTERVAL.getKey(), TimeValue.timeValueMillis(DELETE_INTERVAL_MILLIS)) .put(ApiKeyService.DELETE_TIMEOUT.getKey(), TimeValue.timeValueSeconds(5L)) .build(); } @@ -76,11 +82,15 @@ public void waitForSecurityIndexWritable() throws Exception { @After public void wipeSecurityIndex() throws InterruptedException { // get the api key service and wait until api key expiration is not in progress! + awaitApiKeysRemoverCompletion(); + deleteSecurityIndex(); + } + + private void awaitApiKeysRemoverCompletion() throws InterruptedException { for (ApiKeyService apiKeyService : internalCluster().getInstances(ApiKeyService.class)) { final boolean done = awaitBusy(() -> apiKeyService.isExpirationInProgress() == false); assertTrue(done); } - deleteSecurityIndex(); } public void testCreateApiKey() { @@ -232,47 +242,6 @@ public void testInvalidateApiKeysForApiKeyName() throws InterruptedException, Ex verifyInvalidateResponse(1, responses, invalidateResponse); } - public void testGetAndInvalidateApiKeysWithExpiredAndInvalidatedApiKey() throws Exception { - List responses = createApiKeys(1, null); - Instant created = Instant.now(); - - Client client = client().filterWithHeader(Collections.singletonMap("Authorization", UsernamePasswordToken - .basicAuthHeaderValue(SecuritySettingsSource.TEST_SUPERUSER, SecuritySettingsSourceField.TEST_PASSWORD_SECURE_STRING))); - SecurityClient securityClient = new SecurityClient(client); - - AtomicReference docId = new AtomicReference<>(); - assertBusy(() -> { - SearchResponse searchResponse = client.prepareSearch(SecurityIndexManager.SECURITY_INDEX_NAME) - .setSource(SearchSourceBuilder.searchSource().query(QueryBuilders.termQuery("doc_type", "api_key"))).setSize(10) - .setTerminateAfter(10).get(); - assertThat(searchResponse.getHits().getTotalHits(), equalTo(1L)); - docId.set(searchResponse.getHits().getAt(0).getId()); - }); - - // hack doc to modify the expiration time to the week before - Instant weekBefore = created.minus(8L, ChronoUnit.DAYS); - assertTrue(Instant.now().isAfter(weekBefore)); - client.prepareUpdate(SecurityIndexManager.SECURITY_INDEX_NAME, "doc", docId.get()) - .setDoc("expiration_time", weekBefore.toEpochMilli()).setRefreshPolicy(WriteRequest.RefreshPolicy.IMMEDIATE).get(); - - PlainActionFuture listener = new PlainActionFuture<>(); - securityClient.invalidateApiKey(InvalidateApiKeyRequest.usingApiKeyId(responses.get(0).getId()), listener); - InvalidateApiKeyResponse invalidateResponse = listener.get(); - verifyInvalidateResponse(1, responses, invalidateResponse); - - // try again - listener = new PlainActionFuture<>(); - securityClient.invalidateApiKey(InvalidateApiKeyRequest.usingApiKeyId(responses.get(0).getId()), listener); - invalidateResponse = listener.get(); - assertTrue(invalidateResponse.getInvalidatedApiKeys().isEmpty()); - - // Get API key though returns the API key information - PlainActionFuture listener1 = new PlainActionFuture<>(); - securityClient.getApiKey(GetApiKeyRequest.usingApiKeyId(responses.get(0).getId()), listener1); - GetApiKeyResponse response = listener1.get(); - verifyGetResponse(1, responses, response, Collections.emptySet(), Collections.singletonList(responses.get(0).getId())); - } - private void verifyInvalidateResponse(int noOfApiKeys, List responses, InvalidateApiKeyResponse invalidateResponse) { assertThat(invalidateResponse.getInvalidatedApiKeys().size(), equalTo(noOfApiKeys)); @@ -283,74 +252,146 @@ private void verifyInvalidateResponse(int noOfApiKeys, List responses = createApiKeys(2, null); + Client client = waitForExpiredApiKeysRemoverTriggerReadyAndGetClient().filterWithHeader( + Collections.singletonMap("Authorization", UsernamePasswordToken.basicAuthHeaderValue(SecuritySettingsSource.TEST_SUPERUSER, + SecuritySettingsSourceField.TEST_PASSWORD_SECURE_STRING))); + + List createdApiKeys = createApiKeys(2, null); - Client client = client().filterWithHeader(Collections.singletonMap("Authorization", UsernamePasswordToken - .basicAuthHeaderValue(SecuritySettingsSource.TEST_SUPERUSER, SecuritySettingsSourceField.TEST_PASSWORD_SECURE_STRING))); SecurityClient securityClient = new SecurityClient(client); + PlainActionFuture listener = new PlainActionFuture<>(); - securityClient.invalidateApiKey(InvalidateApiKeyRequest.usingApiKeyId(responses.get(0).getId()), listener); + securityClient.invalidateApiKey(InvalidateApiKeyRequest.usingApiKeyId(createdApiKeys.get(0).getId()), listener); InvalidateApiKeyResponse invalidateResponse = listener.get(); assertThat(invalidateResponse.getInvalidatedApiKeys().size(), equalTo(1)); assertThat(invalidateResponse.getPreviouslyInvalidatedApiKeys().size(), equalTo(0)); assertThat(invalidateResponse.getErrors().size(), equalTo(0)); - AtomicReference docId = new AtomicReference<>(); - assertBusy(() -> { - SearchResponse searchResponse = client.prepareSearch(SecurityIndexManager.SECURITY_INDEX_NAME) - .setSource(SearchSourceBuilder.searchSource().query(QueryBuilders.termQuery("doc_type", "api_key"))).setSize(10) - .setTerminateAfter(10).get(); - assertThat(searchResponse.getHits().getTotalHits(), equalTo(2L)); - docId.set(searchResponse.getHits().getAt(0).getId()); - }); - AtomicBoolean deleteTriggered = new AtomicBoolean(false); - assertBusy(() -> { - if (deleteTriggered.compareAndSet(false, true)) { - securityClient.invalidateApiKey(InvalidateApiKeyRequest.usingApiKeyId(responses.get(1).getId()), new PlainActionFuture<>()); + PlainActionFuture getApiKeyResponseListener = new PlainActionFuture<>(); + securityClient.getApiKey(GetApiKeyRequest.usingRealmName("file"), getApiKeyResponseListener); + assertThat(getApiKeyResponseListener.get().getApiKeyInfos().length, is(2)); + + client = waitForExpiredApiKeysRemoverTriggerReadyAndGetClient().filterWithHeader( + Collections.singletonMap("Authorization", UsernamePasswordToken.basicAuthHeaderValue(SecuritySettingsSource.TEST_SUPERUSER, + SecuritySettingsSourceField.TEST_PASSWORD_SECURE_STRING))); + securityClient = new SecurityClient(client); + + // invalidate API key to trigger remover + listener = new PlainActionFuture<>(); + securityClient.invalidateApiKey(InvalidateApiKeyRequest.usingApiKeyId(createdApiKeys.get(1).getId()), listener); + assertThat(listener.get().getInvalidatedApiKeys().size(), is(1)); + + awaitApiKeysRemoverCompletion(); + + refreshSecurityIndex(); + + // Verify that 1st invalidated API key is deleted whereas the next one is not + getApiKeyResponseListener = new PlainActionFuture<>(); + securityClient.getApiKey(GetApiKeyRequest.usingRealmName("file"), getApiKeyResponseListener); + assertThat(getApiKeyResponseListener.get().getApiKeyInfos().length, is(1)); + ApiKey apiKey = getApiKeyResponseListener.get().getApiKeyInfos()[0]; + assertThat(apiKey.getId(), is(createdApiKeys.get(1).getId())); + assertThat(apiKey.isInvalidated(), is(true)); + } + + private Client waitForExpiredApiKeysRemoverTriggerReadyAndGetClient() throws Exception { + String nodeWithMostRecentRun = null; + long apiKeyLastTrigger = -1L; + for (String nodeName : internalCluster().getNodeNames()) { + ApiKeyService apiKeyService = internalCluster().getInstance(ApiKeyService.class, nodeName); + if (apiKeyService != null) { + if (apiKeyService.lastTimeWhenApiKeysRemoverWasTriggered() > apiKeyLastTrigger) { + nodeWithMostRecentRun = nodeName; + apiKeyLastTrigger = apiKeyService.lastTimeWhenApiKeysRemoverWasTriggered(); + } } - client.admin().indices().prepareRefresh(SecurityIndexManager.SECURITY_INDEX_NAME).get(); - SearchResponse searchResponse = client.prepareSearch(SecurityIndexManager.SECURITY_INDEX_NAME) - .setSource(SearchSourceBuilder.searchSource().query(QueryBuilders.termQuery("doc_type", "api_key"))) - .setTerminateAfter(10).get(); - assertThat(searchResponse.getHits().getTotalHits(), equalTo(1L)); - }, 30, TimeUnit.SECONDS); + } + final ThreadPool threadPool = internalCluster().getInstance(ThreadPool.class, nodeWithMostRecentRun); + final long lastRunTime = apiKeyLastTrigger; + assertBusy(() -> { + assertThat(threadPool.relativeTimeInMillis() - lastRunTime, greaterThan(DELETE_INTERVAL_MILLIS)); + }); + return internalCluster().client(nodeWithMostRecentRun); } - @AwaitsFix(bugUrl = "https://github.com/elastic/elasticsearch/issues/38408") - public void testExpiredApiKeysDeletedAfter1Week() throws Exception { - List responses = createApiKeys(2, null); + public void testExpiredApiKeysBehaviorWhenKeysExpired1WeekBeforeAnd1DayBefore() throws Exception { + Client client = waitForExpiredApiKeysRemoverTriggerReadyAndGetClient().filterWithHeader( + Collections.singletonMap("Authorization", UsernamePasswordToken.basicAuthHeaderValue(SecuritySettingsSource.TEST_SUPERUSER, + SecuritySettingsSourceField.TEST_PASSWORD_SECURE_STRING))); + + int noOfKeys = 4; + List createdApiKeys = createApiKeys(noOfKeys, null); Instant created = Instant.now(); - Client client = client().filterWithHeader(Collections.singletonMap("Authorization", UsernamePasswordToken - .basicAuthHeaderValue(SecuritySettingsSource.TEST_SUPERUSER, SecuritySettingsSourceField.TEST_PASSWORD_SECURE_STRING))); SecurityClient securityClient = new SecurityClient(client); - AtomicReference docId = new AtomicReference<>(); - assertBusy(() -> { - SearchResponse searchResponse = client.prepareSearch(SecurityIndexManager.SECURITY_INDEX_NAME) - .setSource(SearchSourceBuilder.searchSource().query(QueryBuilders.termQuery("doc_type", "api_key"))).setSize(10) - .setTerminateAfter(10).get(); - assertThat(searchResponse.getHits().getTotalHits(), equalTo(2L)); - docId.set(searchResponse.getHits().getAt(0).getId()); - }); - + PlainActionFuture getApiKeyResponseListener = new PlainActionFuture<>(); + securityClient.getApiKey(GetApiKeyRequest.usingRealmName("file"), getApiKeyResponseListener); + assertThat(getApiKeyResponseListener.get().getApiKeyInfos().length, is(noOfKeys)); + + // Expire the 1st key such that it cannot be deleted by the remover + // hack doc to modify the expiration time to a day before + Instant dayBefore = created.minus(1L, ChronoUnit.DAYS); + assertTrue(Instant.now().isAfter(dayBefore)); + UpdateResponse expirationDateUpdatedResponse = client + .prepareUpdate(SecurityIndexManager.SECURITY_INDEX_NAME, "doc", createdApiKeys.get(0).getId()) + .setDoc("expiration_time", dayBefore.toEpochMilli()).setRefreshPolicy(WriteRequest.RefreshPolicy.IMMEDIATE).get(); + assertThat(expirationDateUpdatedResponse.getResult(), is(DocWriteResponse.Result.UPDATED)); + + // Expire the 2nd key such that it cannot be deleted by the remover // hack doc to modify the expiration time to the week before Instant weekBefore = created.minus(8L, ChronoUnit.DAYS); assertTrue(Instant.now().isAfter(weekBefore)); - client.prepareUpdate(SecurityIndexManager.SECURITY_INDEX_NAME, "doc", docId.get()) + expirationDateUpdatedResponse = client + .prepareUpdate(SecurityIndexManager.SECURITY_INDEX_NAME, "doc", createdApiKeys.get(1).getId()) .setDoc("expiration_time", weekBefore.toEpochMilli()).setRefreshPolicy(WriteRequest.RefreshPolicy.IMMEDIATE).get(); + assertThat(expirationDateUpdatedResponse.getResult(), is(DocWriteResponse.Result.UPDATED)); - AtomicBoolean deleteTriggered = new AtomicBoolean(false); - assertBusy(() -> { - if (deleteTriggered.compareAndSet(false, true)) { - securityClient.invalidateApiKey(InvalidateApiKeyRequest.usingApiKeyId(responses.get(1).getId()), new PlainActionFuture<>()); + // Invalidate to trigger the remover + PlainActionFuture listener = new PlainActionFuture<>(); + securityClient.invalidateApiKey(InvalidateApiKeyRequest.usingApiKeyId(createdApiKeys.get(2).getId()), listener); + assertThat(listener.get().getInvalidatedApiKeys().size(), is(1)); + + awaitApiKeysRemoverCompletion(); + + refreshSecurityIndex(); + + // Verify get API keys does not return expired and deleted key + getApiKeyResponseListener = new PlainActionFuture<>(); + securityClient.getApiKey(GetApiKeyRequest.usingRealmName("file"), getApiKeyResponseListener); + assertThat(getApiKeyResponseListener.get().getApiKeyInfos().length, is(3)); + + Set expectedKeyIds = Sets.newHashSet(createdApiKeys.get(0).getId(), createdApiKeys.get(2).getId(), + createdApiKeys.get(3).getId()); + for (ApiKey apiKey : getApiKeyResponseListener.get().getApiKeyInfos()) { + assertThat(apiKey.getId(), isIn(expectedKeyIds)); + if (apiKey.getId().equals(createdApiKeys.get(0).getId())) { + // has been expired, not invalidated + assertTrue(apiKey.getExpiration().isBefore(Instant.now())); + assertThat(apiKey.isInvalidated(), is(false)); + } else if (apiKey.getId().equals(createdApiKeys.get(2).getId())) { + // has not been expired as no expiration, but invalidated + assertThat(apiKey.getExpiration(), is(nullValue())); + assertThat(apiKey.isInvalidated(), is(true)); + } else if (apiKey.getId().equals(createdApiKeys.get(3).getId())) { + // has not been expired as no expiration, not invalidated + assertThat(apiKey.getExpiration(), is(nullValue())); + assertThat(apiKey.isInvalidated(), is(false)); + } else { + fail("unexpected API key " + apiKey); } - client.admin().indices().prepareRefresh(SecurityIndexManager.SECURITY_INDEX_NAME).get(); - SearchResponse searchResponse = client.prepareSearch(SecurityIndexManager.SECURITY_INDEX_NAME) - .setSource(SearchSourceBuilder.searchSource().query(QueryBuilders.termQuery("doc_type", "api_key"))) - .setTerminateAfter(10).get(); - assertThat(searchResponse.getHits().getTotalHits(), equalTo(1L)); - }, 30, TimeUnit.SECONDS); + } + } + + private void refreshSecurityIndex() throws Exception { + assertBusy(() -> { + final RefreshResponse refreshResponse = client() + .filterWithHeader(Collections.singletonMap("Authorization", + UsernamePasswordToken.basicAuthHeaderValue(SecuritySettingsSource.TEST_SUPERUSER, + SecuritySettingsSourceField.TEST_PASSWORD_SECURE_STRING))) + .admin().indices().prepareRefresh(SecurityIndexManager.SECURITY_INDEX_NAME).get(); + assertThat(refreshResponse.getFailedShards(), is(0)); + }); } public void testActiveApiKeysWithNoExpirationNeverGetDeletedByRemover() throws Exception {