Regression tests: audit log compare support and test cases

Author: martinhsv

CHANGES

@@ -1,6 +1,8 @@
 v3.x.y - YYYY-MMM-DD (to be released)
 -------------------------------------
 
+  - Add support to test framework for audit log content verification
+    and add regression tests for issues #2000, #2196
   - Multipart Content-Dispostion should allow field: filename*=
     [@martinhsv]
   - Fix rule-update-target for non-regex

Makefile.am

@@ -155,7 +155,9 @@ TESTS+=test/test-cases/regression/issue-1943.json
 TESTS+=test/test-cases/regression/issue-1956.json
 TESTS+=test/test-cases/regression/issue-1960.json
 TESTS+=test/test-cases/regression/issue-2099.json
+TESTS+=test/test-cases/regression/issue-2000.json
 TESTS+=test/test-cases/regression/issue-2111.json
+TESTS+=test/test-cases/regression/issue-2196.json
 TESTS+=test/test-cases/regression/issue-394.json
 TESTS+=test/test-cases/regression/issue-849.json
 TESTS+=test/test-cases/regression/issue-960.json

test/regression/regression.cc

@@ -58,6 +58,30 @@ bool contains(const std::string &s, const std::string &pattern) {
     return ret;
 }
 
+void clearAuditLog(const std::string &filename) {
+    if (!filename.empty()) {
+        std::ifstream file;
+        file.open(filename.c_str(), std::ifstream::out | std::ifstream::trunc);
+        if (!file.is_open() || file.fail()) {
+            std::cout << std::endl << "Failed to clear previous contents of audit log: " \
+                << filename << std::endl;
+        }
+        file.close();
+    }
+}
+std::string getAuditLogContent(const std::string &filename) {
+    std::stringstream buffer;
+    if (!filename.empty()) {
+        try {
+           std::ifstream t(filename);
+           buffer << t.rdbuf();
+        } catch (...) {
+            std::cout << "Failed to read file:" << filename << std::endl;
+        }
+    }
+    return buffer.str();
+}
+
 
 void actions(ModSecurityTestResults<RegressionTest> *r,
     modsecurity::Transaction *a, std::stringstream *serverLog) {
@@ -278,6 +302,8 @@ void perform_unit_test(ModSecurityTest<RegressionTest> *test,
         modsec_transaction = new modsecurity::Transaction(modsec, modsec_rules,
             &serverLog);
 
+        clearAuditLog(modsec_transaction->m_rules->m_auditLog->m_path1);
+
         modsec_transaction->processConnection(t->clientIp.c_str(),
             t->clientPort, t->serverIp.c_str(), t->serverPort);
 
@@ -393,6 +419,19 @@ void perform_unit_test(ModSecurityTest<RegressionTest> *test,
                 testRes->reason << KWHT << "Expecting: " << RESET \
                     << t->error_log + "";
                 testRes->passed = false;
+            } else if (!t->audit_log.empty()
+                && !contains(getAuditLogContent(modsec_transaction->m_rules->m_auditLog->m_path1), t->audit_log)) {
+                if (test->m_automake_output) {
+                    std::cout << ":test-result: FAIL " << filename \
+                        << ":" << t->name << std::endl;
+                } else {
+                    std::cout << KRED << "failed!" << RESET << std::endl;
+                }
+                testRes->reason << "Audit log was not matching the " \
+                    << "expected results." << std::endl;
+                testRes->reason << KWHT << "Expecting: " << RESET \
+                    << t->audit_log + "";
+                testRes->passed = false;
             } else {
                 if (test->m_automake_output) {
                     std::cout << ":test-result: PASS " << filename \
@@ -410,6 +449,8 @@ void perform_unit_test(ModSecurityTest<RegressionTest> *test,
                 testRes->reason << d->log_messages() << std::endl;
                 testRes->reason << KWHT << "Error log:" << RESET << std::endl;
                 testRes->reason << serverLog.str() << std::endl;
+                testRes->reason << KWHT << "Audit log:" << RESET << std::endl;
+                testRes->reason << getAuditLogContent(modsec_transaction->m_rules->m_auditLog->m_path1) << std::endl;
             }
         }
 

test/regression/regression_test.cc

@@ -180,7 +180,7 @@ RegressionTest *RegressionTest::from_yajl_node(const yajl_val &node) {
                 yajl_val val2 = val->u.object.values[j];
 
                 if (strcmp(key2, "audit_log") == 0) {
-                    u->audit_log = yajl_array_to_str(val2);
+                    u->audit_log = YAJL_GET_STRING(val2);
                 }
                 if (strcmp(key2, "debug_log") == 0) {
                     u->debug_log = YAJL_GET_STRING(val2);

test/test-cases/regression/issue-2000.json

@@ -0,0 +1,45 @@
+[
+  {
+    "enabled":1,
+    "version_min":300000,
+    "title":"Testing audit log part H should output when deny - issue-2000",
+    "expected":{
+      "http_code":200
+    },
+    "client":{
+      "ip":"127.0.0.1",
+      "port":123
+    },
+    "request":{
+      "headers":{
+        "Host":"localhost",
+        "User-Agent":"curl/7.38.0",
+        "Accept":"*/*"
+      },
+      "uri":"index.php?foo=bar&a=xxx",
+      "method":"GET",
+      "body": ""
+    },
+    "expected": {
+      "http_code": 403,
+      "audit_log": "id \"1234"
+    },
+
+    "server":{
+      "ip":"127.0.0.1",
+      "port":80
+    },
+    "rules":[
+      "SecRuleEngine On",
+      "SecAuditLogParts ABIJDEFHZ",
+      "SecAuditEngine RelevantOnly",
+      "SecAuditLogParts ABCFHZ",
+      "SecAuditLog /tmp/test/modsec_audit.log",
+      "SecAuditLogDirMode 0766",
+      "SecAuditLogFileMode 0666",
+      "SecAuditLogType Serial",
+      "SecAuditLogRelevantStatus \"^(?:5|4(?!04))\"",
+      "SecRule ARGS:foo \"@rx ^bar$\" \"id:1234,phase:1,deny,status:403\""
+    ]
+  }
+]

test/test-cases/regression/issue-2196.json

@@ -0,0 +1,45 @@
+[
+  {
+    "enabled":1,
+    "version_min":300000,
+    "title":"Testing audit log not written when nolog - issue-2196",
+    "expected":{
+      "http_code":200
+    },
+    "client":{
+      "ip":"127.0.0.1",
+      "port":123
+    },
+    "request":{
+      "headers":{
+        "Host":"localhost",
+        "User-Agent":"curl/7.38.0",
+        "Accept":"*/*"
+      },
+      "uri":"index.php?foo=bar&a=xxx",
+      "method":"GET",
+      "body": ""
+    },
+    "expected": {
+      "http_code": 200,
+      "audit_log": "\\A[\\s\\S]{0}\\z"
+    },
+
+    "server":{
+      "ip":"127.0.0.1",
+      "port":80
+    },
+    "rules":[
+      "SecRuleEngine On",
+      "SecAuditLogParts ABIJDEFHZ",
+      "SecAuditEngine RelevantOnly",
+      "SecAuditLogParts ABCFHZ",
+      "SecAuditLog /tmp/test/modsec_audit.log",
+      "SecAuditLogDirMode 0766",
+      "SecAuditLogFileMode 0666",
+      "SecAuditLogType Serial",
+      "SecAuditLogRelevantStatus \"^(?:5|4(?!04))\"",
+      "SecRule ARGS:foo \"@rx ^bar$\" \"id:1234,phase:1,nolog,pass\""
+    ]
+  }
+]