From 3679d43c7d2f20225912fea55ba45d18cc536ce0 Mon Sep 17 00:00:00 2001 From: MaciejMierzwa Date: Thu, 14 Dec 2023 18:34:36 +0100 Subject: [PATCH] Search operation test flakiness fix (#3602) Search operation test flakiness fix - https://github.com/opensearch-project/security/issues/3426 - https://github.com/opensearch-project/security/issues/2141 - https://github.com/opensearch-project/security/issues/2169 Similar to this task: https://github.com/opensearch-project/security/issues/1917 From what I've noticed some logs are duplicated on faster machines. During test creation audit logging results were added based on actual results produced by tests. Now if there are slower moments where logging produces non-duplicated logs, those were marked as failed. By submitting this pull request, I confirm that my contribution is made under the terms of the Apache 2.0 license. For more information on following Developer Certificate of Origin and signing off your commits, please check [here](https://github.com/opensearch-project/OpenSearch/blob/main/CONTRIBUTING.md#developer-certificate-of-origin). --------- Signed-off-by: Maciej Mierzwa Signed-off-by: MaciejMierzwa (cherry picked from commit 9da4a78f237f238bfebb5ecd2dff58a814927542) Signed-off-by: Maciej Mierzwa --- .../security/SearchOperationTest.java | 244 +++++++++--------- .../opensearch/security/SnapshotSteps.java | 22 +- .../opensearch/security/rest/WhoAmITests.java | 168 ++++++++++++ .../test/framework/audit/AuditLogsRule.java | 42 ++- .../framework/cluster/ClusterManager.java | 9 + 5 files changed, 355 insertions(+), 130 deletions(-) diff --git a/src/integrationTest/java/org/opensearch/security/SearchOperationTest.java b/src/integrationTest/java/org/opensearch/security/SearchOperationTest.java index fa99a2fdc7..9a212579a8 100644 --- a/src/integrationTest/java/org/opensearch/security/SearchOperationTest.java +++ b/src/integrationTest/java/org/opensearch/security/SearchOperationTest.java @@ -13,6 +13,8 @@ import java.util.List; import java.util.Map; import java.util.concurrent.ExecutionException; +import java.util.concurrent.TimeUnit; +import java.util.concurrent.atomic.AtomicInteger; import com.carrotsearch.randomizedtesting.annotations.ThreadLeakScope; import com.google.common.base.Stopwatch; @@ -23,7 +25,6 @@ import org.junit.Before; import org.junit.BeforeClass; import org.junit.ClassRule; -import org.junit.Ignore; import org.junit.Rule; import org.junit.Test; import org.junit.runner.RunWith; @@ -94,6 +95,7 @@ import org.opensearch.index.reindex.ReindexRequest; import org.opensearch.repositories.RepositoryMissingException; import org.opensearch.search.builder.SearchSourceBuilder; +import org.opensearch.security.auditlog.AuditLog; import org.opensearch.test.framework.AuditCompliance; import org.opensearch.test.framework.AuditConfiguration; import org.opensearch.test.framework.AuditFilters; @@ -353,7 +355,7 @@ public class SearchOperationTest { ).on(INDICES_ON_WHICH_USER_CAN_PERFORM_INDEX_OPERATIONS_PREFIX.concat("*")) ); - private static User USER_ALLOWED_TO_CREATE_INDEX = new User("user-allowed-to-create-index").roles( + private static final User USER_ALLOWED_TO_CREATE_INDEX = new User("user-allowed-to-create-index").roles( new Role("create-index-role").indexPermissions("indices:admin/create").on("*") ); @@ -456,7 +458,7 @@ public void cleanData() throws ExecutionException, InterruptedException { if (indicesExistsResponse.isExists()) { DeleteIndexRequest deleteIndexRequest = new DeleteIndexRequest(indexToBeDeleted); indices.delete(deleteIndexRequest).actionGet(); - Awaitility.await().ignoreExceptions().until(() -> indices.exists(indicesExistsRequest).get().isExists() == false); + Awaitility.await().ignoreExceptions().until(() -> !indices.exists(indicesExistsRequest).get().isExists()); } } @@ -970,12 +972,11 @@ public void shouldIndexDocumentInBulkRequest_positive() throws IOException { } auditLogsRule.assertExactlyOne(userAuthenticated(LIMITED_WRITE_USER).withRestRequest(POST, "/_bulk")); auditLogsRule.assertExactlyOne(grantedPrivilege(LIMITED_WRITE_USER, "BulkRequest")); - auditLogsRule.assertExactly(2, grantedPrivilege(LIMITED_WRITE_USER, "CreateIndexRequest")); - auditLogsRule.assertAtLeast(4, auditPredicate(INDEX_EVENT).withEffectiveUser(LIMITED_WRITE_USER));// sometimes 4 or 6 - auditLogsRule.assertAtLeast(2, grantedPrivilege(LIMITED_WRITE_USER, "PutMappingRequest"));// sometimes 2 or 4 + auditLogsRule.assertExactlyOne(grantedPrivilege(LIMITED_WRITE_USER, "CreateIndexRequest")); + auditLogsRule.assertExactlyOne(auditPredicate(INDEX_EVENT).withEffectiveUser(LIMITED_WRITE_USER)); + auditLogsRule.assertAtLeastTransportMessages(2, grantedPrivilege(LIMITED_WRITE_USER, "PutMappingRequest")); } - @Ignore("Audit log verification is shown to be flaky in this test") @Test public void shouldIndexDocumentInBulkRequest_partiallyPositive() throws IOException { try (RestHighLevelClient restHighLevelClient = cluster.getRestHighLevelClient(LIMITED_WRITE_USER)) { @@ -998,10 +999,10 @@ public void shouldIndexDocumentInBulkRequest_partiallyPositive() throws IOExcept } auditLogsRule.assertExactlyOne(userAuthenticated(LIMITED_WRITE_USER).withRestRequest(POST, "/_bulk")); auditLogsRule.assertExactlyOne(grantedPrivilege(LIMITED_WRITE_USER, "BulkRequest")); - auditLogsRule.assertExactly(2, grantedPrivilege(LIMITED_WRITE_USER, "CreateIndexRequest")); - auditLogsRule.assertExactly(6, auditPredicate(INDEX_EVENT).withEffectiveUser(LIMITED_WRITE_USER)); - auditLogsRule.assertExactly(4, grantedPrivilege(LIMITED_WRITE_USER, "PutMappingRequest")); + auditLogsRule.assertExactlyOne(grantedPrivilege(LIMITED_WRITE_USER, "CreateIndexRequest")); + auditLogsRule.assertExactlyOne(auditPredicate(INDEX_EVENT).withEffectiveUser(LIMITED_WRITE_USER)); auditLogsRule.assertExactlyOne(missingPrivilege(LIMITED_WRITE_USER, "BulkShardRequest").withIndex(SONG_INDEX_NAME)); + auditLogsRule.assertAtLeastTransportMessages(2, grantedPrivilege(LIMITED_WRITE_USER, "PutMappingRequest")); } @Test @@ -1030,7 +1031,6 @@ public void shouldIndexDocumentInBulkRequest_negative() throws IOException { auditLogsRule.assertExactlyOne(missingPrivilege(LIMITED_WRITE_USER, "BulkShardRequest").withIndex(SONG_INDEX_NAME)); } - @Ignore("Audit log verification is shown to be flaky in this test") @Test public void shouldUpdateDocumentsInBulk_positive() throws IOException { try (RestHighLevelClient restHighLevelClient = cluster.getRestHighLevelClient(LIMITED_WRITE_USER)) { @@ -1052,13 +1052,10 @@ public void shouldUpdateDocumentsInBulk_positive() throws IOException { } auditLogsRule.assertExactly(2, userAuthenticated(LIMITED_WRITE_USER).withRestRequest(POST, "/_bulk")); auditLogsRule.assertExactly(2, grantedPrivilege(LIMITED_WRITE_USER, "BulkRequest")); - auditLogsRule.assertExactly(2, grantedPrivilege(LIMITED_WRITE_USER, "CreateIndexRequest")); - auditLogsRule.assertExactly(4, grantedPrivilege(LIMITED_WRITE_USER, "PutMappingRequest")); - auditLogsRule.assertExactly(6, auditPredicate(INDEX_EVENT).withEffectiveUser(LIMITED_WRITE_USER)); - + auditLogsRule.assertAtLeastTransportMessages(2, grantedPrivilege(LIMITED_WRITE_USER, "PutMappingRequest")); + auditLogsRule.assertExactlyOne(auditPredicate(INDEX_EVENT).withEffectiveUser(LIMITED_WRITE_USER)); } - @Ignore("Audit log verification is shown to be flaky in this test") @Test public void shouldUpdateDocumentsInBulk_partiallyPositive() throws IOException { try (RestHighLevelClient restHighLevelClient = cluster.getRestHighLevelClient(LIMITED_WRITE_USER)) { @@ -1081,10 +1078,10 @@ public void shouldUpdateDocumentsInBulk_partiallyPositive() throws IOException { } auditLogsRule.assertExactly(2, userAuthenticated(LIMITED_WRITE_USER).withRestRequest(POST, "/_bulk")); auditLogsRule.assertExactly(2, grantedPrivilege(LIMITED_WRITE_USER, "BulkRequest")); - auditLogsRule.assertExactly(2, grantedPrivilege(LIMITED_WRITE_USER, "CreateIndexRequest")); - auditLogsRule.assertExactly(4, grantedPrivilege(LIMITED_WRITE_USER, "PutMappingRequest")); - auditLogsRule.assertExactly(6, auditPredicate(INDEX_EVENT).withEffectiveUser(LIMITED_WRITE_USER)); + auditLogsRule.assertExactlyOne(grantedPrivilege(LIMITED_WRITE_USER, "CreateIndexRequest")); + auditLogsRule.assertExactlyOne(auditPredicate(INDEX_EVENT).withEffectiveUser(LIMITED_WRITE_USER)); auditLogsRule.assertExactlyOne(missingPrivilege(LIMITED_WRITE_USER, "BulkShardRequest").withIndex(SONG_INDEX_NAME)); + auditLogsRule.assertAtLeastTransportMessages(2, grantedPrivilege(LIMITED_WRITE_USER, "PutMappingRequest")); } @Test @@ -1114,6 +1111,10 @@ public void shouldUpdateDocumentsInBulk_negative() throws IOException { @Test public void shouldDeleteDocumentInBulk_positive() throws IOException { + // create index + Settings sourceIndexSettings = Settings.builder().put("index.number_of_replicas", 2).put("index.number_of_shards", 2).build(); + IndexOperationsHelper.createIndex(cluster, WRITE_SONG_INDEX_NAME, sourceIndexSettings); + try (RestHighLevelClient restHighLevelClient = cluster.getRestHighLevelClient(LIMITED_WRITE_USER)) { BulkRequest bulkRequest = new BulkRequest().setRefreshPolicy(IMMEDIATE); bulkRequest.add(new IndexRequest(WRITE_SONG_INDEX_NAME).id("one").source(SONGS[0].asMap())); @@ -1138,14 +1139,16 @@ public void shouldDeleteDocumentInBulk_positive() throws IOException { } auditLogsRule.assertExactly(2, userAuthenticated(LIMITED_WRITE_USER).withRestRequest(POST, "/_bulk")); auditLogsRule.assertExactly(2, grantedPrivilege(LIMITED_WRITE_USER, "BulkRequest")); - auditLogsRule.assertExactly(2, grantedPrivilege(LIMITED_WRITE_USER, "CreateIndexRequest")); - auditLogsRule.assertExactly(4, grantedPrivilege(LIMITED_WRITE_USER, "PutMappingRequest")); - auditLogsRule.assertExactly(6, auditPredicate(INDEX_EVENT).withEffectiveUser(LIMITED_WRITE_USER)); + auditLogsRule.assertExactly(2, auditPredicate(null).withLayer(AuditLog.Origin.TRANSPORT)); + auditLogsRule.assertAtLeastTransportMessages(4, grantedPrivilege(LIMITED_WRITE_USER, "PutMappingRequest")); + auditLogsRule.assertAtLeastTransportMessages(4, auditPredicate(INDEX_EVENT).withEffectiveUser(LIMITED_WRITE_USER)); } - @Ignore("Audit log verification is shown to be flaky in this test") @Test public void shouldDeleteDocumentInBulk_partiallyPositive() throws IOException { + Settings indexSettings = Settings.builder().put("index.number_of_replicas", 0).put("index.number_of_shards", 1).build(); + IndexOperationsHelper.createIndex(cluster, WRITE_SONG_INDEX_NAME, indexSettings); + try (RestHighLevelClient restHighLevelClient = cluster.getRestHighLevelClient(LIMITED_WRITE_USER)) { BulkRequest bulkRequest = new BulkRequest().setRefreshPolicy(IMMEDIATE); bulkRequest.add(new IndexRequest(WRITE_SONG_INDEX_NAME).id("one").source(SONGS[0].asMap())); @@ -1170,10 +1173,8 @@ public void shouldDeleteDocumentInBulk_partiallyPositive() throws IOException { } auditLogsRule.assertExactly(2, userAuthenticated(LIMITED_WRITE_USER).withRestRequest(POST, "/_bulk")); auditLogsRule.assertExactly(2, grantedPrivilege(LIMITED_WRITE_USER, "BulkRequest")); - auditLogsRule.assertExactly(2, grantedPrivilege(LIMITED_WRITE_USER, "CreateIndexRequest")); - auditLogsRule.assertExactly(4, grantedPrivilege(LIMITED_WRITE_USER, "PutMappingRequest")); - auditLogsRule.assertExactly(6, auditPredicate(INDEX_EVENT).withEffectiveUser(LIMITED_WRITE_USER)); auditLogsRule.assertExactlyOne(missingPrivilege(LIMITED_WRITE_USER, "BulkShardRequest")); + auditLogsRule.assertAtLeastTransportMessages(2, grantedPrivilege(LIMITED_WRITE_USER, "PutMappingRequest")); } @Test @@ -1202,7 +1203,6 @@ public void shouldDeleteDocumentInBulk_negative() throws IOException { } - @Ignore("Seems like reindixing isn't completing before the test proceeds") @Test public void shouldReindexDocuments_positive() throws IOException { try (RestHighLevelClient restHighLevelClient = cluster.getRestHighLevelClient(REINDEXING_USER)) { @@ -1221,14 +1221,13 @@ public void shouldReindexDocuments_positive() throws IOException { auditLogsRule.assertExactlyOne(grantedPrivilege(REINDEXING_USER, "ReindexRequest")); auditLogsRule.assertExactlyOne(grantedPrivilege(REINDEXING_USER, "SearchRequest")); auditLogsRule.assertExactlyOne(grantedPrivilege(REINDEXING_USER, "BulkRequest")); - auditLogsRule.assertExactly(2, grantedPrivilege(REINDEXING_USER, "CreateIndexRequest")); - auditLogsRule.assertExactly(4, grantedPrivilege(REINDEXING_USER, "PutMappingRequest")); + auditLogsRule.assertExactlyOne(grantedPrivilege(REINDEXING_USER, "CreateIndexRequest")); auditLogsRule.assertExactlyOne(grantedPrivilege(REINDEXING_USER, "SearchScrollRequest")); - auditLogsRule.assertExactly(6, auditPredicate(INDEX_EVENT).withEffectiveUser(REINDEXING_USER)); + auditLogsRule.assertExactlyOne(auditPredicate(INDEX_EVENT).withEffectiveUser(REINDEXING_USER)); auditLogsRule.assertExactlyOne(missingPrivilege(REINDEXING_USER, "ClearScrollRequest")); + auditLogsRule.assertAtLeastTransportMessages(2, grantedPrivilege(REINDEXING_USER, "PutMappingRequest")); } - @Ignore("Seems like reindixing isn't completing before the test proceeds") @Test public void shouldReindexDocuments_negativeSource() throws IOException { try (RestHighLevelClient restHighLevelClient = cluster.getRestHighLevelClient(REINDEXING_USER)) { @@ -1243,7 +1242,6 @@ public void shouldReindexDocuments_negativeSource() throws IOException { auditLogsRule.assertExactlyOne(missingPrivilege(REINDEXING_USER, "SearchRequest")); } - @Ignore("Seems like reindixing isn't completing before the test proceeds") @Test public void shouldReindexDocuments_negativeDestination() throws IOException { try (RestHighLevelClient restHighLevelClient = cluster.getRestHighLevelClient(REINDEXING_USER)) { @@ -1262,7 +1260,6 @@ public void shouldReindexDocuments_negativeDestination() throws IOException { auditLogsRule.assertExactlyOne(missingPrivilege(REINDEXING_USER, "ClearScrollRequest")); } - @Ignore("Seems like reindixing isn't completing before the test proceeds") @Test public void shouldReindexDocuments_negativeSourceAndDestination() throws IOException { try (RestHighLevelClient restHighLevelClient = cluster.getRestHighLevelClient(REINDEXING_USER)) { @@ -1335,7 +1332,6 @@ public void shouldDeleteDocument_negative() throws IOException { } } - @Ignore("Create alias / delete alias isn't resolving in a timely manner for this test") @Test public void shouldCreateAlias_positive() throws IOException { try (RestHighLevelClient restHighLevelClient = cluster.getRestHighLevelClient(LIMITED_READ_USER)) { @@ -1349,11 +1345,10 @@ public void shouldCreateAlias_positive() throws IOException { assertThat(internalClient, clusterContainsDocument(TEMPORARY_ALIAS_NAME, ID_S1)); } auditLogsRule.assertExactlyOne(userAuthenticated(LIMITED_READ_USER).withRestRequest(POST, "/_aliases")); - auditLogsRule.assertExactly(2, grantedPrivilege(LIMITED_READ_USER, "IndicesAliasesRequest")); - auditLogsRule.assertExactly(2, auditPredicate(INDEX_EVENT).withEffectiveUser(LIMITED_READ_USER)); + auditLogsRule.assertExactlyOne(grantedPrivilege(LIMITED_READ_USER, "IndicesAliasesRequest")); + auditLogsRule.assertExactlyOne(auditPredicate(INDEX_EVENT).withEffectiveUser(LIMITED_READ_USER)); } - @Ignore("Create alias / delete alias isn't resolving in a timely manner for this test") @Test public void shouldCreateAlias_negative() throws IOException { try (RestHighLevelClient restHighLevelClient = cluster.getRestHighLevelClient(LIMITED_READ_USER)) { @@ -1371,7 +1366,6 @@ public void shouldCreateAlias_negative() throws IOException { auditLogsRule.assertExactlyOne(missingPrivilege(LIMITED_READ_USER, "IndicesAliasesRequest")); } - @Ignore("Create alias / delete alias isn't resolving in a timely manner for this test") @Test public void shouldDeleteAlias_positive() throws IOException { try (RestHighLevelClient restHighLevelClient = cluster.getRestHighLevelClient(LIMITED_READ_USER)) { @@ -1388,8 +1382,8 @@ public void shouldDeleteAlias_positive() throws IOException { assertThat(internalClient, not(clusterContainsDocument(TEMPORARY_ALIAS_NAME, ID_S1))); } auditLogsRule.assertExactly(2, userAuthenticated(LIMITED_READ_USER).withRestRequest(POST, "/_aliases")); - auditLogsRule.assertExactly(4, grantedPrivilege(LIMITED_READ_USER, "IndicesAliasesRequest")); - auditLogsRule.assertExactly(4, auditPredicate(INDEX_EVENT).withEffectiveUser(LIMITED_READ_USER)); + auditLogsRule.assertExactly(2, grantedPrivilege(LIMITED_READ_USER, "IndicesAliasesRequest")); + auditLogsRule.assertExactly(2, auditPredicate(INDEX_EVENT).withEffectiveUser(LIMITED_READ_USER)); } @Test @@ -1409,7 +1403,6 @@ public void shouldDeleteAlias_negative() throws IOException { auditLogsRule.assertExactlyOne(missingPrivilege(LIMITED_READ_USER, "IndicesAliasesRequest")); } - @Ignore("Create alias / delete alias isn't resolving in a timely manner for this test") @Test public void shouldCreateIndexTemplate_positive() throws IOException { try (RestHighLevelClient restHighLevelClient = cluster.getRestHighLevelClient(LIMITED_WRITE_USER)) { @@ -1433,12 +1426,12 @@ public void shouldCreateIndexTemplate_positive() throws IOException { } auditLogsRule.assertExactlyOne(userAuthenticated(LIMITED_WRITE_USER).withRestRequest(PUT, "/_template/musical-index-template")); auditLogsRule.assertExactlyOne(userAuthenticated(LIMITED_WRITE_USER).withRestRequest(PUT, "/song-transcription-jazz/_doc/0001")); - auditLogsRule.assertExactly(2, grantedPrivilege(LIMITED_WRITE_USER, "PutIndexTemplateRequest")); + auditLogsRule.assertExactlyOne(grantedPrivilege(LIMITED_WRITE_USER, "PutIndexTemplateRequest")); auditLogsRule.assertExactlyOne(grantedPrivilege(LIMITED_WRITE_USER, "IndexRequest")); auditLogsRule.assertExactlyOne(grantedPrivilege(LIMITED_WRITE_USER, "BulkRequest")); - auditLogsRule.assertExactly(2, grantedPrivilege(LIMITED_WRITE_USER, "CreateIndexRequest")); - auditLogsRule.assertAtLeast(2, grantedPrivilege(LIMITED_WRITE_USER, "PutMappingRequest")); - auditLogsRule.assertExactly(8, auditPredicate(INDEX_EVENT).withEffectiveUser(LIMITED_WRITE_USER)); + auditLogsRule.assertExactlyOne(grantedPrivilege(LIMITED_WRITE_USER, "CreateIndexRequest")); + auditLogsRule.assertExactly(2, auditPredicate(INDEX_EVENT).withEffectiveUser(LIMITED_WRITE_USER)); + auditLogsRule.assertAtLeastTransportMessages(2, grantedPrivilege(LIMITED_WRITE_USER, "PutMappingRequest")); } @Test @@ -1471,9 +1464,9 @@ public void shouldDeleteTemplate_positive() throws IOException { } auditLogsRule.assertExactlyOne(userAuthenticated(LIMITED_WRITE_USER).withRestRequest(PUT, "/_template/musical-index-template")); auditLogsRule.assertExactlyOne(userAuthenticated(LIMITED_WRITE_USER).withRestRequest(DELETE, "/_template/musical-index-template")); - auditLogsRule.assertExactly(2, grantedPrivilege(LIMITED_WRITE_USER, "PutIndexTemplateRequest")); - auditLogsRule.assertExactly(2, grantedPrivilege(LIMITED_WRITE_USER, "DeleteIndexTemplateRequest")); - auditLogsRule.assertExactly(4, auditPredicate(INDEX_EVENT).withEffectiveUser(LIMITED_WRITE_USER)); + auditLogsRule.assertExactlyOne(grantedPrivilege(LIMITED_WRITE_USER, "PutIndexTemplateRequest")); + auditLogsRule.assertExactlyOne(grantedPrivilege(LIMITED_WRITE_USER, "DeleteIndexTemplateRequest")); + auditLogsRule.assertExactly(2, auditPredicate(INDEX_EVENT).withEffectiveUser(LIMITED_WRITE_USER)); } @Test @@ -1491,7 +1484,6 @@ public void shouldDeleteTemplate_negative() throws IOException { auditLogsRule.assertExactlyOne(missingPrivilege(LIMITED_READ_USER, "DeleteIndexTemplateRequest")); } - @Ignore("Create alias / delete alias isn't resolving in a timely manner for this test") @Test public void shouldUpdateTemplate_positive() throws IOException { try (RestHighLevelClient restHighLevelClient = cluster.getRestHighLevelClient(LIMITED_WRITE_USER)) { @@ -1519,12 +1511,12 @@ public void shouldUpdateTemplate_positive() throws IOException { } auditLogsRule.assertExactly(2, userAuthenticated(LIMITED_WRITE_USER).withRestRequest(PUT, "/_template/musical-index-template")); auditLogsRule.assertExactlyOne(userAuthenticated(LIMITED_WRITE_USER).withRestRequest(PUT, "/song-transcription-jazz/_doc/000one")); - auditLogsRule.assertExactly(4, grantedPrivilege(LIMITED_WRITE_USER, "PutIndexTemplateRequest")); + auditLogsRule.assertExactly(2, grantedPrivilege(LIMITED_WRITE_USER, "PutIndexTemplateRequest")); auditLogsRule.assertExactlyOne(grantedPrivilege(LIMITED_WRITE_USER, "IndexRequest")); auditLogsRule.assertExactlyOne(grantedPrivilege(LIMITED_WRITE_USER, "BulkRequest")); - auditLogsRule.assertExactly(2, grantedPrivilege(LIMITED_WRITE_USER, "CreateIndexRequest")); - auditLogsRule.assertExactly(4, grantedPrivilege(LIMITED_WRITE_USER, "PutMappingRequest")); - auditLogsRule.assertExactly(10, auditPredicate(INDEX_EVENT).withEffectiveUser(LIMITED_WRITE_USER)); + auditLogsRule.assertExactlyOne(grantedPrivilege(LIMITED_WRITE_USER, "CreateIndexRequest")); + auditLogsRule.assertExactly(3, auditPredicate(INDEX_EVENT).withEffectiveUser(LIMITED_WRITE_USER)); + auditLogsRule.assertAtLeastTransportMessages(2, grantedPrivilege(LIMITED_WRITE_USER, "PutMappingRequest")); } @Test @@ -1614,7 +1606,7 @@ public void shouldCreateSnapshotRepository_positive() throws IOException { assertThat(internalClient, clusterContainsSnapshotRepository(TEST_SNAPSHOT_REPOSITORY_NAME)); } auditLogsRule.assertExactlyOne(userAuthenticated(LIMITED_WRITE_USER).withRestRequest(PUT, "/_snapshot/test-snapshot-repository")); - auditLogsRule.assertExactly(2, grantedPrivilege(LIMITED_WRITE_USER, "PutRepositoryRequest")); + auditLogsRule.assertExactlyOne(grantedPrivilege(LIMITED_WRITE_USER, "PutRepositoryRequest")); } @Test @@ -1650,8 +1642,8 @@ public void shouldDeleteSnapshotRepository_positive() throws IOException { auditLogsRule.assertExactlyOne( userAuthenticated(LIMITED_WRITE_USER).withRestRequest(DELETE, "/_snapshot/test-snapshot-repository") ); - auditLogsRule.assertExactly(2, grantedPrivilege(LIMITED_WRITE_USER, "PutRepositoryRequest")); - auditLogsRule.assertExactly(2, grantedPrivilege(LIMITED_WRITE_USER, "DeleteRepositoryRequest")); + auditLogsRule.assertExactlyOne(grantedPrivilege(LIMITED_WRITE_USER, "PutRepositoryRequest")); + auditLogsRule.assertExactlyOne(grantedPrivilege(LIMITED_WRITE_USER, "DeleteRepositoryRequest")); } @Test @@ -1668,9 +1660,10 @@ public void shouldDeleteSnapshotRepository_negative() throws IOException { auditLogsRule.assertExactlyOne(missingPrivilege(LIMITED_READ_USER, "DeleteRepositoryRequest")); } - @Test // Bug which can be reproduced with the below test: https://github.com/opensearch-project/security/issues/2169 + @Test public void shouldCreateSnapshot_positive() throws IOException { final String snapshotName = "snapshot-positive-test"; + long snapshotGetCount; try (RestHighLevelClient restHighLevelClient = cluster.getRestHighLevelClient(LIMITED_WRITE_USER)) { SnapshotSteps steps = new SnapshotSteps(restHighLevelClient); steps.createSnapshotRepository(TEST_SNAPSHOT_REPOSITORY_NAME, cluster.getSnapshotDirPath(), "fs"); @@ -1679,20 +1672,21 @@ public void shouldCreateSnapshot_positive() throws IOException { assertThat(response, notNullValue()); assertThat(response.status(), equalTo(RestStatus.ACCEPTED)); - steps.waitForSnapshotCreation(TEST_SNAPSHOT_REPOSITORY_NAME, snapshotName); + snapshotGetCount = steps.waitForSnapshotCreation(TEST_SNAPSHOT_REPOSITORY_NAME, snapshotName); assertThat(internalClient, clusterContainSuccessSnapshot(TEST_SNAPSHOT_REPOSITORY_NAME, snapshotName)); } auditLogsRule.assertExactlyOne(userAuthenticated(LIMITED_WRITE_USER).withRestRequest(PUT, "/_snapshot/test-snapshot-repository")); auditLogsRule.assertExactlyOne( userAuthenticated(LIMITED_WRITE_USER).withRestRequest(PUT, "/_snapshot/test-snapshot-repository/snapshot-positive-test") ); - auditLogsRule.assertAtLeast( - 1, - userAuthenticated(LIMITED_WRITE_USER).withRestRequest(GET, "/_snapshot/test-snapshot-repository/snapshot-positive-test") + auditLogsRule.assertExactly( + snapshotGetCount, + userAuthenticated(LIMITED_WRITE_USER).withEffectiveUser(LIMITED_WRITE_USER) + .withRestRequest(GET, "/_snapshot/test-snapshot-repository/snapshot-positive-test") ); - auditLogsRule.assertExactly(2, grantedPrivilege(LIMITED_WRITE_USER, "PutRepositoryRequest")); - auditLogsRule.assertExactly(2, grantedPrivilege(LIMITED_WRITE_USER, "CreateSnapshotRequest")); - auditLogsRule.assertAtLeast(2, grantedPrivilege(LIMITED_WRITE_USER, "GetSnapshotsRequest")); + auditLogsRule.assertExactlyOne(grantedPrivilege(LIMITED_WRITE_USER, "PutRepositoryRequest")); + auditLogsRule.assertExactlyOne(grantedPrivilege(LIMITED_WRITE_USER, "CreateSnapshotRequest")); + auditLogsRule.assertAtLeast(snapshotGetCount, grantedPrivilege(LIMITED_WRITE_USER, "GetSnapshotsRequest")); } @Test @@ -1717,12 +1711,13 @@ public void shouldCreateSnapshot_negative() throws IOException { @Test public void shouldDeleteSnapshot_positive() throws IOException { String snapshotName = "delete-snapshot-positive"; + long snapshotGetCount; try (RestHighLevelClient restHighLevelClient = cluster.getRestHighLevelClient(LIMITED_WRITE_USER)) { SnapshotSteps steps = new SnapshotSteps(restHighLevelClient); restHighLevelClient.snapshot(); steps.createSnapshotRepository(TEST_SNAPSHOT_REPOSITORY_NAME, cluster.getSnapshotDirPath(), "fs"); steps.createSnapshot(TEST_SNAPSHOT_REPOSITORY_NAME, snapshotName, SONG_INDEX_NAME); - steps.waitForSnapshotCreation(TEST_SNAPSHOT_REPOSITORY_NAME, snapshotName); + snapshotGetCount = steps.waitForSnapshotCreation(TEST_SNAPSHOT_REPOSITORY_NAME, snapshotName); var response = steps.deleteSnapshot(TEST_SNAPSHOT_REPOSITORY_NAME, snapshotName); @@ -1736,24 +1731,25 @@ public void shouldDeleteSnapshot_positive() throws IOException { auditLogsRule.assertExactlyOne( userAuthenticated(LIMITED_WRITE_USER).withRestRequest(DELETE, "/_snapshot/test-snapshot-repository/delete-snapshot-positive") ); - auditLogsRule.assertAtLeast( - 1, + auditLogsRule.assertExactly( + snapshotGetCount, userAuthenticated(LIMITED_WRITE_USER).withRestRequest(GET, "/_snapshot/test-snapshot-repository/delete-snapshot-positive") ); - auditLogsRule.assertExactly(2, grantedPrivilege(LIMITED_WRITE_USER, "PutRepositoryRequest")); - auditLogsRule.assertExactly(2, grantedPrivilege(LIMITED_WRITE_USER, "CreateSnapshotRequest")); - auditLogsRule.assertExactly(2, grantedPrivilege(LIMITED_WRITE_USER, "DeleteSnapshotRequest")); - auditLogsRule.assertAtLeast(2, grantedPrivilege(LIMITED_WRITE_USER, "GetSnapshotsRequest")); + auditLogsRule.assertExactlyOne(grantedPrivilege(LIMITED_WRITE_USER, "PutRepositoryRequest")); + auditLogsRule.assertExactlyOne(grantedPrivilege(LIMITED_WRITE_USER, "CreateSnapshotRequest")); + auditLogsRule.assertExactlyOne(grantedPrivilege(LIMITED_WRITE_USER, "DeleteSnapshotRequest")); + auditLogsRule.assertExactly(snapshotGetCount, grantedPrivilege(LIMITED_WRITE_USER, "GetSnapshotsRequest")); } @Test public void shouldDeleteSnapshot_negative() throws IOException { String snapshotName = "delete-snapshot-negative"; + long snapshotGetCount; try (RestHighLevelClient restHighLevelClient = cluster.getRestHighLevelClient(LIMITED_WRITE_USER)) { SnapshotSteps steps = new SnapshotSteps(restHighLevelClient); steps.createSnapshotRepository(TEST_SNAPSHOT_REPOSITORY_NAME, cluster.getSnapshotDirPath(), "fs"); steps.createSnapshot(TEST_SNAPSHOT_REPOSITORY_NAME, snapshotName, SONG_INDEX_NAME); - steps.waitForSnapshotCreation(TEST_SNAPSHOT_REPOSITORY_NAME, snapshotName); + snapshotGetCount = steps.waitForSnapshotCreation(TEST_SNAPSHOT_REPOSITORY_NAME, snapshotName); } try (RestHighLevelClient restHighLevelClient = cluster.getRestHighLevelClient(LIMITED_READ_USER)) { SnapshotSteps steps = new SnapshotSteps(restHighLevelClient); @@ -1768,23 +1764,27 @@ public void shouldDeleteSnapshot_negative() throws IOException { auditLogsRule.assertExactlyOne( userAuthenticated(LIMITED_READ_USER).withRestRequest(DELETE, "/_snapshot/test-snapshot-repository/delete-snapshot-negative") ); - auditLogsRule.assertAtLeast( - 1, + auditLogsRule.assertExactly( + snapshotGetCount, userAuthenticated(LIMITED_WRITE_USER).withRestRequest(GET, "/_snapshot/test-snapshot-repository/delete-snapshot-negative") ); - auditLogsRule.assertExactly(2, grantedPrivilege(LIMITED_WRITE_USER, "PutRepositoryRequest")); - auditLogsRule.assertExactly(2, grantedPrivilege(LIMITED_WRITE_USER, "CreateSnapshotRequest")); - auditLogsRule.assertExactly(1, missingPrivilege(LIMITED_READ_USER, "DeleteSnapshotRequest")); - auditLogsRule.assertAtLeast(2, grantedPrivilege(LIMITED_WRITE_USER, "GetSnapshotsRequest")); + auditLogsRule.assertExactlyOne(grantedPrivilege(LIMITED_WRITE_USER, "PutRepositoryRequest")); + auditLogsRule.assertExactlyOne(grantedPrivilege(LIMITED_WRITE_USER, "CreateSnapshotRequest")); + auditLogsRule.assertExactlyOne(missingPrivilege(LIMITED_READ_USER, "DeleteSnapshotRequest")); + auditLogsRule.assertExactly(snapshotGetCount, grantedPrivilege(LIMITED_WRITE_USER, "GetSnapshotsRequest")); } - @Ignore("Audit log entries verifcation isn't always consistant") @Test public void shouldRestoreSnapshot_positive() throws IOException { final String snapshotName = "restore-snapshot-positive"; + long snapshotGetCount; + AtomicInteger restoredCount = new AtomicInteger(); try (RestHighLevelClient restHighLevelClient = cluster.getRestHighLevelClient(LIMITED_WRITE_USER)) { SnapshotSteps steps = new SnapshotSteps(restHighLevelClient); // 1. create some documents + Settings indexSettings = Settings.builder().put("index.number_of_replicas", 0).put("index.number_of_shards", 1).build(); + IndexOperationsHelper.createIndex(cluster, WRITE_SONG_INDEX_NAME, indexSettings); + BulkRequest bulkRequest = new BulkRequest(); bulkRequest.add(new IndexRequest(WRITE_SONG_INDEX_NAME).id("Eins").source(SONGS[0].asMap())); bulkRequest.add(new IndexRequest(WRITE_SONG_INDEX_NAME).id("Zwei").source(SONGS[1].asMap())); @@ -1798,7 +1798,7 @@ public void shouldRestoreSnapshot_positive() throws IOException { steps.createSnapshot(TEST_SNAPSHOT_REPOSITORY_NAME, snapshotName, WRITE_SONG_INDEX_NAME); // 4. wait till snapshot is ready - steps.waitForSnapshotCreation(TEST_SNAPSHOT_REPOSITORY_NAME, snapshotName); + snapshotGetCount = steps.waitForSnapshotCreation(TEST_SNAPSHOT_REPOSITORY_NAME, snapshotName); // 5. introduce some changes bulkRequest = new BulkRequest(); @@ -1818,8 +1818,12 @@ public void shouldRestoreSnapshot_positive() throws IOException { CountRequest countRequest = new CountRequest(RESTORED_SONG_INDEX_NAME); Awaitility.await() .ignoreExceptions() + .pollInterval(100, TimeUnit.MILLISECONDS) .alias("Index contains proper number of documents restored from snapshot.") - .until(() -> restHighLevelClient.count(countRequest, DEFAULT).getCount() == 2); + .until(() -> { + restoredCount.incrementAndGet(); + return restHighLevelClient.count(countRequest, DEFAULT).getCount() == 2; + }); // 8. verify that document are present in restored index assertThat( @@ -1843,30 +1847,33 @@ public void shouldRestoreSnapshot_positive() throws IOException { "/_snapshot/test-snapshot-repository/restore-snapshot-positive/_restore" ) ); + auditLogsRule.assertExactly( + restoredCount.get(), + userAuthenticated(LIMITED_WRITE_USER).withRestRequest(POST, "/restored_write_song_index/_count") + ); auditLogsRule.assertExactly(2, userAuthenticated(LIMITED_WRITE_USER).withRestRequest(POST, "/_bulk")); - auditLogsRule.assertAtLeast( - 1, + auditLogsRule.assertExactly( + snapshotGetCount, userAuthenticated(LIMITED_WRITE_USER).withRestRequest(GET, "/_snapshot/test-snapshot-repository/restore-snapshot-positive") ); - auditLogsRule.assertExactly(2, grantedPrivilege(LIMITED_WRITE_USER, "PutRepositoryRequest")); - auditLogsRule.assertExactly(2, grantedPrivilege(LIMITED_WRITE_USER, "CreateSnapshotRequest")); + auditLogsRule.assertExactlyOne(grantedPrivilege(LIMITED_WRITE_USER, "PutRepositoryRequest")); + auditLogsRule.assertExactlyOne(grantedPrivilege(LIMITED_WRITE_USER, "CreateSnapshotRequest")); auditLogsRule.assertExactly(2, grantedPrivilege(LIMITED_WRITE_USER, "BulkRequest")); - auditLogsRule.assertExactly(2, grantedPrivilege(LIMITED_WRITE_USER, "CreateIndexRequest")); - auditLogsRule.assertExactly(4, grantedPrivilege(LIMITED_WRITE_USER, "PutMappingRequest")); - auditLogsRule.assertExactly(2, grantedPrivilege(LIMITED_WRITE_USER, "RestoreSnapshotRequest")); - auditLogsRule.assertAtLeast(2, grantedPrivilege(LIMITED_WRITE_USER, "GetSnapshotsRequest")); - auditLogsRule.assertExactly(6, auditPredicate(INDEX_EVENT).withEffectiveUser(LIMITED_WRITE_USER)); - - // Audit events generated in step 7 above - auditLogsRule.assertAtLeast(1, userAuthenticated(LIMITED_WRITE_USER).withRestRequest(POST, "/restored_write_song_index/_count")); - auditLogsRule.assertAtLeast(1, grantedPrivilege(LIMITED_WRITE_USER, "SearchRequest")); + auditLogsRule.assertExactlyOne(grantedPrivilege(LIMITED_WRITE_USER, "RestoreSnapshotRequest")); + auditLogsRule.assertExactly(restoredCount.get(), grantedPrivilege(LIMITED_WRITE_USER, "SearchRequest")); + auditLogsRule.assertExactly(snapshotGetCount, grantedPrivilege(LIMITED_WRITE_USER, "GetSnapshotsRequest")); + auditLogsRule.assertAtLeastTransportMessages(2, grantedPrivilege(LIMITED_WRITE_USER, "PutMappingRequest")); } @Test public void shouldRestoreSnapshot_failureForbiddenIndex() throws IOException { final String snapshotName = "restore-snapshot-negative-forbidden-index"; String restoreToIndex = "forbidden_index"; + long snapshotGetCount; + Settings indexSettings = Settings.builder().put("index.number_of_shards", 1).put("index.number_of_replicas", 0).build(); + IndexOperationsHelper.createIndex(cluster, WRITE_SONG_INDEX_NAME, indexSettings); try (RestHighLevelClient restHighLevelClient = cluster.getRestHighLevelClient(LIMITED_WRITE_USER)) { + SnapshotSteps steps = new SnapshotSteps(restHighLevelClient); // 1. create some documents BulkRequest bulkRequest = new BulkRequest(); @@ -1882,7 +1889,7 @@ public void shouldRestoreSnapshot_failureForbiddenIndex() throws IOException { steps.createSnapshot(TEST_SNAPSHOT_REPOSITORY_NAME, snapshotName, WRITE_SONG_INDEX_NAME); // 4. wait till snapshot is ready - steps.waitForSnapshotCreation(TEST_SNAPSHOT_REPOSITORY_NAME, snapshotName); + snapshotGetCount = steps.waitForSnapshotCreation(TEST_SNAPSHOT_REPOSITORY_NAME, snapshotName); // 5. restore the snapshot assertThatThrownBy( @@ -1908,27 +1915,28 @@ public void shouldRestoreSnapshot_failureForbiddenIndex() throws IOException { ) ); auditLogsRule.assertExactlyOne(userAuthenticated(LIMITED_WRITE_USER).withRestRequest(POST, "/_bulk")); - auditLogsRule.assertAtLeast( - 1, + auditLogsRule.assertExactly( + snapshotGetCount, userAuthenticated(LIMITED_WRITE_USER).withRestRequest( GET, "/_snapshot/test-snapshot-repository/restore-snapshot-negative-forbidden-index" ) ); - auditLogsRule.assertExactly(2, grantedPrivilege(LIMITED_WRITE_USER, "PutRepositoryRequest")); - auditLogsRule.assertExactly(2, grantedPrivilege(LIMITED_WRITE_USER, "CreateSnapshotRequest")); + auditLogsRule.assertExactlyOne(grantedPrivilege(LIMITED_WRITE_USER, "PutRepositoryRequest")); + auditLogsRule.assertExactlyOne(grantedPrivilege(LIMITED_WRITE_USER, "CreateSnapshotRequest")); auditLogsRule.assertExactlyOne(grantedPrivilege(LIMITED_WRITE_USER, "BulkRequest")); - auditLogsRule.assertExactly(2, grantedPrivilege(LIMITED_WRITE_USER, "CreateIndexRequest")); - auditLogsRule.assertExactly(4, grantedPrivilege(LIMITED_WRITE_USER, "PutMappingRequest")); - auditLogsRule.assertExactlyOne(grantedPrivilege(LIMITED_WRITE_USER, "RestoreSnapshotRequest")); - auditLogsRule.assertAtLeast(2, grantedPrivilege(LIMITED_WRITE_USER, "GetSnapshotsRequest")); - auditLogsRule.assertExactly(6, auditPredicate(INDEX_EVENT).withEffectiveUser(LIMITED_WRITE_USER)); - auditLogsRule.assertExactlyOne(missingPrivilege(LIMITED_WRITE_USER, "RestoreSnapshotRequest")); + auditLogsRule.assertExactly(snapshotGetCount, grantedPrivilege(LIMITED_WRITE_USER, "GetSnapshotsRequest")); + auditLogsRule.assertAtLeastTransportMessages(1, auditPredicate(INDEX_EVENT).withEffectiveUser(LIMITED_WRITE_USER)); + auditLogsRule.assertExactlyScanAll(1, missingPrivilege(LIMITED_WRITE_USER, "RestoreSnapshotRequest")); + auditLogsRule.assertAtLeastTransportMessages(2, grantedPrivilege(LIMITED_WRITE_USER, "PutMappingRequest")); } @Test public void shouldRestoreSnapshot_failureOperationForbidden() throws IOException { String snapshotName = "restore-snapshot-negative-forbidden-operation"; + long snapshotGetCount; + Settings indexSettings = Settings.builder().put("index.number_of_shards", 1).put("index.number_of_replicas", 0).build(); + IndexOperationsHelper.createIndex(cluster, WRITE_SONG_INDEX_NAME, indexSettings); try (RestHighLevelClient restHighLevelClient = cluster.getRestHighLevelClient(LIMITED_WRITE_USER)) { SnapshotSteps steps = new SnapshotSteps(restHighLevelClient); // 1. create some documents @@ -1945,7 +1953,7 @@ public void shouldRestoreSnapshot_failureOperationForbidden() throws IOException steps.createSnapshot(TEST_SNAPSHOT_REPOSITORY_NAME, snapshotName, WRITE_SONG_INDEX_NAME); // 4. wait till snapshot is ready - steps.waitForSnapshotCreation(TEST_SNAPSHOT_REPOSITORY_NAME, snapshotName); + snapshotGetCount = steps.waitForSnapshotCreation(TEST_SNAPSHOT_REPOSITORY_NAME, snapshotName); } // 5. restore the snapshot try (RestHighLevelClient restHighLevelClient = cluster.getRestHighLevelClient(LIMITED_READ_USER)) { @@ -1973,21 +1981,19 @@ public void shouldRestoreSnapshot_failureOperationForbidden() throws IOException ) ); auditLogsRule.assertExactlyOne(userAuthenticated(LIMITED_WRITE_USER).withRestRequest(POST, "/_bulk")); - auditLogsRule.assertAtLeast( - 1, + auditLogsRule.assertExactly( + snapshotGetCount, userAuthenticated(LIMITED_WRITE_USER).withRestRequest( GET, "/_snapshot/test-snapshot-repository/restore-snapshot-negative-forbidden-operation" ) ); - auditLogsRule.assertExactly(2, grantedPrivilege(LIMITED_WRITE_USER, "PutRepositoryRequest")); - auditLogsRule.assertExactly(2, grantedPrivilege(LIMITED_WRITE_USER, "CreateSnapshotRequest")); + auditLogsRule.assertExactlyOne(grantedPrivilege(LIMITED_WRITE_USER, "PutRepositoryRequest")); + auditLogsRule.assertExactlyOne(grantedPrivilege(LIMITED_WRITE_USER, "CreateSnapshotRequest")); auditLogsRule.assertExactlyOne(grantedPrivilege(LIMITED_WRITE_USER, "BulkRequest")); - auditLogsRule.assertExactly(2, grantedPrivilege(LIMITED_WRITE_USER, "CreateIndexRequest")); - auditLogsRule.assertExactly(4, grantedPrivilege(LIMITED_WRITE_USER, "PutMappingRequest")); - auditLogsRule.assertExactly(1, missingPrivilege(LIMITED_READ_USER, "RestoreSnapshotRequest")); - auditLogsRule.assertAtLeast(2, grantedPrivilege(LIMITED_WRITE_USER, "GetSnapshotsRequest")); - auditLogsRule.assertExactly(6, auditPredicate(INDEX_EVENT).withEffectiveUser(LIMITED_WRITE_USER)); + auditLogsRule.assertExactlyScanAll(1, missingPrivilege(LIMITED_READ_USER, "RestoreSnapshotRequest")); + auditLogsRule.assertExactly(snapshotGetCount, grantedPrivilege(LIMITED_WRITE_USER, "GetSnapshotsRequest")); + auditLogsRule.assertAtLeastTransportMessages(2, grantedPrivilege(LIMITED_WRITE_USER, "PutMappingRequest")); } @Test @@ -2125,11 +2131,11 @@ public void shouldDeleteIndexByAliasRequest_positive() throws IOException { userAuthenticated(USER_ALLOWED_TO_PERFORM_INDEX_OPERATIONS_ON_SELECTED_INDICES).withRestRequest(POST, "/_aliases") ); auditLogsRule.assertExactly( - 2, + 1, grantedPrivilege(USER_ALLOWED_TO_PERFORM_INDEX_OPERATIONS_ON_SELECTED_INDICES, "IndicesAliasesRequest") ); auditLogsRule.assertExactly( - 2, + 1, auditPredicate(INDEX_EVENT).withEffectiveUser(USER_ALLOWED_TO_PERFORM_INDEX_OPERATIONS_ON_SELECTED_INDICES) ); } @@ -2706,11 +2712,11 @@ public void shouldCreateIndexWithAlias_positive() throws IOException { ) ); auditLogsRule.assertExactly( - 2, + 1, grantedPrivilege(USER_ALLOWED_TO_PERFORM_INDEX_OPERATIONS_ON_SELECTED_INDICES, "CreateIndexRequest") ); auditLogsRule.assertExactly( - 2, + 1, auditPredicate(INDEX_EVENT).withEffectiveUser(USER_ALLOWED_TO_PERFORM_INDEX_OPERATIONS_ON_SELECTED_INDICES) ); } diff --git a/src/integrationTest/java/org/opensearch/security/SnapshotSteps.java b/src/integrationTest/java/org/opensearch/security/SnapshotSteps.java index 28aa6abd43..a03891ecca 100644 --- a/src/integrationTest/java/org/opensearch/security/SnapshotSteps.java +++ b/src/integrationTest/java/org/opensearch/security/SnapshotSteps.java @@ -11,6 +11,8 @@ import java.io.IOException; import java.util.Map; +import java.util.concurrent.TimeUnit; +import java.util.concurrent.atomic.AtomicInteger; import org.awaitility.Awaitility; @@ -58,13 +60,21 @@ public CreateSnapshotResponse createSnapshot(String repositoryName, String snaps return snapshotClient.create(createSnapshotRequest, DEFAULT); } - public void waitForSnapshotCreation(String repositoryName, String snapshotName) { + public int waitForSnapshotCreation(String repositoryName, String snapshotName) { + AtomicInteger count = new AtomicInteger(); GetSnapshotsRequest getSnapshotsRequest = new GetSnapshotsRequest(repositoryName, new String[] { snapshotName }); - Awaitility.await().alias("wait for snapshot creation").ignoreExceptions().until(() -> { - GetSnapshotsResponse snapshotsResponse = snapshotClient.get(getSnapshotsRequest, DEFAULT); - SnapshotInfo snapshotInfo = snapshotsResponse.getSnapshots().get(0); - return SnapshotState.SUCCESS.equals(snapshotInfo.state()); - }); + Awaitility.await() + .pollDelay(250, TimeUnit.MILLISECONDS) + .pollInterval(2, TimeUnit.SECONDS) + .alias("wait for snapshot creation") + .ignoreExceptions() + .until(() -> { + count.incrementAndGet(); + GetSnapshotsResponse snapshotsResponse = snapshotClient.get(getSnapshotsRequest, DEFAULT); + SnapshotInfo snapshotInfo = snapshotsResponse.getSnapshots().get(0); + return SnapshotState.SUCCESS.equals(snapshotInfo.state()); + }); + return count.get(); } // CS-SUPPRESS-SINGLE: RegexpSingleline It is not possible to use phrase "cluster manager" instead of master here diff --git a/src/integrationTest/java/org/opensearch/security/rest/WhoAmITests.java b/src/integrationTest/java/org/opensearch/security/rest/WhoAmITests.java index badb938b3a..c7ce657247 100644 --- a/src/integrationTest/java/org/opensearch/security/rest/WhoAmITests.java +++ b/src/integrationTest/java/org/opensearch/security/rest/WhoAmITests.java @@ -104,5 +104,173 @@ public void testWhoAmIPost() throws Exception { assertThat(client.post(WHOAMI_ENDPOINT).getStatusCode(), equalTo(HttpStatus.SC_OK)); } + // No audit logs generated because `/whoami` is passthrough at Transport Layer, and POST route is not a NamedRoute + auditLogsRule.assertAuditLogsCount(0, 0); + } + + @Test + public void testAuditLogSimilarityWithTransportLayer() { + try (TestRestClient client = cluster.getRestClient(AUDIT_LOG_VERIFIER)) { + assertResponse(client.get(WHOAMI_PROTECTED_ENDPOINT), HttpStatus.SC_OK, expectedAuthorizedBody); + auditLogsRule.assertExactlyOne(userAuthenticatedPredicate(AUDIT_LOG_VERIFIER, GET, "/" + WHOAMI_PROTECTED_ENDPOINT)); + auditLogsRule.assertExactlyOne( + privilegePredicateRESTLayer(GRANTED_PRIVILEGES, AUDIT_LOG_VERIFIER, GET, "/" + WHOAMI_PROTECTED_ENDPOINT) + ); + + assertThat(client.get("_cat/indices").getStatusCode(), equalTo(HttpStatus.SC_OK)); + + // transport layer audit messages + auditLogsRule.assertExactly(1, grantedPrivilege(AUDIT_LOG_VERIFIER, "GetSettingsRequest")); + + List grantedPrivilegesMessages = auditLogsRule.getCurrentTestAuditMessages() + .stream() + .filter(msg -> msg.getCategory().equals(GRANTED_PRIVILEGES)) + .collect(Collectors.toList()); + + verifyAuditLogSimilarity(grantedPrivilegesMessages); + } + } + + private void assertResponse(TestRestClient.HttpResponse response, int expectedStatus, String expectedBody) { + assertThat(response.getStatusCode(), equalTo(expectedStatus)); + assertThat(response.getBody(), equalTo(expectedBody)); + } + + private void verifyAuditLogSimilarity(List currentTestAuditMessages) { + List restSet = new ArrayList<>(); + List transportSet = new ArrayList<>(); + + // It is okay to loop through all even though we end up using only 2, as the total number of messages should be around 8 + for (AuditMessage auditMessage : currentTestAuditMessages) { + if ("REST".equals(auditMessage.getAsMap().get(AuditMessage.REQUEST_LAYER).toString())) { + restSet.add(auditMessage); + } else if ("TRANSPORT".equals(auditMessage.getAsMap().get(AuditMessage.REQUEST_LAYER).toString())) { + transportSet.add(auditMessage); + } + } + // We pass 1 message from each layer to check for similarity + checkForStructuralSimilarity(restSet.get(0), transportSet.get(0)); + } + + /** + * Checks for structural similarity between audit message generated at Rest layer vs transport layer + * Example REST audit message for GRANTED_PRIVILEGES: + * { + * "audit_cluster_name":"local_cluster_1", + * "audit_node_name":"data_0", + * "audit_rest_request_method":"GET", + * "audit_category":"GRANTED_PRIVILEGES", + * "audit_request_origin":"REST", + * "audit_node_id":"Dez5cwAAQAC6cdmK_____w", + * "audit_request_layer":"REST", + * "audit_rest_request_path":"/_plugins/_security/whoamiprotected", + * "@timestamp":"2023-08-16T17:35:53.531+00:00", + * "audit_format_version":4, + * "audit_request_remote_address":"127.0.0.1", + * "audit_node_host_address":"127.0.0.1", + * "audit_rest_request_headers":{ + * "Connection":[ + * "keep-alive" + * ], + * "User-Agent":[ + * "Apache-HttpClient/5.2.1 (Java/19.0.1)" + * ], + * "content-length":[ + * "0" + * ], + * "Host":[ + * "127.0.0.1:47210" + * ], + * "Accept-Encoding":[ + * "gzip, x-gzip, deflate" + * ] + * }, + * "audit_request_effective_user":"audit_log_verifier", + * "audit_node_host_name":"127.0.0.1" + * } + * + * + * Example Transport audit message for GRANTED_PRIVILEGES: + * { + * "audit_cluster_name":"local_cluster_1", + * "audit_transport_headers":{ + * "_system_index_access_allowed":"false" + * }, + * "audit_node_name":"data_0", + * "audit_trace_task_id":"Dez5cwAAQAC6cdmK_____w:87", + * "audit_transport_request_type":"GetSettingsRequest", + * "audit_category":"GRANTED_PRIVILEGES", + * "audit_request_origin":"REST", + * "audit_node_id":"Dez5cwAAQAC6cdmK_____w", + * "audit_request_layer":"TRANSPORT", + * "@timestamp":"2023-08-16T17:35:53.621+00:00", + * "audit_format_version":4, + * "audit_request_remote_address":"127.0.0.1", + * "audit_request_privilege":"indices:monitor/settings/get", + * "audit_node_host_address":"127.0.0.1", + * "audit_request_effective_user":"audit_log_verifier", + * "audit_node_host_name":"127.0.0.1" + * } + * + * + * @param restAuditMessage audit message generated at REST layer + * @param transportAuditMessage audit message generated at Transport layer + */ + private void checkForStructuralSimilarity(AuditMessage restAuditMessage, AuditMessage transportAuditMessage) { + + Map restMsgFields = restAuditMessage.getAsMap(); + Map transportMsgFields = transportAuditMessage.getAsMap(); + + Set restAuditSet = restMsgFields.keySet(); + Set transportAuditSet = transportMsgFields.keySet(); + + // Added a magic number here and below, because there are always 15 or more items in each message generated via Audit logs + assertThat(restAuditSet.size(), greaterThan(14)); + assertThat(transportAuditSet.size(), greaterThan(14)); + + // check for values of common fields + Set commonFields = new HashSet<>(restAuditSet); + commonFields.retainAll(transportAuditSet); + + assertCommonFields(commonFields, restMsgFields, transportMsgFields); + + // check for values of uncommon fields + restAuditSet.removeAll(transportAuditMessage.getAsMap().keySet()); + transportAuditSet.removeAll(restAuditMessage.getAsMap().keySet()); + + // We compare two sets and see there were more than 10 items with same keys indicating these logs are similar + // There are a few headers that are generated different for REST vs TRANSPORT layer audit logs, but that is expected + // The end goal of this test is to ensure similarity, not equality. + assertThat(restAuditSet.size(), lessThan(5)); + assertThat(transportAuditSet.size(), lessThan(5)); + + assertThat(restMsgFields.get("audit_rest_request_path"), equalTo("/_plugins/_security/whoamiprotected")); + assertThat(restMsgFields.get("audit_rest_request_method").toString(), equalTo("GET")); + assertThat(restMsgFields.get("audit_rest_request_headers").toString().contains("Connection"), equalTo(true)); + + assertThat(transportMsgFields.get("audit_transport_request_type"), equalTo("GetSettingsRequest")); + assertThat(transportMsgFields.get("audit_request_privilege"), equalTo("indices:monitor/settings/get")); + assertThat(Strings.isNullOrEmpty(transportMsgFields.get("audit_trace_task_id").toString()), equalTo(false)); + } + + private void assertCommonFields(Set commonFields, Map restMsgFields, Map transportMsgFields) { + for (String key : commonFields) { + if (key.equals("@timestamp")) { + String restTimeStamp = restMsgFields.get(key).toString(); + String transportTimeStamp = transportMsgFields.get(key).toString(); + + DateTimeFormatter formatter = DateTimeFormatter.ofPattern("yyyy-MM-dd'T'HH:mm:ss.SSSXXX"); + LocalDateTime restDateTime = LocalDateTime.parse(restTimeStamp, formatter); + LocalDateTime transportDateTime = LocalDateTime.parse(transportTimeStamp, formatter); + + // assert that these log messages are generated within 10 seconds of each other + assertTrue(Duration.between(restDateTime, transportDateTime).getSeconds() < 10); + } else if (key.equals("audit_request_layer")) { + assertThat(restMsgFields.get(key).toString(), equalTo("REST")); + assertThat(transportMsgFields.get(key).toString(), equalTo("TRANSPORT")); + } else { + assertThat(restMsgFields.get(key), equalTo(transportMsgFields.get(key))); + } + } } } diff --git a/src/integrationTest/java/org/opensearch/test/framework/audit/AuditLogsRule.java b/src/integrationTest/java/org/opensearch/test/framework/audit/AuditLogsRule.java index 3d13d731eb..3f9a0ae466 100644 --- a/src/integrationTest/java/org/opensearch/test/framework/audit/AuditLogsRule.java +++ b/src/integrationTest/java/org/opensearch/test/framework/audit/AuditLogsRule.java @@ -39,6 +39,7 @@ public class AuditLogsRule implements TestRule { private static final Logger log = LogManager.getLogger(AuditLogsRule.class); private List currentTestAuditMessages; + private List currentTransportTestAuditMessages; public List getCurrentTestAuditMessages() { return currentTestAuditMessages; @@ -56,6 +57,7 @@ public void waitForAuditLogs() { private void afterWaitingForAuditLogs() { if (log.isDebugEnabled()) { log.debug("Audit records captured during test:\n{}", auditMessagesToString(currentTestAuditMessages)); + log.debug("Audit transport records captured during test:\n{}", auditMessagesToString(currentTransportTestAuditMessages)); } } @@ -63,6 +65,13 @@ public void assertExactlyOne(Predicate predicate) { assertExactly(1, predicate); } + public void assertExactlyScanAll(long expectedNumberOfAuditMessages, Predicate predicate) { + List auditMessages = new ArrayList<>(currentTestAuditMessages); + auditMessages.addAll(currentTransportTestAuditMessages); + assertExactly(exactNumberOfAuditsFulfillPredicate(expectedNumberOfAuditMessages, predicate), auditMessages); + + } + public void assertAuditLogsCount(int from, int to) { int actualCount = currentTestAuditMessages.size(); String message = "Expected audit log count is between " + from + " and " + to + " but was " + actualCount; @@ -70,10 +79,10 @@ public void assertAuditLogsCount(int from, int to) { } public void assertExactly(long expectedNumberOfAuditMessages, Predicate predicate) { - assertExactly(exactNumberOfAuditsFulfillPredicate(expectedNumberOfAuditMessages, predicate)); + assertExactly(exactNumberOfAuditsFulfillPredicate(expectedNumberOfAuditMessages, predicate), currentTestAuditMessages); } - private void assertExactly(Matcher> matcher) { + private void assertExactly(Matcher> matcher, List currentTestAuditMessages) { // pollDelay - initial delay before first evaluation Awaitility.await("Await for audit logs") .atMost(3, TimeUnit.SECONDS) @@ -82,7 +91,11 @@ private void assertExactly(Matcher> matcher) { } public void assertAtLeast(long minCount, Predicate predicate) { - assertExactly(atLeastCertainNumberOfAuditsFulfillPredicate(minCount, predicate)); + assertExactly(atLeastCertainNumberOfAuditsFulfillPredicate(minCount, predicate), currentTestAuditMessages); + } + + public void assertAtLeastTransportMessages(long minCount, Predicate predicate) { + assertExactly(atLeastCertainNumberOfAuditsFulfillPredicate(minCount, predicate), currentTransportTestAuditMessages); } private static String auditMessagesToString(List audits) { @@ -122,16 +135,35 @@ private void whenTimeoutOccurs(String methodName) { private void afterTest() { TestRuleAuditLogSink.unregisterListener(); this.currentTestAuditMessages = null; + this.currentTransportTestAuditMessages = null; } private void beforeTest(String methodName) { log.info("Start collecting audit logs before test {}", methodName); this.currentTestAuditMessages = synchronizedList(new ArrayList<>()); + this.currentTransportTestAuditMessages = synchronizedList(new ArrayList<>()); TestRuleAuditLogSink.registerListener(this); } public void onAuditMessage(AuditMessage auditMessage) { - currentTestAuditMessages.add(auditMessage); - log.debug("New audit message received '{}', total number of audit messages '{}'.", auditMessage, currentTestAuditMessages.size()); + if (auditMessage.getAsMap().keySet().contains("audit_transport_headers")) { + if (log.isDebugEnabled()) { + log.debug( + "New transport audit message received '{}', total number of transport audit messages '{}'.", + auditMessage, + currentTransportTestAuditMessages.size() + ); + } + currentTransportTestAuditMessages.add(auditMessage); + } else { + if (log.isDebugEnabled()) { + log.debug( + "New audit message received '{}', total number of audit messages '{}'.", + auditMessage, + currentTestAuditMessages.size() + ); + } + currentTestAuditMessages.add(auditMessage); + } } } diff --git a/src/integrationTest/java/org/opensearch/test/framework/cluster/ClusterManager.java b/src/integrationTest/java/org/opensearch/test/framework/cluster/ClusterManager.java index 0bf50c7a4d..551a231830 100644 --- a/src/integrationTest/java/org/opensearch/test/framework/cluster/ClusterManager.java +++ b/src/integrationTest/java/org/opensearch/test/framework/cluster/ClusterManager.java @@ -74,6 +74,15 @@ public enum ClusterManager { new NodeSettings(NodeRole.CLUSTER_MANAGER), new NodeSettings(NodeRole.DATA), new NodeSettings(NodeRole.DATA) + ), + + THREE_CLUSTER_MANAGERS_COORDINATOR( + new NodeSettings(NodeRole.CLUSTER_MANAGER), + new NodeSettings(NodeRole.CLUSTER_MANAGER), + new NodeSettings(NodeRole.CLUSTER_MANAGER), + new NodeSettings(NodeRole.DATA), + new NodeSettings(NodeRole.DATA), + new NodeSettings() ); private List nodeSettings = new LinkedList<>();