From 6359d988f02c583231879c83bec016a822d450aa Mon Sep 17 00:00:00 2001 From: Andrei Stefan Date: Fri, 8 Feb 2019 17:23:16 +0200 Subject: [PATCH] Account for a possible rolled over file while reading the audit log file (#34909) (cherry picked from commit 75cb6b38ed67dc9d32c9291b0c174ffa94e473bc) --- x-pack/plugin/sql/qa/security/build.gradle | 5 +- .../sql/qa/security/SqlSecurityTestCase.java | 122 ++++++++++++------ .../src/test/resources/plugin-security.policy | 1 + 3 files changed, 91 insertions(+), 37 deletions(-) diff --git a/x-pack/plugin/sql/qa/security/build.gradle b/x-pack/plugin/sql/qa/security/build.gradle index d9bffd393641d..45ab8c92f1e7f 100644 --- a/x-pack/plugin/sql/qa/security/build.gradle +++ b/x-pack/plugin/sql/qa/security/build.gradle @@ -7,7 +7,7 @@ Project mainProject = project group = "${group}.x-pack.qa.sql.security" // Tests are pushed down to subprojects and will be checked there. -testingConventions.enabled = false +testingConventions.enabled = false subprojects { // Use resources from the parent project in subprojects @@ -41,8 +41,11 @@ subprojects { } integTestRunner { + def today = new Date().format('yyyy-MM-dd') systemProperty 'tests.audit.logfile', "${ -> integTest.nodes[0].homeDir}/logs/${ -> integTest.nodes[0].clusterName }_audit.json" + systemProperty 'tests.audit.yesterday.logfile', + "${ -> integTest.nodes[0].homeDir}/logs/${ -> integTest.nodes[0].clusterName }_audit-${today}.json" } runqa { diff --git a/x-pack/plugin/sql/qa/security/src/test/java/org/elasticsearch/xpack/sql/qa/security/SqlSecurityTestCase.java b/x-pack/plugin/sql/qa/security/src/test/java/org/elasticsearch/xpack/sql/qa/security/SqlSecurityTestCase.java index 94f6952bd6d8e..3f024cf6e0bb5 100644 --- a/x-pack/plugin/sql/qa/security/src/test/java/org/elasticsearch/xpack/sql/qa/security/SqlSecurityTestCase.java +++ b/x-pack/plugin/sql/qa/security/src/test/java/org/elasticsearch/xpack/sql/qa/security/SqlSecurityTestCase.java @@ -84,6 +84,7 @@ protected interface Actions { * {@code plugin-security.policy}. So we may as well have gradle set the property. */ private static final Path AUDIT_LOG_FILE = lookupAuditLog(); + private static final Path ROLLED_OVER_AUDIT_LOG_FILE = lookupRolledOverAuditLog(); @SuppressForbidden(reason="security doesn't work with mock filesystem") private static Path lookupAuditLog() { @@ -95,6 +96,16 @@ private static Path lookupAuditLog() { } return Paths.get(auditLogFileString); } + + @SuppressForbidden(reason="security doesn't work with mock filesystem") + private static Path lookupRolledOverAuditLog() { + String auditLogFileString = System.getProperty("tests.audit.yesterday.logfile"); + if (null == auditLogFileString) { + throw new IllegalStateException("tests.audit.yesterday.logfile must be set to run this test. It should be automatically " + + "set by gradle."); + } + return Paths.get(auditLogFileString); + } private static boolean oneTimeSetup = false; private static boolean auditFailure = false; @@ -107,7 +118,12 @@ private static Path lookupAuditLog() { /** * How much of the audit log was written before the test started. */ - private long auditLogWrittenBeforeTestStart; + private static long auditLogWrittenBeforeTestStart; + + /** + * If the audit log file rolled over. This is a rare case possible only at midnight. + */ + private static boolean auditFileRolledOver = false; public SqlSecurityTestCase(Actions actions) { this.actions = actions; @@ -164,7 +180,7 @@ public void setInitialAuditLogOffset() { return null; } if (false == Files.isRegularFile(AUDIT_LOG_FILE)) { - throw new IllegalStateException("expected tests.audit.logfile [" + AUDIT_LOG_FILE + "]to be a plain file but wasn't"); + throw new IllegalStateException("expected tests.audit.logfile [" + AUDIT_LOG_FILE + "] to be a plain file but wasn't"); } try { auditLogWrittenBeforeTestStart = Files.size(AUDIT_LOG_FILE); @@ -556,51 +572,85 @@ public void assertLogs() throws Exception { if (sm != null) { sm.checkPermission(new SpecialPermission()); } - BufferedReader logReader = AccessController.doPrivileged((PrivilegedAction) () -> { + + BufferedReader[] logReaders = new BufferedReader[2]; + AccessController.doPrivileged((PrivilegedAction) () -> { try { - return Files.newBufferedReader(AUDIT_LOG_FILE, StandardCharsets.UTF_8); + // the audit log file rolled over during the test + // and we need to consume the rest of the rolled over file plus the new audit log file + if (auditFileRolledOver == false && Files.exists(ROLLED_OVER_AUDIT_LOG_FILE)) { + // once the audit file rolled over, it will stay like this + auditFileRolledOver = true; + // the order in the array matters, as the readers will be used in that order + logReaders[0] = Files.newBufferedReader(ROLLED_OVER_AUDIT_LOG_FILE, StandardCharsets.UTF_8); + } + logReaders[1] = Files.newBufferedReader(AUDIT_LOG_FILE, StandardCharsets.UTF_8); + return null; } catch (IOException e) { throw new RuntimeException(e); } }); - logReader.skip(auditLogWrittenBeforeTestStart); + + // The "index" is used as a way of reading from both rolled over file and current audit file in order: rolled over file + // first, then the audit log file. Very rarely we will read from the rolled over file: when the test happened to run + // at midnight and the audit file rolled over during the test. + int index; + if (logReaders[0] != null) { + logReaders[0].skip(auditLogWrittenBeforeTestStart); + // start with the rolled over file first + index = 0; + } else { + // the current audit log file reader should always be non-null + logReaders[1].skip(auditLogWrittenBeforeTestStart); + // start with the current audit logging file + index = 1; + } List> logs = new ArrayList<>(); String line; - while ((line = logReader.readLine()) != null) { - try { - final Map log = XContentHelper.convertToMap(JsonXContent.jsonXContent, line, false); - if (false == ("access_denied".equals(log.get("event.action")) - || "access_granted".equals(log.get("event.action")))) { - continue; - } - assertThat(log.containsKey("action"), is(true)); - if (false == (SQL_ACTION_NAME.equals(log.get("action")) - || GetIndexAction.NAME.equals(log.get("action")) - || FieldCapabilitiesAction.NAME.equals(log.get("action")))) { - // TODO we may want to extend this and the assertions to SearchAction.NAME as well - continue; + while (index < 2) { + line = logReaders[index].readLine(); + // when the end of the file is reached, either stop or move to the next reader + if (line == null) { + if (++index == 2) { + break; } - assertThat(log.containsKey("user.name"), is(true)); - List indices = new ArrayList<>(); - if (log.containsKey("indices")) { - indices = (ArrayList) log.get("indices"); - if ("test_admin".equals(log.get("user.name"))) { - /* - * Sometimes we accidentally sneak access to the security tables. This is fine, - * SQL drops them from the interface. So we might have access to them, but we - * don't show them. - */ - indices.remove(".security"); - indices.remove(".security-6"); + } + else { + try { + final Map log = XContentHelper.convertToMap(JsonXContent.jsonXContent, line, false); + if (false == ("access_denied".equals(log.get("event.action")) + || "access_granted".equals(log.get("event.action")))) { + continue; + } + assertThat(log.containsKey("action"), is(true)); + if (false == (SQL_ACTION_NAME.equals(log.get("action")) + || GetIndexAction.NAME.equals(log.get("action")) + || FieldCapabilitiesAction.NAME.equals(log.get("action")))) { + // TODO we may want to extend this and the assertions to SearchAction.NAME as well + continue; + } + assertThat(log.containsKey("user.name"), is(true)); + List indices = new ArrayList<>(); + if (log.containsKey("indices")) { + indices = (ArrayList) log.get("indices"); + if ("test_admin".equals(log.get("user.name"))) { + /* + * Sometimes we accidentally sneak access to the security tables. This is fine, + * SQL drops them from the interface. So we might have access to them, but we + * don't show them. + */ + indices.remove(".security"); + indices.remove(".security-6"); + } } + // Use a sorted list for indices for consistent error reporting + Collections.sort(indices); + log.put("indices", indices); + logs.add(log); + } catch (final ElasticsearchParseException e) { + throw new IllegalArgumentException("Unrecognized log: " + line, e); } - // Use a sorted list for indices for consistent error reporting - Collections.sort(indices); - log.put("indices", indices); - logs.add(log); - } catch (final ElasticsearchParseException e) { - throw new IllegalArgumentException("Unrecognized log: " + line, e); } } List> allLogs = new ArrayList<>(logs); diff --git a/x-pack/plugin/sql/qa/security/src/test/resources/plugin-security.policy b/x-pack/plugin/sql/qa/security/src/test/resources/plugin-security.policy index d013547b9fd5f..434fdee0a8d20 100644 --- a/x-pack/plugin/sql/qa/security/src/test/resources/plugin-security.policy +++ b/x-pack/plugin/sql/qa/security/src/test/resources/plugin-security.policy @@ -1,6 +1,7 @@ grant { // Needed to read the audit log file permission java.io.FilePermission "${tests.audit.logfile}", "read"; + permission java.io.FilePermission "${tests.audit.yesterday.logfile}", "read"; //// Required by ssl subproject: // Required for the net client to setup ssl rather than use global ssl.