From 3a048ee2dbb1078f23404f886945b760a27c68aa Mon Sep 17 00:00:00 2001 From: michaelgranzow-avi Date: Thu, 3 Aug 2017 19:50:43 +0200 Subject: [PATCH] Support --enable-debug-logs=no option of configure script (#2) * Support --enable-debug-logs=no option of configure script * Undo unintended white space changes * Undo more unintended white space changes * Address review comments - thanks Mirko * Address more review comments - thanks Mirko --- src/actions/ctl/rule_engine.cc | 2 + src/actions/disruptive/allow.cc | 2 + src/actions/disruptive/block.cc | 2 + src/actions/disruptive/pass.cc | 2 + src/actions/init_col.cc | 2 + src/actions/log.cc | 2 + src/actions/msg.cc | 2 + src/audit_log/audit_log.cc | 8 ++ src/audit_log/writer/https.cc | 2 + src/macro_expansion.cc | 2 + src/operators/pm.cc | 2 + src/operators/rx.cc | 2 + src/operators/validate_dtd.cc | 12 ++ src/operators/validate_dtd.h | 4 + src/operators/validate_schema.cc | 18 ++- src/operators/validate_schema.h | 4 + src/request_body_processor/json.cc | 12 ++ src/request_body_processor/multipart.cc | 141 +++++++++++++++++++++++- src/request_body_processor/xml.cc | 10 ++ src/rule.cc | 54 +++++++++ src/transaction.cc | 14 +++ src/variables/xml.cc | 10 ++ 22 files changed, 305 insertions(+), 4 deletions(-) diff --git a/src/actions/ctl/rule_engine.cc b/src/actions/ctl/rule_engine.cc index d06295d5..8e1d0d81 100644 --- a/src/actions/ctl/rule_engine.cc +++ b/src/actions/ctl/rule_engine.cc @@ -50,7 +50,9 @@ bool RuleEngine::evaluate(Rule *rule, Transaction *transaction) { a << modsecurity::RulesProperties::ruleEngineStateString(m_ruleEngine); a << " as requested by a ctl:ruleEngine action"; +#ifndef NO_LOGS transaction->debug(8, a.str()); +#endif transaction->m_secRuleEngine = m_ruleEngine; return true; diff --git a/src/actions/disruptive/allow.cc b/src/actions/disruptive/allow.cc index 99580084..c88f3870 100644 --- a/src/actions/disruptive/allow.cc +++ b/src/actions/disruptive/allow.cc @@ -49,9 +49,11 @@ bool Allow::init(std::string *error) { bool Allow::evaluate(Rule *rule, Transaction *transaction) { +#ifndef NO_LOGS transaction->debug(4, "Dropping the evaluation of upcoming rules " \ "in favor of an `allow' action of type: " \ + allowTypeToName(m_allowType)); +#endif transaction->m_allowType = m_allowType; diff --git a/src/actions/disruptive/block.cc b/src/actions/disruptive/block.cc index 632f5cee..787c390c 100644 --- a/src/actions/disruptive/block.cc +++ b/src/actions/disruptive/block.cc @@ -32,7 +32,9 @@ namespace disruptive { bool Block::evaluate(Rule *rule, Transaction *transaction, std::shared_ptr rm) { +#ifndef NO_LOGS transaction->debug(8, "Marking request as disruptive."); +#endif for (Action *a : transaction->m_rules->m_defaultActions[rule->m_phase]) { if (a->isDisruptive() == false) { diff --git a/src/actions/disruptive/pass.cc b/src/actions/disruptive/pass.cc index d10b9b1a..d4e6501d 100644 --- a/src/actions/disruptive/pass.cc +++ b/src/actions/disruptive/pass.cc @@ -33,7 +33,9 @@ bool Pass::evaluate(Rule *rule, Transaction *transaction, intervention::free(&transaction->m_it); intervention::reset(&transaction->m_it); +#ifndef NO_LOGS transaction->debug(8, "Running action pass"); +#endif return true; } diff --git a/src/actions/init_col.cc b/src/actions/init_col.cc index da22b5ed..903bb133 100644 --- a/src/actions/init_col.cc +++ b/src/actions/init_col.cc @@ -71,8 +71,10 @@ bool InitCol::evaluate(Rule *rule, Transaction *t) { return false; } +#ifndef NO_LOGS t->debug(5, "Collection `" + m_collection_key + "' initialized with " \ "value: " + collectionName); +#endif return true; } diff --git a/src/actions/log.cc b/src/actions/log.cc index 48f00ac5..66006c13 100644 --- a/src/actions/log.cc +++ b/src/actions/log.cc @@ -30,7 +30,9 @@ namespace actions { bool Log::evaluate(Rule *rule, Transaction *transaction, std::shared_ptr rm) { +#ifndef NO_LOGS transaction->debug(9, "Saving transaction to logs"); +#endif rm->m_saveMessage = true; return true; } diff --git a/src/actions/msg.cc b/src/actions/msg.cc index 938f7a55..14d89ab1 100644 --- a/src/actions/msg.cc +++ b/src/actions/msg.cc @@ -51,7 +51,9 @@ bool Msg::evaluate(Rule *rule, Transaction *transaction, std::shared_ptr rm) { std::string msg = data(transaction); rm->m_message = msg; +#ifndef NO_LOGS transaction->debug(9, "Saving msg: " + msg); +#endif transaction->m_collections.storeOrUpdateFirst("RULE:msg", msg); diff --git a/src/audit_log/audit_log.cc b/src/audit_log/audit_log.cc index 9fcc5c7b..61447655 100644 --- a/src/audit_log/audit_log.cc +++ b/src/audit_log/audit_log.cc @@ -282,10 +282,12 @@ bool AuditLog::saveIfRelevant(Transaction *transaction, int parts) { if ((m_status == RelevantOnlyAuditLogStatus && this->isRelevant(transaction->m_httpCodeReturned) == false) && saveAnyway == false) { +#ifndef NO_LOGS transaction->debug(9, "Return code `" + std::to_string(transaction->m_httpCodeReturned) + "'" \ " is not interesting to audit logs, relevant code(s): `" + m_relevant + "'."); +#endif return false; } @@ -293,15 +295,21 @@ bool AuditLog::saveIfRelevant(Transaction *transaction, int parts) { if (parts == -1) { parts = m_parts; } +#ifndef NO_LOGS transaction->debug(5, "Saving this request as part " \ "of the audit logs."); +#endif if (m_writer == NULL) { +#ifndef NO_LOGS transaction->debug(1, "Internal error, audit log writer is null"); +#endif } else { std::string error; bool a = m_writer->write(transaction, parts, &error); if (a == false) { +#ifndef NO_LOGS transaction->debug(1, "Cannot save the audit log: " + error); +#endif return false; } } diff --git a/src/audit_log/writer/https.cc b/src/audit_log/writer/https.cc index 7ceda404..7602cd60 100644 --- a/src/audit_log/writer/https.cc +++ b/src/audit_log/writer/https.cc @@ -47,7 +47,9 @@ bool Https::init(std::string *error) { bool Https::write(Transaction *transaction, int parts, std::string *error) { Utils::HttpsClient m_http_client; +#ifndef NO_LOGS transaction->debug(7, "Sending logs to: " + m_audit->m_path1); +#endif std::string log = transaction->toJSON(parts); m_http_client.setRequestType("application/json"); diff --git a/src/macro_expansion.cc b/src/macro_expansion.cc index 22e77d8e..264816ce 100644 --- a/src/macro_expansion.cc +++ b/src/macro_expansion.cc @@ -301,12 +301,14 @@ std::string MacroExpansion::expand(const std::string& input, } } +#ifndef NO_LOGS if (variableValue) { transaction->debug(6, "Resolving: " + variable + " to: " + *variableValue); } else { transaction->debug(6, "Resolving: " + variable + " to: NULL"); } +#endif res.erase(start, end - start + 1); if (res[start] == '%') { res.erase(start, 1); diff --git a/src/operators/pm.cc b/src/operators/pm.cc index 08e89d98..3b52e053 100644 --- a/src/operators/pm.cc +++ b/src/operators/pm.cc @@ -99,8 +99,10 @@ bool Pm::evaluate(Transaction *transaction, Rule *rule, if (capture && transaction && rc) { transaction->m_collections.storeOrUpdateFirst("TX", "0", std::string(match)); +#ifndef NO_LOGS transaction->debug(7, "Added pm match TX.0: " + \ std::string(match)); +#endif } return rc > 0; diff --git a/src/operators/rx.cc b/src/operators/rx.cc index 9ed07cb9..8be06a39 100644 --- a/src/operators/rx.cc +++ b/src/operators/rx.cc @@ -45,8 +45,10 @@ bool Rx::evaluate(Transaction *transaction, Rule *rule, for (const SMatch& a : matches) { transaction->m_collections.storeOrUpdateFirst("TX", std::to_string(i), a.match); +#ifndef NO_LOGS transaction->debug(7, "Added regex subexpression TX." + std::to_string(i) + ": " + a.match); +#endif transaction->m_matched.push_back(a.match); i++; } diff --git a/src/operators/validate_dtd.cc b/src/operators/validate_dtd.cc index 7f74370f..bb3e05c4 100644 --- a/src/operators/validate_dtd.cc +++ b/src/operators/validate_dtd.cc @@ -50,19 +50,25 @@ bool ValidateDTD::evaluate(Transaction *t, const std::string &str) { if (m_dtd == NULL) { std::string err = std::string("XML: Failed to load DTD: ") \ + m_resource; +#ifndef NO_LOGS t->debug(4, err); +#endif return true; } if (t->m_xml->m_data.doc == NULL) { +#ifndef NO_LOGS t->debug(4, "XML document tree could not "\ "be found for DTD validation."); +#endif return true; } if (t->m_xml->m_data.well_formed != 1) { +#ifndef NO_LOGS t->debug(4, "XML: DTD validation failed because " \ "content is not well formed."); +#endif return true; } @@ -78,7 +84,9 @@ bool ValidateDTD::evaluate(Transaction *t, const std::string &str) { cvp = xmlNewValidCtxt(); if (cvp == NULL) { +#ifndef NO_LOGS t->debug(4, "XML: Failed to create a validation context."); +#endif return true; } @@ -88,13 +96,17 @@ bool ValidateDTD::evaluate(Transaction *t, const std::string &str) { cvp->userData = t; if (!xmlValidateDtd(cvp, t->m_xml->m_data.doc, m_dtd)) { +#ifndef NO_LOGS t->debug(4, "XML: DTD validation failed."); +#endif xmlFreeValidCtxt(cvp); return true; } +#ifndef NO_LOGS t->debug(4, std::string("XML: Successfully validated " \ "payload against DTD: ") + m_resource); +#endif xmlFreeValidCtxt(cvp); diff --git a/src/operators/validate_dtd.h b/src/operators/validate_dtd.h index 371ac4d5..39fb64d2 100644 --- a/src/operators/validate_dtd.h +++ b/src/operators/validate_dtd.h @@ -62,7 +62,9 @@ class ValidateDTD : public Operator { if (len > 0) { s = "XML Error: " + std::string(buf); } +#ifndef NO_LOGS t->debug(4, s); +#endif } @@ -79,7 +81,9 @@ class ValidateDTD : public Operator { if (len > 0) { s = "XML Warning: " + std::string(buf); } +#ifndef NO_LOGS t->debug(4, s); +#endif } diff --git a/src/operators/validate_schema.cc b/src/operators/validate_schema.cc index 7abc128d..44063a65 100644 --- a/src/operators/validate_schema.cc +++ b/src/operators/validate_schema.cc @@ -50,7 +50,9 @@ bool ValidateSchema::evaluate(Transaction *t, if (m_err.empty() == false) { err << m_err; } +#ifndef NO_LOGS t->debug(4, err.str()); +#endif return true; } @@ -73,7 +75,9 @@ bool ValidateSchema::evaluate(Transaction *t, if (m_err.empty() == false) { err << " " << m_err; } +#ifndef NO_LOGS t->debug(4, err.str()); +#endif xmlSchemaFreeParserCtxt(m_parserCtx); return true; } @@ -84,7 +88,9 @@ bool ValidateSchema::evaluate(Transaction *t, if (m_err.empty() == false) { err << " " << m_err; } +#ifndef NO_LOGS t->debug(4, err.str()); +#endif return true; } @@ -94,36 +100,46 @@ bool ValidateSchema::evaluate(Transaction *t, (xmlSchemaValidityWarningFunc)warn_runtime, t); if (t->m_xml->m_data.doc == NULL) { +#ifndef NO_LOGS t->debug(4, "XML document tree could not be found for " \ "schema validation."); +#endif return true; } if (t->m_xml->m_data.well_formed != 1) { +#ifndef NO_LOGS t->debug(4, "XML: Schema validation failed because " \ "content is not well formed."); +#endif return true; } /* Make sure there were no other generic processing errors */ /* if (msr->msc_reqbody_error) { +#ifndef NO_LOGS t->debug(4, "XML: Schema validation could not proceed due to previous" " processing errors."); +#endif return true; } */ rc = xmlSchemaValidateDoc(m_validCtx, t->m_xml->m_data.doc); if (rc != 0) { - t->debug(4, "XML: Schema validation failed."); +#ifndef NO_LOGS + t->debug(4, "XML: Schema validation failed."); +#endif xmlSchemaFree(m_schema); xmlSchemaFreeParserCtxt(m_parserCtx); return true; /* No match. */ } +#ifndef NO_LOGS t->debug(4, "XML: Successfully validated payload against " \ "Schema: " + m_resource); +#endif return false; } diff --git a/src/operators/validate_schema.h b/src/operators/validate_schema.h index 7548b624..72df051f 100644 --- a/src/operators/validate_schema.h +++ b/src/operators/validate_schema.h @@ -103,7 +103,9 @@ class ValidateSchema : public Operator { if (len > 0) { s = "XML Error: " + std::string(buf); } +#ifndef NO_LOGS t->debug(4, s); +#endif } @@ -120,7 +122,9 @@ class ValidateSchema : public Operator { if (len > 0) { s = "XML Warning: " + std::string(buf); } +#ifndef NO_LOGS t->debug(4, s); +#endif } static void null_error(void *ctx, const char *msg, ...) { diff --git a/src/request_body_processor/json.cc b/src/request_body_processor/json.cc index 5597e5a1..93b739d3 100644 --- a/src/request_body_processor/json.cc +++ b/src/request_body_processor/json.cc @@ -48,7 +48,9 @@ int JSON::yajl_map_key(void *ctx, const unsigned char *key, size_t length) { */ safe_key.assign((const char *)key, length); +#ifndef NO_LOGS tthis->debug(9, "New JSON hash key '" + safe_key + "'"); +#endif /** * TODO: How do we free the previously string value stored here? @@ -128,8 +130,10 @@ int JSON::yajl_start_map(void *ctx) { tthis->m_data.prefix.assign(tthis->m_data.current_key); } +#ifndef NO_LOGS tthis->debug(9, "New JSON hash context (prefix '" + \ tthis->m_data.prefix + "')"); +#endif return 1; } @@ -176,7 +180,9 @@ int JSON::addArgument(const std::string& value) { * to reference this argument; for now we simply ignore these */ if (m_data.current_key.empty()) { +#ifndef NO_LOGS debug(3, "Cannot add scalar value without an associated key"); +#endif return 1; } @@ -245,7 +251,9 @@ JSON::JSON(Transaction *transaction) : m_transaction(transaction) { }; +#ifndef NO_LOGS debug(9, "JSON parser initialization"); +#endif /** * Prefix and current key are initially empty @@ -261,7 +269,9 @@ JSON::JSON(Transaction *transaction) : m_transaction(transaction) { * * TODO: make UTF8 validation optional, as it depends on Content-Encoding */ +#ifndef NO_LOGS debug(9, "yajl JSON parsing callback initialization"); +#endif m_data.handle = yajl_alloc(&callbacks, NULL, this); yajl_config(m_data.handle, yajl_allow_partial_values, 0); @@ -269,7 +279,9 @@ JSON::JSON(Transaction *transaction) : m_transaction(transaction) { JSON::~JSON() { +#ifndef NO_LOGS debug(9, "JSON: Cleaning up JSON results"); +#endif yajl_free(m_data.handle); } diff --git a/src/request_body_processor/multipart.cc b/src/request_body_processor/multipart.cc index 5cc5968d..5b316487 100644 --- a/src/request_body_processor/multipart.cc +++ b/src/request_body_processor/multipart.cc @@ -69,10 +69,12 @@ Multipart::Multipart(std:: string header, Transaction *transaction) Multipart::~Multipart() { +#ifndef NO_LOGS debug(4, "Multipart: Cleanup started (remove files " \ + RulesProperties::configBooleanString( m_transaction->m_rules->m_uploadKeepFiles) \ + ")"); +#endif if (m_transaction->m_rules->m_uploadKeepFiles != RulesProperties::TrueConfigBoolean) { @@ -84,8 +86,12 @@ Multipart::~Multipart() { close(m->m_tmp_file_fd); m->m_tmp_file_fd = -1; } - - if (unlink(m->m_tmp_file_name.c_str()) < 0) { +#ifndef NO_LOGS + const int unlink_rc = +#endif + unlink(m->m_tmp_file_name.c_str()); +#ifndef NO_LOGS + if (unlink_rc < 0) { debug(1, "Multipart: Failed to delete file (part) \"" \ + m->m_tmp_file_name + "\" because " \ + std::to_string(errno) + "(" \ @@ -94,6 +100,7 @@ Multipart::~Multipart() { debug(4, "Multipart: Failed to delete file (part) \"" \ + m->m_tmp_file_name + "\""); } +#endif } } } @@ -204,9 +211,11 @@ void Multipart::validate_quotes(const char *data) { for (i = 0; i < len; i++) { if (data[i] == '\'') { +#ifndef NO_LOGS debug(9, "Multipart: Invalid quoting detected: " \ + std::string(data) + " length " \ + std::to_string(len) + " bytes"); +#endif m_flag_invalid_quoting = 1; } } @@ -347,28 +356,36 @@ int Multipart::parse_content_disposition(const char *c_d_value, int offset) { offset + ((p - c_d_value) - value.size())); if (!m_mpp->m_name.empty()) { +#ifndef NO_LOGS debug(4, "Multipart: Warning: Duplicate Content-Disposition " \ "name: " + value + ". Previously: " + m_mpp->m_name + ""); +#endif return -14; } m_mpp->m_name.assign(value); m_mpp->m_nameOffset = offset + ((p - c_d_value) - value.size()); +#ifndef NO_LOGS debug(9, "Multipart: Content-Disposition name: " + value + "."); +#endif } else if (name == "filename") { validate_quotes(value.c_str()); m_transaction->m_variableMultiPartFileName.set(value, value, \ offset + ((p - c_d_value) - value.size())); if (!m_mpp->m_filename.empty()) { +#ifndef NO_LOGS debug(4, "Multipart: Warning: Duplicate Content-Disposition " \ "filename: " + value + "."); +#endif return -15; } m_mpp->m_filename.assign(value); m_mpp->m_filenameOffset = offset + ((p - c_d_value) - value.size()); +#ifndef NO_LOGS debug(9, "Multipart: Content-Disposition filename: " \ + value + "."); +#endif } else { return -11; } @@ -385,9 +402,11 @@ int Multipart::parse_content_disposition(const char *c_d_value, int offset) { if (*p != ';') { p--; if (*p == '\'' || *p == '\"') { +#ifndef NO_LOGS debug(9, "Multipart: Invalid quoting detected: " \ + std::string(p) + " length " \ + std::to_string(strlen(p)) + " bytes"); +#endif m_flag_invalid_quoting = 1; } p++; @@ -478,10 +497,12 @@ int Multipart::process_part_data(std::string *error, size_t offset) { && (m_nfiles >= m_transaction->m_rules->m_uploadFileLimit.m_value)) { if (m_flag_file_limit_exceeded == 0) { - debug(1, "Multipart: Upload file limit exceeded " \ +#ifndef NO_LOGS + debug(1, "Multipart: Upload file limit exceeded " \ + std::to_string( m_transaction->m_rules->m_uploadFileLimit.m_value) \ + ". Use SecUploadFileLimit to change the limit."); +#endif error->assign("Multipart: Upload file limit exceeded " \ + std::to_string( m_transaction->m_rules->m_uploadFileLimit.m_value) \ @@ -504,8 +525,10 @@ int Multipart::process_part_data(std::string *error, size_t offset) { /* do we have an opened file? */ if (m_mpp->m_tmp_file_fd < 0) { +#ifndef NO_LOGS debug(1, "Multipart: Failed to create file: " \ + m_mpp->m_tmp_file_name); +#endif error->assign("Multipart: Failed to create file: " \ + m_mpp->m_tmp_file_name); return -1; @@ -514,17 +537,21 @@ int Multipart::process_part_data(std::string *error, size_t offset) { m_nfiles++; +#ifndef NO_LOGS debug(4, "Multipart: Created temporary file " \ + std::to_string(m_nfiles) + " (mode 04o): " \ + m_mpp->m_tmp_file_name); +#endif } /* write the reserve first */ if (m_reserve[0] != 0) { if (write(m_mpp->m_tmp_file_fd, &m_reserve[1], m_reserve[0]) != m_reserve[0]) { +#ifndef NO_LOGS debug(1, "Multipart: writing to \"" \ + m_mpp->m_tmp_file_name + "\" failed"); +#endif error->assign("Multipart: writing to \"" \ + m_mpp->m_tmp_file_name + "\" failed"); return -1; @@ -543,8 +570,10 @@ int Multipart::process_part_data(std::string *error, size_t offset) { if (write(m_mpp->m_tmp_file_fd, m_buf, MULTIPART_BUF_SIZE - m_bufleft) != (MULTIPART_BUF_SIZE - m_bufleft)) { +#ifndef NO_LOGS debug(1, "Multipart: writing to \"" \ + m_mpp->m_tmp_file_name + "\" failed"); +#endif error->assign("Multipart: writing to \"" \ + m_mpp->m_tmp_file_name + "\" failed"); return -1; @@ -598,10 +627,14 @@ int Multipart::process_part_data(std::string *error, size_t offset) { m_mpp->m_value_parts.push_back(std::make_pair(d, m_buf_offset)); +#ifndef NO_LOGS debug(9, "Multipart: Added data to variable: " + d); +#endif } else { +#ifndef NO_LOGS debug(1, "Multipart: unknown part type: " \ + std::to_string(m_mpp->m_type)); +#endif error->assign("Multipart: unknown part type: " \ + std::to_string(m_mpp->m_type)); return false; @@ -631,7 +664,9 @@ int Multipart::process_part_header(std::string *error, int offset) { len = MULTIPART_BUF_SIZE - m_bufleft; for (i = 0; i < len; i++) { if (m_buf[i] == '\0') { +#ifndef NO_LOGS debug(1, "Multipart: Nul byte in part headers."); +#endif error->assign("Multipart: Nul byte in part headers."); return false; } @@ -658,7 +693,9 @@ int Multipart::process_part_header(std::string *error, int offset) { int rc; if (m_mpp->m_headers.count("Content-Disposition") == 0) { +#ifndef NO_LOGS debug(1, "Multipart: Part missing Content-Disposition header."); +#endif error->assign("Multipart: Part missing " \ "Content-Disposition header."); return false; @@ -668,16 +705,20 @@ int Multipart::process_part_header(std::string *error, int offset) { rc = parse_content_disposition(header_value.c_str(), m_mpp->m_headers.at("Content-Disposition").first); if (rc < 0) { +#ifndef NO_LOGS debug(1, "Multipart: Invalid Content-Disposition header (" + std::to_string(rc) + "): " + header_value); +#endif error->assign("Multipart: Invalid Content-Disposition header (" + std::to_string(rc) + "): " + header_value); return false; } if (m_mpp->m_name.empty()) { +#ifndef NO_LOGS debug(1, "Multipart: Content-Disposition header missing " \ "name field."); +#endif error->assign("Multipart: Content-Disposition header missing " \ "name field."); @@ -690,8 +731,10 @@ int Multipart::process_part_header(std::string *error, int offset) { * didn't understand C-D but we did. */ if (strstr(header_value.c_str(), "filename=") == NULL) { +#ifndef NO_LOGS debug(1, "Multipart: Invalid Content-Disposition " \ "header (filename)."); +#endif error->assign("Multipart: Invalid Content-Disposition " \ "header (filename)."); return false; @@ -723,7 +766,9 @@ int Multipart::process_part_header(std::string *error, int offset) { if (m_mpp->m_last_header_name.empty()) { /* we are not building a header at this moment */ +#ifndef NO_LOGS debug(1, "Multipart: Invalid part header (folding error)."); +#endif error->assign("Multipart: Invalid part header " \ "(folding error)."); return false; @@ -751,12 +796,16 @@ int Multipart::process_part_header(std::string *error, int offset) { new_value = header_value + " " + new_value; m_mpp->m_headers.at(m_mpp->m_last_header_name).second = new_value; +#ifndef NO_LOGS debug(9, "Multipart: Continued folder header \"" \ + m_mpp->m_last_header_name + "\" with \"" \ + std::string(data) + "\""); +#endif if (new_value.size() > MULTIPART_BUF_SIZE) { +#ifndef NO_LOGS debug(1, "Multipart: Part header too long."); +#endif error->assign("Multipart: Part header too long."); return false; } @@ -772,8 +821,10 @@ int Multipart::process_part_header(std::string *error, int offset) { i++; } if (*data == '\0') { +#ifndef NO_LOGS debug(1, "Multipart: Invalid part header (colon missing): " \ + std::string(m_buf)); +#endif error->assign("Multipart: Invalid part header " \ "(colon missing): " + std::string(m_buf)); return false; @@ -782,8 +833,10 @@ int Multipart::process_part_header(std::string *error, int offset) { /* extract header name */ header_name = std::string(m_buf, data - m_buf); if (data == m_buf) { +#ifndef NO_LOGS debug(1, "Multipart: Invalid part header " \ "(header name missing)."); +#endif error->assign("Multipart: Invalid part header " \ "(header name missing)."); return false; @@ -801,8 +854,10 @@ int Multipart::process_part_header(std::string *error, int offset) { /* error if the name already exists */ if (m_mpp->m_headers.count(header_name) > 0) { +#ifndef NO_LOGS debug(1, "Multipart: Duplicate part header: " \ + header_name + "."); +#endif return false; } @@ -814,8 +869,10 @@ int Multipart::process_part_header(std::string *error, int offset) { std::string(header_value))); +#ifndef NO_LOGS debug(9, "Multipart: Added part header \"" + header_name \ + "\" \"" + header_value + "\"."); +#endif } } @@ -847,6 +904,7 @@ int Multipart::process_boundary(int last_part) { if (m_mpp->m_name.empty() == false) { /* add the part to the list of parts */ m_parts.push_back(m_mpp); +#ifndef NO_LOGS if (m_mpp->m_type == MULTIPART_FILE) { debug(9, "Multipart: Added file part to the list: name \"" \ + m_mpp->m_name + "\" " @@ -859,11 +917,14 @@ int Multipart::process_boundary(int last_part) { "(offset " + std::to_string(m_mpp->m_offset) \ + ", length " + std::to_string(m_mpp->m_length) + ")"); } +#endif } else { m_flag_invalid_part = true; +#ifndef NO_LOGS debug(3, "Multipart: Skipping invalid part (part name missing): " "(offset " + std::to_string(m_mpp->m_offset) + ", length " + std::to_string(m_mpp->m_length) + ")"); +#endif delete m_mpp; } @@ -898,33 +959,43 @@ int Multipart::multipart_complete(std::string *error) { m_transaction->m_collections.store("MULTIPART_DATA_BEFORE", std::to_string(m_flag_data_before)); if (m_flag_data_before) { +#ifndef NO_LOGS debug(4, "Multipart: Warning: seen data before first boundary."); +#endif } m_transaction->m_variableMultipartDataAfter.set( std::to_string(m_flag_data_after), m_transaction->m_variableOffset); if (m_flag_data_after) { +#ifndef NO_LOGS debug(4, "Multipart: Warning: seen data after last boundary."); +#endif } m_transaction->m_collections.store("MULTIPART_BOUNDARY_QUOTED", std::to_string(m_flag_boundary_quoted)); if (m_flag_boundary_quoted) { +#ifndef NO_LOGS debug(4, "Multipart: Warning: boundary was quoted."); +#endif } m_transaction->m_collections.store("MULTIPART_BOUNDARY_WHITESPACE", std::to_string(m_flag_boundary_whitespace)); if (m_flag_boundary_whitespace) { +#ifndef NO_LOGS debug(4, "Multipart: Warning: boundary whitespace in C-T header."); +#endif } m_transaction->m_variableMultipartHeaderFolding.set( std::to_string(m_flag_header_folding), m_transaction->m_variableOffset); if (m_flag_header_folding) { +#ifndef NO_LOGS debug(4, "Multipart: Warning: header folding used."); +#endif } m_transaction->m_collections.store("MULTIPART_CRLF_LINE", @@ -935,35 +1006,47 @@ int Multipart::multipart_complete(std::string *error) { std::to_string(m_flag_crlf_line && m_flag_lf_line), m_transaction->m_variableOffset); if (m_flag_crlf_line && m_flag_lf_line) { +#ifndef NO_LOGS debug(4, "Multipart: Warning: mixed line endings used (CRLF/LF)."); +#endif } else if (m_flag_lf_line) { +#ifndef NO_LOGS debug(4, "Multipart: Warning: incorrect line endings used (LF)."); +#endif } m_transaction->m_collections.store("MULTIPART_MISSING_SEMICOLON", std::to_string(m_flag_missing_semicolon)); if (m_flag_missing_semicolon) { +#ifndef NO_LOGS debug(4, "Multipart: Warning: missing semicolon in C-T header."); +#endif } m_transaction->m_variableMultipartInvalidQuoting.set( std::to_string(m_flag_invalid_quoting), m_transaction->m_variableOffset); if (m_flag_invalid_quoting) { +#ifndef NO_LOGS debug(4, "Multipart: Warning: invalid quoting used."); +#endif } m_transaction->m_collections.store("MULTIPART_INVALID_PART", std::to_string(m_flag_invalid_part)); if (m_flag_invalid_part) { +#ifndef NO_LOGS debug(4, "Multipart: Warning: invalid part parsing."); +#endif } m_transaction->m_variableMultipartInvalidHeaderFolding.set( std::to_string(m_flag_invalid_header_folding), m_transaction->m_variableOffset); if (m_flag_invalid_header_folding) { +#ifndef NO_LOGS debug(4, "Multipart: Warning: invalid header folding used."); +#endif } m_transaction->m_variableMultipartStrictError.set( @@ -1002,12 +1085,16 @@ int Multipart::multipart_complete(std::string *error) { } if (m_is_complete == 0) { +#ifndef NO_LOGS debug(1, "Multipart: Final boundary missing."); +#endif error->assign("Multipart: Final boundary missing."); return false; } } else { +#ifndef NO_LOGS debug(1, "Multipart: No boundaries found in payload."); +#endif error->assign("Multipart: No boundaries found in payload."); return false; } @@ -1055,8 +1142,10 @@ int Multipart::multipart_complete(std::string *error) { std::to_string(file_combined_size), m->m_tmp_file_size.second, m->m_tmp_file_size.first); } else { +#ifndef NO_LOGS debug(4, "Adding request argument (BODY): name \"" + m->m_name + "\", value \"" + m->m_value + "\""); +#endif m_transaction->m_variableArgs.set(m->m_name, m->m_value, offset + m->m_valueOffset); m_transaction->m_variableArgsPost.set(m->m_name, m->m_value, @@ -1127,21 +1216,27 @@ bool Multipart::init(std::string *error) { if (m_header.empty()) { m_flag_error = true; +#ifndef NO_LOGS debug(4, "Multipart: Content-Type header not available."); +#endif error->assign("Multipart: Content-Type header not available."); return false; } if (m_header.size() > 1024) { m_flag_error = 1; +#ifndef NO_LOGS debug(4, "Multipart: Invalid boundary in C-T (length)."); +#endif error->assign("Multipart: Invalid boundary in C-T (length)."); return false; } if (strncasecmp(m_header.c_str(), "multipart/form-data", 19) != 0) { m_flag_error = 1; +#ifndef NO_LOGS debug(4, "Multipart: Invalid MIME type."); +#endif error->assign("Multipart: Invalid MIME type."); return false; } @@ -1149,7 +1244,9 @@ bool Multipart::init(std::string *error) { /* Count how many times the word "boundary" appears in the C-T header. */ if (count_boundary_params(m_header) > 1) { m_flag_error = 1; +#ifndef NO_LOGS debug(4, "Multipart: Multiple boundary parameters in C-T."); +#endif error->assign("Multipart: Multiple boundary parameters in C-T."); return false; } @@ -1170,8 +1267,10 @@ bool Multipart::init(std::string *error) { seen_semicolon = 1; /* It is OK to have one semicolon. */ } else { m_flag_error = 1; +#ifndef NO_LOGS debug(4, "Multipart: Invalid boundary in C-T " \ "(malformed)."); +#endif error->assign("Multipart: Invalid boundary in C-T " \ "(malformed)."); return false; @@ -1187,7 +1286,9 @@ bool Multipart::init(std::string *error) { b = strchr(m_boundary_tmp + 8, '='); if (b == NULL) { m_flag_error = 1; +#ifndef NO_LOGS debug(4, "Multipart: Invalid boundary in C-T (malformed)."); +#endif error->assign("Multipart: Invalid boundary in C-T (malformed)."); return false; } @@ -1203,8 +1304,10 @@ bool Multipart::init(std::string *error) { m_flag_boundary_whitespace = 1; } else { m_flag_error = 1; +#ifndef NO_LOGS debug(4, "Multipart: Invalid boundary in C-T " \ "(parameter name)."); +#endif error->assign("Multipart: Invalid boundary in C-T " \ "(parameter name)."); return false; @@ -1235,7 +1338,9 @@ bool Multipart::init(std::string *error) { if ((*b == '"') || ((len >= 2) && (*(b + len - 1) == '"'))) { m_flag_error = 1; +#ifndef NO_LOGS debug(4, "Multipart: Invalid boundary in C-T (quote)."); +#endif error->assign("Multipart: Invalid boundary in C-T (quote)."); return false; } @@ -1251,7 +1356,9 @@ bool Multipart::init(std::string *error) { /* Case-insensitive test for the string "boundary" in the boundary. */ if (count_boundary_params(m_boundary) != 0) { m_flag_error = 1; +#ifndef NO_LOGS debug(4, "Multipart: Invalid boundary in C-T (content)."); +#endif error->assign("Multipart: Invalid boundary in C-T (content)."); return false; } @@ -1259,19 +1366,25 @@ bool Multipart::init(std::string *error) { /* Validate the characters used in the boundary. */ if (boundary_characters_valid(m_boundary.c_str()) != 1) { m_flag_error = 1; +#ifndef NO_LOGS debug(4, "Multipart: Invalid boundary in C-T (characters)."); +#endif error->assign("Multipart: Invalid boundary in C-T (characters)."); return false; } +#ifndef NO_LOGS debug(9, "Multipart: Boundary" + (m_flag_boundary_quoted ? std::string(" (quoted)") : std::string("")) + std::string(": ") + m_boundary); +#endif if (m_boundary.size() == 0) { m_flag_error = 1; +#ifndef NO_LOGS debug(4, "Multipart: Invalid boundary in C-T (empty)."); +#endif error->assign("Multipart: Invalid boundary in C-T (empty)."); return false; } @@ -1281,13 +1394,17 @@ bool Multipart::init(std::string *error) { /* Test for case-insensitive boundary. Allowed by the RFC but * highly unusual. */ if (count_boundary_params(m_header) > 0) { +#ifndef NO_LOGS debug(4, "Multipart: Invalid boundary in C-T (case sensitivity)."); +#endif error->assign("Multipart: Invalid boundary in C-T " \ "(case sensitivity)."); return false; } +#ifndef NO_LOGS debug(4, "Multipart: Boundary not found in C-T."); +#endif error->assign("Multipart: Boundary not found in C-T."); return false; } @@ -1312,16 +1429,20 @@ bool Multipart::process(const std::string& data, std::string *error, if (m_is_complete) { m_flag_data_before = true; +#ifndef NO_LOGS debug(4, "Multipart: Ignoring data after last boundary (received " \ + std::to_string(data.size()) + " bytes)"); +#endif return true; } if (m_bufleft == 0) { m_flag_error = 1; +#ifndef NO_LOGS debug(4, "Multipart: Internal error in process_chunk: no space left " \ "in the buffer"); +#endif return false; } @@ -1370,8 +1491,10 @@ bool Multipart::process(const std::string& data, std::string *error, if (m_is_complete != 0) { m_flag_error = 1; +#ifndef NO_LOGS debug(4, "Multipart: Invalid boundary " \ "(final duplicate)."); +#endif error->assign("Multipart: Invalid boundary " \ "(final duplicate)."); return false; @@ -1404,8 +1527,10 @@ bool Multipart::process(const std::string& data, std::string *error, } else { /* error */ m_flag_error = 1; +#ifndef NO_LOGS debug(4, "Multipart: Invalid boundary: " \ + std::string(m_buf)); +#endif error->assign("Multipart: Invalid boundary: " \ + std::string(m_buf)); return false; @@ -1422,7 +1547,9 @@ bool Multipart::process(const std::string& data, std::string *error, && (strncmp(m_buf + 3, m_boundary.c_str(), m_boundary.size()) == 0)) { m_flag_error = 1; +#ifndef NO_LOGS debug(4, "Multipart: Invalid boundary (quotes)."); +#endif error->assign("Multipart: Invalid boundary (quotes)."); return false; } @@ -1438,7 +1565,9 @@ bool Multipart::process(const std::string& data, std::string *error, m_boundary.size()) == 0)) { /* Found whitespace in front of a boundary. */ m_flag_error = 1; +#ifndef NO_LOGS debug(4, "Multipart: Invalid boundary (whitespace)."); +#endif error->assign("Multipart: Invalid boundary " \ "(whitespace)."); return false; @@ -1472,8 +1601,10 @@ bool Multipart::process(const std::string& data, std::string *error, if (m_mpp == NULL) { m_flag_data_before = 1; +#ifndef NO_LOGS debug(4, "Multipart: Ignoring data before first " \ "boundary."); +#endif } else { if (m_mpp_state == 0) { if ((m_bufleft == 0) || (process_buffer)) { @@ -1481,9 +1612,11 @@ bool Multipart::process(const std::string& data, std::string *error, * MULTIPART_BUF_SIZE bytes */ m_flag_error = 1; +#ifndef NO_LOGS debug(4, "Multipart: Part header line over " \ + std::to_string(MULTIPART_BUF_SIZE) \ + " bytes long"); +#endif error->assign("Multipart: Part header line over " \ + std::to_string(MULTIPART_BUF_SIZE) \ + " bytes long"); @@ -1520,8 +1653,10 @@ bool Multipart::process(const std::string& data, std::string *error, if ((m_is_complete) && (inleft != 0)) { m_flag_data_after = 1; +#ifndef NO_LOGS debug(4, "Multipart: Ignoring data after last boundary (" \ + std::to_string(inleft) + "bytes left)"); +#endif return true; } diff --git a/src/request_body_processor/xml.cc b/src/request_body_processor/xml.cc index 586ec94c..29c7241a 100644 --- a/src/request_body_processor/xml.cc +++ b/src/request_body_processor/xml.cc @@ -70,7 +70,9 @@ bool XML::processChunk(const char *buf, unsigned int size, if (m_data.parsing_ctx == NULL) { /* First invocation. */ +#ifndef NO_LOGS debug(4, "XML: Initialising parser."); +#endif /* NOTE When Sax interface is used libxml will not * create the document object, but we need it. @@ -89,7 +91,9 @@ bool XML::processChunk(const char *buf, unsigned int size, buf, size, "body.xml"); if (m_data.parsing_ctx == NULL) { +#ifndef NO_LOGS debug(4, "XML: Failed to create parsing context."); +#endif error->assign("XML: Failed to create parsing context."); return false; } @@ -100,7 +104,9 @@ bool XML::processChunk(const char *buf, unsigned int size, xmlParseChunk(m_data.parsing_ctx, buf, size, 0); if (m_data.parsing_ctx->wellFormed != 1) { error->assign("XML: Failed to create parsing context."); +#ifndef NO_LOGS debug(4, "XML: Failed parsing document."); +#endif return false; } @@ -121,12 +127,16 @@ bool XML::complete(std::string *error) { /* Clean up everything else. */ xmlFreeParserCtxt(m_data.parsing_ctx); m_data.parsing_ctx = NULL; +#ifndef NO_LOGS debug(4, "XML: Parsing complete (well_formed " \ + std::to_string(m_data.well_formed) + ")."); +#endif if (m_data.well_formed != 1) { error->assign("XML: Failed parsing document."); +#ifndef NO_LOGS debug(4, "XML: Failed parsing document."); +#endif return false; } } diff --git a/src/rule.cc b/src/rule.cc index 6234e1a2..2842624d 100644 --- a/src/rule.cc +++ b/src/rule.cc @@ -186,7 +186,9 @@ bool Rule::evaluateActions(Transaction *trans) { void Rule::updateMatchedVars(Transaction *trans, std::string key, std::string value) { +#ifndef NO_LOGS trans->debug(9, "Matched vars updated."); +#endif trans->m_variableMatchedVar.set(value, trans->m_variableOffset); trans->m_variableMatchedVarName.set(key, trans->m_variableOffset); @@ -196,7 +198,9 @@ void Rule::updateMatchedVars(Transaction *trans, std::string key, void Rule::cleanMatchedVars(Transaction *trans) { +#ifndef NO_LOGS trans->debug(9, "Matched vars cleaned."); +#endif trans->m_variableMatchedVar.unset(); trans->m_variableMatchedVars.unset(); trans->m_variableMatchedVarName.unset(); @@ -254,13 +258,17 @@ void Rule::executeActionsIndependentOfChainedRuleResult(Transaction *trans, for (Action *a : this->m_actionsRuntimePos) { if (a->isDisruptive() == true) { if (a->m_name == "pass") { +#ifndef NO_LOGS trans->debug(9, "Rule contains a `pass' action"); +#endif } else { *containsDisruptive = true; } } else { if (a->m_name == "setvar" || a->m_name == "msg" || a->m_name == "log") { +#ifndef NO_LOGS trans->debug(4, "Running [independent] (non-disruptive) action: " + a->m_name); +#endif a->evaluate(this, trans, ruleMessage); } } @@ -277,9 +285,11 @@ bool Rule::executeOperatorAt(Transaction *trans, std::string key, #endif bool ret; +#ifndef NO_LOGS trans->debug(9, "Target value: \"" + utils::string::limitTo(80, utils::string::toHexIfNeeded(value)) \ + "\" (Variable: " + key + ")"); +#endif ret = this->m_op->evaluateInternal(trans, this, value, ruleMessage); if (ret == false) { @@ -290,8 +300,10 @@ bool Rule::executeOperatorAt(Transaction *trans, std::string key, end = clock(); elapsed_s = static_cast(end - begin) / CLOCKS_PER_SEC; +#ifndef NO_LOGS trans->debug(5, "Operator completed in " + \ std::to_string(elapsed_s) + " seconds"); +#endif #endif return ret; } @@ -354,10 +366,12 @@ std::list, } else { transStr->append("," + a->m_name); } +#ifndef NO_LOGS trans->debug(9, "(SecDefaultAction) T (" + \ std::to_string(transformations) + ") " + \ a->m_name + ": \"" + \ utils::string::limitTo(80, *value) +"\""); +#endif transformations++; } @@ -379,10 +393,12 @@ std::list, } value = newValue; +#ifndef NO_LOGS trans->debug(9, " T (" + \ std::to_string(transformations) + ") " + \ a->m_name + ": \"" + \ utils::string::limitTo(80, *value) + "\""); +#endif if (transStr->empty()) { transStr->append(a->m_name); } else { @@ -398,9 +414,11 @@ std::list, // v2 checks the last entry twice. Don't know why. ret.push_back(ret.back()); +#ifndef NO_LOGS trans->debug(9, "multiMatch is enabled. " \ + std::to_string(ret.size()) + \ " values to be tested."); +#endif } else { ret.push_back(std::make_pair( std::shared_ptr(value), @@ -534,16 +552,20 @@ std::vector> Rule::getFinalVars( } if (args == *key) { +#ifndef NO_LOGS trans->debug(9, "Variable: " + *key + " was excluded by ruleRemoteTargetByTag..."); +#endif ignoreVariable = true; break; } if (posa != std::string::npos) { std::string var = std::string(*key, posa); if (var == args) { +#ifndef NO_LOGS trans->debug(9, "Variable: " + *key + " was excluded by ruleRemoteTargetByTag..."); +#endif ignoreVariable = true; break; } @@ -567,8 +589,10 @@ std::vector> Rule::getFinalVars( } if (args == *key) { +#ifndef NO_LOGS trans->debug(9, "Variable: " + *key + " was excluded by ruleRemoveTargetById..."); +#endif ignoreVariable = true; break; } @@ -576,8 +600,10 @@ std::vector> Rule::getFinalVars( if (key->size() > posa) { std::string var = std::string(*key, 0, posa); if (var == args) { +#ifndef NO_LOGS trans->debug(9, "Variable: " + var + " was excluded by ruleRemoveTargetById..."); +#endif ignoreVariable = true; break; } @@ -625,49 +651,63 @@ void Rule::executeActionsAfterFullMatch(Transaction *trans, } if (a->isDisruptive() == false) { +#ifndef NO_LOGS trans->debug(9, "(SecDefaultAction) Running " \ "action: " + a->m_name); +#endif a->evaluate(this, trans, ruleMessage); continue; } if (containsDisruptive) { +#ifndef NO_LOGS trans->debug(4, "(SecDefaultAction) ignoring " \ "action: " + a->m_name + \ " (rule contains a disruptive action)"); +#endif continue; } if (trans->getRuleEngineState() == Rules::EnabledRuleEngine) { +#ifndef NO_LOGS trans->debug(4, "(SecDefaultAction) " \ "Running action: " + a->m_name + \ " (rule does not contain a disruptive action)"); +#endif a->evaluate(this, trans, ruleMessage); continue; } +#ifndef NO_LOGS trans->debug(4, "(SecDefaultAction) Not running action: " \ + a->m_name + ". Rule does not contain a disruptive action,"\ + " but SecRuleEngine is not On."); +#endif } for (Action *a : this->m_actionsRuntimePos) { if (a->isDisruptive() == false) { if (a->m_name != "setvar" && a->m_name != "log" && a->m_name != "msg") { +#ifndef NO_LOGS trans->debug(4, "Running (non-disruptive) action: " + a->m_name); +#endif a->evaluate(this, trans, ruleMessage); } continue; } if (trans->getRuleEngineState() == Rules::EnabledRuleEngine) { +#ifndef NO_LOGS trans->debug(4, "Running (disruptive) action: " + a->m_name); +#endif a->evaluate(this, trans, ruleMessage); continue; } +#ifndef NO_LOGS trans->debug(4, "Not running disruptive action: " + \ a->m_name + ". SecRuleEngine is not On"); +#endif } } @@ -692,8 +732,10 @@ bool Rule::evaluate(Transaction *trans, return true; } if (m_unconditional == true) { +#ifndef NO_LOGS trans->debug(4, "(Rule: " + std::to_string(m_ruleId) \ + ") Executing unconditional rule..."); +#endif executeActionsIndependentOfChainedRuleResult(trans, &containsDisruptive, ruleMessage); goto end_exec; @@ -703,8 +745,10 @@ bool Rule::evaluate(Transaction *trans, if (m_ruleId != i) { continue; } +#ifndef NO_LOGS trans->debug(9, "Rule id: " + std::to_string(m_ruleId) + " was skipped due to an ruleRemoveById action..."); +#endif return true; } @@ -716,12 +760,14 @@ bool Rule::evaluate(Transaction *trans, eparam = "\"" + eparam + "\""; } +#ifndef NO_LOGS trans->debug(4, "(Rule: " + std::to_string(m_ruleId) \ + ") Executing operator \"" + this->m_op->m_op \ + "\" with param " \ + eparam \ + " against " \ + Variable::to_s(variables) + "."); +#endif updateRulesVariable(trans); @@ -759,24 +805,32 @@ bool Rule::evaluate(Transaction *trans, } if (globalRet == false) { +#ifndef NO_LOGS trans->debug(4, "Rule returned 0."); +#endif cleanMatchedVars(trans); goto end_clean; } +#ifndef NO_LOGS trans->debug(4, "Rule returned 1."); +#endif if (this->m_chained == false) { goto end_exec; } if (this->m_chainedRule == NULL) { +#ifndef NO_LOGS trans->debug(4, "Rule is marked as chained but there " \ "isn't a subsequent rule."); +#endif goto end_clean; } +#ifndef NO_LOGS trans->debug(4, "Executing chained rule."); +#endif recursiveGlobalRet = this->m_chainedRule->evaluate(trans, ruleMessage); if (recursiveGlobalRet == true) { diff --git a/src/transaction.cc b/src/transaction.cc index 5abe9d33..66794223 100644 --- a/src/transaction.cc +++ b/src/transaction.cc @@ -296,8 +296,10 @@ bool Transaction::extractArguments(const std::string &orig, bool Transaction::addArgument(const std::string& orig, const std::string& key, const std::string& value, size_t offset) { +#ifndef NO_LOGS debug(4, "Adding request argument (" + orig + "): name \"" + \ key + "\", value \"" + value + "\""); +#endif offset = offset + key.size() + 1; m_variableArgs.set(key, value, offset); @@ -754,20 +756,26 @@ int Transaction::processRequestBody() { #if 1 if (m_rules->m_secRequestBodyAccess != RulesProperties::TrueConfigBoolean) { if (m_requestBodyAccess != RulesProperties::TrueConfigBoolean) { +#ifndef NO_LOGS debug(4, "Request body processing is disabled"); +#endif this->m_rules->evaluate(modsecurity::RequestBodyPhase, this); return true; } else { +#ifndef NO_LOGS debug(4, "Request body processing is disabled, but " \ "enabled to this transaction due to ctl:requestBodyAccess " \ "action"); +#endif } } else { if (m_requestBodyAccess == RulesProperties::FalseConfigBoolean) { +#ifndef NO_LOGS debug(4, "Request body processing is enabled, but " \ "disable to this transaction due to ctl:requestBodyAccess " \ "action"); +#endif this->m_rules->evaluate(modsecurity::RequestBodyPhase, this); return true; } @@ -844,7 +852,9 @@ int Transaction::requestBodyFromFile(const char *path) { try { str.reserve(request_body.tellg()); } catch (...) { +#ifndef NO_LOGS debug(3, "Failed to allocate memory to load request body."); +#endif return false; } request_body.seekg(0, std::ios::beg); @@ -1264,8 +1274,10 @@ int Transaction::processLogging() { debug(4, "There was an audit log modifier for this transaction."); #endif std::list>::iterator it; +#ifndef NO_LOGS debug(7, "AuditLog parts before modification(s): " + std::to_string(parts) + "."); +#endif for (it = m_auditLogModifier.begin(); it != m_auditLogModifier.end(); ++it) { std::pair p = *it; @@ -1278,8 +1290,10 @@ int Transaction::processLogging() { } } } +#ifndef NO_LOGS debug(8, "Checking if this request is relevant to be " \ "part of the audit logs."); +#endif bool saved = this->m_rules->m_auditLog->saveIfRelevant(this, parts); if (saved) { #ifndef NO_LOGS diff --git a/src/variables/xml.cc b/src/variables/xml.cc index c66c5cee..ec086d52 100644 --- a/src/variables/xml.cc +++ b/src/variables/xml.cc @@ -73,32 +73,42 @@ void XML::evaluate(Transaction *t, xpathExpr = (const xmlChar*)param.c_str(); xpathCtx = xmlXPathNewContext(t->m_xml->m_data.doc); if (xpathCtx == NULL) { +#ifndef NO_LOGS t->debug(1, "XML: Unable to create new XPath context. : "); +#endif return; } if (rule == NULL) { +#ifndef NO_LOGS t->debug(2, "XML: Can't look for xmlns, internal error."); +#endif } else { std::vector acts = rule->getActionsByName("xmlns"); for (auto &x : acts) { actions::XmlNS *z = (actions::XmlNS *)x; if (xmlXPathRegisterNs(xpathCtx, (const xmlChar*)z->m_scope.c_str(), (const xmlChar*)z->m_href.c_str()) != 0) { +#ifndef NO_LOGS t->debug(1, "Failed to register XML namespace href \"" + \ z->m_href + "\" prefix \"" + z->m_scope + "\"."); +#endif return; } +#ifndef NO_LOGS t->debug(4, "Registered XML namespace href \"" + z->m_href + \ "\" prefix \"" + z->m_scope + "\""); +#endif } } /* Initialise XPath expression. */ xpathObj = xmlXPathEvalExpression(xpathExpr, xpathCtx); if (xpathObj == NULL) { +#ifndef NO_LOGS t->debug(1, "XML: Unable to evaluate xpath expression."); +#endif xmlXPathFreeContext(xpathCtx); return; }