Changes debuglogs schema to avoid unecessary str allocation

headers/modsecurity/debug_log.h

@@ -50,8 +50,8 @@ class DebugLog {
     const std::string& getDebugLogFile();
     virtual int getDebugLogLevel();
 
- private:
     int m_debugLevel;
+ private:
     std::string m_fileName;
 };
 

headers/modsecurity/transaction.h

@@ -48,6 +48,30 @@ typedef struct Rules_t Rules;
 #include "modsecurity/collection/collection.h"
 #include "modsecurity/variable_origin.h"
 
+#ifndef NO_LOGS
+#define ms_dbg(b, c) \
+  do { \
+      if (m_rules && m_rules->m_debugLog && m_rules->m_debugLog->m_debugLevel >= b) { \
+          m_rules->debug(b, m_id, m_uri, c); \
+      } \
+  } while (0);
+#else
+#define ms_dbg(b, c) \
+  do { } while (0);
+#endif
+
+#ifndef NO_LOGS
+#define ms_dbg_a(t, b, c) \
+  do { \
+      if (t && t->m_rules && t->m_rules->m_debugLog && t->m_rules->m_debugLog->m_debugLevel >= b) { \
+          t->debug(b, c); \
+      } \
+  } while (0);
+#else
+#define ms_dbg_a(t, b, c) \
+    do { } while (0);
+#endif
+
 
 #define LOGFY_ADD(a, b) \
     yajl_gen_string(g, reinterpret_cast<const unsigned char*>(a), strlen(a)); \

src/actions/block.cc

@@ -31,9 +31,7 @@ namespace actions {
 
 bool Block::evaluate(Rule *rule, Transaction *transaction,
     std::shared_ptr<RuleMessage> rm) {
-#ifndef NO_LOGS
+    ms_dbg_a(transaction, 8, "Marking request as disruptive.");
-    transaction->debug(8, "Marking request as disruptive.");
-#endif
 
     for (Action *a : transaction->m_rules->m_defaultActions[rule->m_phase]) {
         if (a->isDisruptive() == false) {

src/actions/ctl/rule_engine.cc

@@ -19,6 +19,7 @@
 #include <string>
 
 #include "modsecurity/rules_properties.h"
+#include "modsecurity/rules.h"
 #include "modsecurity/transaction.h"
 
 namespace modsecurity {
@@ -50,9 +51,7 @@ bool RuleEngine::evaluate(Rule *rule, Transaction *transaction) {
     a << modsecurity::RulesProperties::ruleEngineStateString(m_ruleEngine);
     a << " as requested by a ctl:ruleEngine action";
 
-#ifndef NO_LOGS
+    ms_dbg_a(transaction, 8, a.str());
-    transaction->debug(8, a.str());
-#endif
 
     transaction->m_secRuleEngine = m_ruleEngine;
     return true;

src/actions/disruptive/allow.cc

@@ -20,6 +20,7 @@
 
 #include "modsecurity/transaction.h"
 #include "modsecurity/rule.h"
+#include "modsecurity/rules.h"
 #include "src/utils/string.h"
 #include "modsecurity/modsecurity.h"
 
@@ -49,11 +50,9 @@ bool Allow::init(std::string *error) {
 
 
 bool Allow::evaluate(Rule *rule, Transaction *transaction) {
-#ifndef NO_LOGS
+    ms_dbg_a(transaction, 4, "Dropping the evaluation of upcoming rules " \
-    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;
 

src/actions/disruptive/deny.cc

@@ -30,9 +30,7 @@ namespace disruptive {
 
 bool Deny::evaluate(Rule *rule, Transaction *transaction,
     std::shared_ptr<RuleMessage> rm) {
-#ifndef NO_LOGS
+    ms_dbg_a(transaction, 8, "Running action deny");
-    transaction->debug(8, "Running action deny");
-#endif
 
     if (transaction->m_it.status == 200) {
         transaction->m_it.status = 403;

src/actions/disruptive/deny.h

@@ -18,6 +18,7 @@
 
 #include "modsecurity/actions/action.h"
 #include "modsecurity/transaction.h"
+#include "modsecurity/rules.h"
 #include "modsecurity/rule_message.h"
 
 #ifndef SRC_ACTIONS_DISRUPTIVE_DENY_H_

src/actions/disruptive/pass.cc

@@ -21,6 +21,7 @@
 
 #include "modsecurity/transaction.h"
 #include "modsecurity/rule.h"
+#include "modsecurity/rules.h"
 #include "modsecurity/rule_message.h"
 
 namespace modsecurity {
@@ -33,9 +34,7 @@ bool Pass::evaluate(Rule *rule, Transaction *transaction,
     intervention::free(&transaction->m_it);
     intervention::reset(&transaction->m_it);
 
-#ifndef NO_LOGS
+    ms_dbg_a(transaction, 8, "Running action pass");
-    transaction->debug(8, "Running action pass");
-#endif
 
     return true;
 }

src/actions/exec.cc

@@ -21,6 +21,7 @@
 #include "modsecurity/actions/action.h"
 #include "modsecurity/transaction.h"
 #include "modsecurity/rule.h"
+#include "modsecurity/rules.h"
 #include "src/utils/system.h"
 #include "src/engine/lua.h"
 
@@ -49,9 +50,7 @@ bool Exec::init(std::string *error) {
 
 
 bool Exec::evaluate(Rule *rule, Transaction *t) {
-#ifndef NO_LOGS
+    ms_dbg_a(t, 8, "Running script... " + m_script);
-    t->debug(8, "Running script... " + m_script);
-#endif
     m_lua.run(t);
     return true;
 }

src/actions/init_col.cc

@@ -67,10 +67,8 @@ bool InitCol::evaluate(Rule *rule, Transaction *t) {
         return false;
     }
 
-#ifndef NO_LOGS
+    ms_dbg_a(t, 5, "Collection `" + m_collection_key + "' initialized with " \
-    t->debug(5, "Collection `" + m_collection_key + "' initialized with " \
         "value: " + collectionName);
-#endif
 
     return true;
 }

src/actions/log.cc

@@ -30,9 +30,7 @@ namespace actions {
 
 bool Log::evaluate(Rule *rule, Transaction *transaction,
     std::shared_ptr<RuleMessage> rm) {
-#ifndef NO_LOGS
+    ms_dbg_a(transaction, 9, "Saving transaction to logs");
-    transaction->debug(9, "Saving transaction to logs");
-#endif
     rm->m_saveMessage = true;
     return true;
 }

src/actions/msg.cc

@@ -50,9 +50,7 @@ bool Msg::evaluate(Rule *rule, Transaction *transaction,
     std::shared_ptr<RuleMessage> rm) {
     std::string msg = data(transaction);
     rm->m_message = msg;
-#ifndef NO_LOGS
+    ms_dbg_a(transaction, 9, "Saving msg: " + msg);
-    transaction->debug(9, "Saving msg: " + msg);
-#endif
 
     return true;
 }

src/actions/set_env.cc

@@ -34,10 +34,8 @@ bool SetENV::init(std::string *error) {
 bool SetENV::evaluate(Rule *rule, Transaction *t) {
     std::string colNameExpanded(m_string->evaluate(t));
 
-#ifndef NO_LOGS
+    ms_dbg_a(t, 8, "Setting envoriment variable: "
-    t->debug(8, "Setting envoriment variable: "
         + colNameExpanded + ".");
-#endif
 
     putenv((char *)colNameExpanded.c_str());
 

src/actions/set_rsc.cc

@@ -33,11 +33,8 @@ bool SetRSC::init(std::string *error) {
 
 bool SetRSC::evaluate(Rule *rule, Transaction *t) {
     std::string colNameExpanded(m_string->evaluate(t));
-
+    ms_dbg_a(t, 8, "RESOURCE initiated with value: \'"
-#ifndef NO_LOGS
-    t->debug(8, "RESOURCE initiated with value: \'"
         + colNameExpanded + "\'.");
-#endif
 
     t->m_collections.m_resource_collection_key = colNameExpanded;
     t->m_variableResource.set(colNameExpanded, t->m_variableOffset);

src/actions/set_sid.cc

@@ -33,11 +33,8 @@ bool SetSID::init(std::string *error) {
 
 bool SetSID::evaluate(Rule *rule, Transaction *t) {
     std::string colNameExpanded(m_string->evaluate(t));
-
+    ms_dbg_a(t, 8, "Session ID initiated with value: \'"
-#ifndef NO_LOGS
-    t->debug(8, "Session ID initiated with value: \'"
         + colNameExpanded + "\'.");
-#endif
 
     t->m_collections.m_session_collection_key = colNameExpanded;
     t->m_variableSessionID.set(colNameExpanded, t->m_variableOffset);

src/actions/set_uid.cc

@@ -33,11 +33,8 @@ bool SetUID::init(std::string *error) {
 
 bool SetUID::evaluate(Rule *rule, Transaction *t) {
     std::string colNameExpanded(m_string->evaluate(t));
-
+    ms_dbg_a(t, 8, "User collection initiated with value: \'"
-#ifndef NO_LOGS
-    t->debug(8, "User collection initiated with value: \'"
         + colNameExpanded + "\'.");
-#endif
 
     t->m_collections.m_user_collection_key = colNameExpanded;
     t->m_variableUserID.set(colNameExpanded, t->m_variableOffset);

src/actions/set_var.cc

@@ -133,30 +133,30 @@ bool SetVar::evaluate(Rule *rule, Transaction *t) {
         }
     }
 
-#ifndef NO_LOGS
+    ms_dbg_a(t, 8, "Saving variable: " + m_variable->m_collectionName \
-    t->debug(8, "Saving variable: " + m_variable->m_collectionName \
         + ":" + m_variableNameExpanded + " with value: " + targetValue);
-#endif
+
-        if (tx) {
+    if (tx) {
-            tx->storeOrUpdateFirst(t, m_variableNameExpanded, targetValue);
+        tx->storeOrUpdateFirst(t, m_variableNameExpanded, targetValue);
-        } else if (session) {
+    } else if (session) {
-            session->storeOrUpdateFirst(t, m_variableNameExpanded, targetValue);
+        session->storeOrUpdateFirst(t, m_variableNameExpanded, targetValue);
-        } else if (ip) {
+    } else if (ip) {
-            ip->storeOrUpdateFirst(t, m_variableNameExpanded, targetValue);
+        ip->storeOrUpdateFirst(t, m_variableNameExpanded, targetValue);
-        } else if (resource) {
+    } else if (resource) {
-            resource->storeOrUpdateFirst(t, m_variableNameExpanded, targetValue);
+        resource->storeOrUpdateFirst(t, m_variableNameExpanded, targetValue);
-        } else if (global) {
+    } else if (global) {
-            global->storeOrUpdateFirst(t, m_variableNameExpanded, targetValue);
+        global->storeOrUpdateFirst(t, m_variableNameExpanded, targetValue);
-        } else if (user) {
+    } else if (user) {
-            user->storeOrUpdateFirst(t, m_variableNameExpanded, targetValue);
+        user->storeOrUpdateFirst(t, m_variableNameExpanded, targetValue);
-        } else {
+    } else {
-            // ?
+        // ?
-        }
+    }
-/*
+
-        t->m_collections.storeOrUpdateFirst(m_variable->m_collectionName,
+    /*
-            m_variableNameExpanded,
+    t->m_collections.storeOrUpdateFirst(m_variable->m_collectionName,
-            t->m_rules->m_secWebAppId.m_value, targetValue);
+        m_variableNameExpanded,
-            */
+        t->m_rules->m_secWebAppId.m_value, targetValue);
+    */
 end:
     return true;
 }

src/actions/severity.cc

@@ -22,6 +22,7 @@
 #include "modsecurity/actions/action.h"
 #include "modsecurity/transaction.h"
 #include "modsecurity/rule.h"
+#include "modsecurity/rules.h"
 #include "src/utils/string.h"
 #include "modsecurity/rule_message.h"
 
@@ -72,11 +73,9 @@ bool Severity::init(std::string *error) {
 
 bool Severity::evaluate(Rule *rule, Transaction *transaction,
     std::shared_ptr<RuleMessage> rm) {
-#ifndef NO_LOGS
+    ms_dbg_a(transaction, 9, "This rule severity is: " + \
-    transaction->debug(9, "This rule severity is: " + \
         std::to_string(this->m_severity) + " current transaction is: " + \
         std::to_string(transaction->m_highestSeverityAction));
-#endif
 
     rm->m_severity = m_severity;
 

src/actions/skip.cc

@@ -20,7 +20,7 @@
 
 #include "modsecurity/actions/action.h"
 #include "modsecurity/transaction.h"
-
+#include "modsecurity/rules.h"
 
 namespace modsecurity {
 namespace actions {
@@ -39,10 +39,9 @@ bool Skip::init(std::string *error) {
 
 
 bool Skip::evaluate(Rule *rule, Transaction *transaction) {
-#ifndef NO_LOGS
+    ms_dbg_a(transaction, 5, "Skipping the next " + \
-    transaction->debug(5, "Skipping the next " + std::to_string(m_skip_next) \
+        std::to_string(m_skip_next) + " rules.");
-        + " rules.");
+
-#endif
     transaction->m_skip_next = m_skip_next;
 
     return true;

src/actions/skip_after.cc

@@ -20,6 +20,7 @@
 
 #include "modsecurity/actions/action.h"
 #include "modsecurity/transaction.h"
+#include "modsecurity/rules.h"
 
 
 namespace modsecurity {
@@ -27,9 +28,7 @@ namespace actions {
 
 
 bool SkipAfter::evaluate(Rule *rule, Transaction *transaction) {
-#ifndef NO_LOGS
+    ms_dbg_a(transaction, 5, "Setting skipAfter for: " + m_parser_payload);
-    transaction->debug(5, "Setting skipAfter for: " + m_parser_payload);
-#endif
     transaction->m_marker = m_parser_payload;
     return true;
 }

src/actions/tag.cc

@@ -59,10 +59,7 @@ std::string Tag::getName(Transaction *transaction) {
 bool Tag::evaluate(Rule *rule, Transaction *transaction,
     std::shared_ptr<RuleMessage> rm) {
     std::string tag = getName(transaction);
-
+    ms_dbg_a(transaction, 9, "Rule tag: " + tag);
-#ifndef NO_LOGS
-    transaction->debug(9, "Rule tag: " + tag);
-#endif
 
     rm->m_tags.push_back(tag);
 

src/anchored_set_variable.cc

@@ -96,7 +96,7 @@ void AnchoredSetVariable::resolve(
         if (!ke.toOmit(x.first)) {
             l->insert(l->begin(), new VariableValue(x.second));
         } else {
-            m_transaction->debug(7, "Excluding key: " + x.first
+            ms_dbg_a(m_transaction, 7, "Excluding key: " + x.first
                 + " from target value.");
         }
     }
@@ -147,7 +147,7 @@ void AnchoredSetVariable::resolveRegularExpression(Utils::Regex *r,
         if (!ke.toOmit(x.first)) {
             l->insert(l->begin(), new VariableValue(x.second));
         } else {
-            m_transaction->debug(7, "Excluding key: " + x.first
+            ms_dbg_a(m_transaction, 7, "Excluding key: " + x.first
                 + " from target value.");
         }
     }

src/audit_log/audit_log.cc

@@ -292,9 +292,7 @@ bool AuditLog::saveIfRelevant(Transaction *transaction) {
 bool AuditLog::saveIfRelevant(Transaction *transaction, int parts) {
     bool saveAnyway = false;
     if (m_status == OffAuditLogStatus || m_status == NotSetLogStatus) {
-#ifndef NO_LOGS
+        ms_dbg_a(transaction, 5, "Audit log engine was not set.");
-        transaction->debug(5, "Audit log engine was not set.");
-#endif
         return true;
     }
 
@@ -308,12 +306,10 @@ bool AuditLog::saveIfRelevant(Transaction *transaction, int parts) {
     if ((m_status == RelevantOnlyAuditLogStatus
         && this->isRelevant(transaction->m_httpCodeReturned) == false)
         && saveAnyway == false) {
-#ifndef NO_LOGS
+        ms_dbg_a(transaction, 9, "Return code `" +
-        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;
     }
@@ -321,21 +317,15 @@ bool AuditLog::saveIfRelevant(Transaction *transaction, int parts) {
     if (parts == -1) {
         parts = m_parts;
     }
-#ifndef NO_LOGS
+    ms_dbg_a(transaction, 5, "Saving this request as part " \
-    transaction->debug(5, "Saving this request as part " \
             "of the audit logs.");
-#endif
     if (m_writer == NULL) {
-#ifndef NO_LOGS
+        ms_dbg_a(transaction, 1, "Internal error, audit log writer is null");
-        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
+            ms_dbg_a(transaction, 1, "Cannot save the audit log: " + error);
-            transaction->debug(1, "Cannot save the audit log: " + error);
-#endif
             return false;
         }
     }

src/audit_log/writer/https.cc

@@ -27,10 +27,12 @@
 
 #include "modsecurity/audit_log.h"
 #include "modsecurity/transaction.h"
+#include "modsecurity/rules.h"
 #include "src/utils/md5.h"
 #include "src/utils/https_client.h"
 
 
+
 namespace modsecurity {
 namespace audit_log {
 namespace writer {
@@ -47,9 +49,7 @@ bool Https::init(std::string *error) {
 
 bool Https::write(Transaction *transaction, int parts, std::string *error) {
     Utils::HttpsClient m_http_client;
-#ifndef NO_LOGS
+    ms_dbg_a(transaction, 7, "Sending logs to: " + m_audit->m_path1);
-    transaction->debug(7, "Sending logs to: " + m_audit->m_path1);
-#endif
 
     std::string log = transaction->toJSON(parts);
     m_http_client.setRequestType("application/json");

src/engine/lua.cc

@@ -161,9 +161,7 @@ int Lua::run(Transaction *t) {
 #endif
         }
         e.append(lua_tostring(L, -1));
-#ifndef NO_LOGS
+        ms_dbg_a(t, 2, e);
-        t->debug(2, e);
-#endif
         ret = false;
         goto err;
     }
@@ -177,9 +175,8 @@ int Lua::run(Transaction *t) {
             e.append(" - ");
             e.append(luaerr);
         }
-#ifndef NO_LOGS
+        ms_dbg_a(t, 2, e);
-        t->debug(2, e);
+
-#endif
         ret = false;
         goto err;
     }
@@ -195,9 +192,8 @@ int Lua::run(Transaction *t) {
             e.append(" - ");
             e.append(luaerr);
         }
-#ifndef NO_LOGS
+        ms_dbg_a(t, 2, e);
-        t->debug(2, e);
+
-#endif
         ret = false;
         goto err;
     }
@@ -206,9 +202,8 @@ int Lua::run(Transaction *t) {
     if (a != NULL) {
         luaRet.assign(a);
     }
-#ifndef NO_LOGS
+
-    t->debug(9, "Returning from lua script: " + luaRet);
+    ms_dbg_a(t, 9, "Returning from lua script: " + luaRet);
-#endif
 
     if (luaRet.size() == 0) {
         ret = false;
@@ -221,9 +216,8 @@ err:
 
     return ret;
 #else
-#ifndef NO_LOGS
+    ms_dbg_a(t, 9, "Lua support was not enabled.");
-    t->debug(9, "Lua support was not enabled.");
+
-#endif
     return false;
 #endif
 }
@@ -245,9 +239,7 @@ int Lua::log(lua_State *L) {
 
     /* Log message. */
     if (t != NULL) {
-#ifndef NO_LOGS
+        ms_dbg_a(t, level, text);
-        t->debug(level, text);
-#endif
     }
 
     return 0;
@@ -339,9 +331,8 @@ int Lua::setvar(lua_State *L) {
 
 
     if (nargs != 2) {
-#ifndef NO_LOGS
+        ms_dbg_a(t, 8,
-        t->debug(8, "m.setvar: Failed m.setvar funtion must has 2 arguments");
+            "m.setvar: Failed m.setvar funtion must has 2 arguments");
-#endif
         return -1;
     }
     var_value = luaL_checkstring(L, 2);
@@ -362,10 +353,9 @@ int Lua::setvar(lua_State *L) {
             std::string::npos);
 
     } else {
-#ifndef NO_LOGS
+        ms_dbg_a(t, 8,
-        t->debug(8, "m.setvar: Must specify a collection using dot character" \
+            "m.setvar: Must specify a collection using dot character" \
             " - ie m.setvar(tx.myvar,mydata)");
-#endif
         return -1;
     }
 
@@ -443,10 +433,9 @@ std::string Lua::applyTransformations(lua_State *L, Transaction *t,
             if (tfn) {
                 newVar = tfn->evaluate(newVar, t);
             } else {
-#ifndef NO_LOGS
+                ms_dbg_a(t, 1,
-                t->debug(1, "SecRuleScript: Invalid transformation function: " \
+                    "SecRuleScript: Invalid transformation function: " \
                     + std::string(name));
-#endif
             }
             delete tfn;
         }
@@ -467,19 +456,15 @@ std::string Lua::applyTransformations(lua_State *L, Transaction *t,
             newVar = tfn->evaluate(newVar, t);
             delete tfn;
         } else {
-#ifndef NO_LOGS
+            ms_dbg_a(t, 1, "SecRuleScript: Invalid transformation function: " \
-            t->debug(1, "SecRuleScript: Invalid transformation function: " \
                 + std::string(name));
-#endif
         }
         return newVar;
     }
-#ifndef NO_LOGS
+    ms_dbg_a(t, 8, "SecRuleScript: Transformation parameter must be a " \
-    t->debug(8, "SecRuleScript: Transformation parameter must be a " \
         "transformation name or array of transformation names, but found " \
         "" + std::string(lua_typename(L, idx)) + " (type " \
         + std::to_string(lua_type(L, idx)) + ")");
-#endif
     return newVar;
 }
 #endif

src/operators/detect_sqli.cc

@@ -35,26 +35,20 @@ bool DetectSQLi::evaluate(Transaction *t, Rule *rule,
     if (issqli) {
         if (t) {
             t->m_matched.push_back(fingerprint);
-#ifndef NO_LOGS
+            ms_dbg_a(t, 4, "detected SQLi using libinjection with " \
-            t->debug(4, "detected SQLi using libinjection with " \
                 "fingerprint '" + std::string(fingerprint) + "' at: '" +
                 input + "'");
-#endif
             if (rule && t && rule->m_containsCaptureAction) {
                 t->m_collections.m_tx_collection->storeOrUpdateFirst(
                     "0", std::string(fingerprint));
-#ifndef NO_LOGS
+                ms_dbg_a(t, 7, "Added DetectSQLi match TX.0: " + \
-                t->debug(7, "Added DetectSQLi match TX.0: " + \
                     std::string(fingerprint));
-#endif
                 }
         }
     } else {
         if (t) {
-#ifndef NO_LOGS
+            ms_dbg_a(t, 9, "detected SQLi: not able to find an " \
-            t->debug(9, "detected SQLi: not able to find an " \
                 "inject on '" + input + "'");
-#endif
         }
     }
 

src/operators/detect_xss.cc

@@ -33,22 +33,16 @@ bool DetectXSS::evaluate(Transaction *t, Rule *rule,
 
     if (t) {
         if (is_xss) {
-#ifndef NO_LOGS
+            ms_dbg_a(t, 5, "detected XSS using libinjection.");
-            t->debug(5, "detected XSS using libinjection.");
-#endif
             if (rule && t && rule->m_containsCaptureAction) {
                 t->m_collections.m_tx_collection->storeOrUpdateFirst(
                     "0", std::string(input));
-#ifndef NO_LOGS
+                ms_dbg_a(t, 7, "Added DetectXSS match TX.0: " + \
-                t->debug(7, "Added DetectXSS match TX.0: " + \
                     std::string(input));
-#endif
+            }
-            } 
         } else {
-#ifndef NO_LOGS
+            ms_dbg_a(t, 9, "libinjection was not able to " \
-            t->debug(9, "libinjection was not able to " \
+                "find any XSS in: " + input);
-            "find any XSS in: " + input);
-#endif
             }
     }
     return is_xss != 0;

src/operators/fuzzy_hash.cc

@@ -103,19 +103,15 @@ bool FuzzyHash::evaluate(Transaction *t, const std::string &str) {
 
     if (fuzzy_hash_buf((const unsigned char*)str.c_str(),
         str.size(), result)) {
-#ifndef NO_LOGS
+        ms_dbg_a(t, 4, "Problems generating fuzzy hash");
-        t->debug(4, "Problems generating fuzzy hash");
-#endif
         return false;
     }
 
     while (chunk != NULL) {
         int i = fuzzy_compare(chunk->data, result);
         if (i >= m_threshold) {
-#ifndef NO_LOGS
+            ms_dbg_a(t, 4, "Fuzzy hash: matched " \
-            t->debug(4, "Fuzzy hash: matched " \
                 "with score: " + std::to_string(i) + ".");
-#endif
             return true;
         }
         chunk = chunk->next;

src/operators/geo_lookup.cc

@@ -33,6 +33,11 @@
 namespace modsecurity {
 namespace operators {
 
+bool GeoLookup::debug(Transaction *transaction, int x, std::string a) {
+    ms_dbg_a(transaction, x, a);
+    return true;
+}
+
 
 bool GeoLookup::evaluate(Transaction *trans, const std::string &exp) {
     using std::placeholders::_1;

src/operators/geo_lookup.h

@@ -30,6 +30,9 @@ class GeoLookup : public Operator {
     GeoLookup()
         : Operator("GeoLookup") { }
     bool evaluate(Transaction *transaction, const std::string &exp) override;
+
+ protected:
+    bool debug(Transaction *transaction, int x, std::string a);
 };
 
 }  // namespace operators

src/operators/operator.cc

@@ -68,13 +68,6 @@ namespace modsecurity {
 namespace operators {
 
 
-bool Operator::debug(Transaction *transaction, int x, std::string a) {
-#ifndef NO_LOGS
-    transaction->debug(x, a);
-#endif
-    return true;
-}
-
 bool Operator::evaluateInternal(Transaction *transaction,
     Rule *rule, const std::string& a, std::shared_ptr<RuleMessage> rm) {
     bool res = evaluate(transaction, rule, a, rm);
@@ -138,13 +131,8 @@ std::string Operator::resolveMatchMessage(Transaction *t,
 
 
 bool Operator::evaluate(Transaction *transaction, const std::string& a) {
-#ifndef NO_LOGS
+    ms_dbg_a(transaction, 2, "Operator: " + m_op + \
-    if (transaction) {
+        " is not implemented or malfunctioning.");
-        transaction->debug(2, "Operator: " + this->m_op + \
-            " is not implemented or malfunctioning.");
-    }
-#endif
-
     return true;
 }
 

src/operators/operator.h

@@ -142,9 +142,6 @@ class Operator {
     std::string m_param;
     std::unique_ptr<RunTimeString> m_string;
     bool m_couldContainsMacro;
-
- protected:
-    bool debug(Transaction *transaction, int x, std::string a);
 };
 
 }  // namespace operators

src/operators/pm.cc

@@ -106,10 +106,8 @@ bool Pm::evaluate(Transaction *transaction, Rule *rule,
     if (rule && rule->m_containsCaptureAction && transaction && rc) {
         transaction->m_collections.m_tx_collection->storeOrUpdateFirst("0",
             std::string(match));
-#ifndef NO_LOGS
+        ms_dbg_a(transaction, 7, "Added pm match TX.0: " + \
-        transaction->debug(7, "Added pm match TX.0: " + \
             std::string(match));
-#endif
     }
 
     return rc > 0;

src/operators/rbl.cc

@@ -39,7 +39,7 @@ std::string Rbl::mapIpToAddress(std::string ipStr, Transaction *trans) {
     }
 
     if (sscanf(ipStr.c_str(), "%d.%d.%d.%d", &h0, &h1, &h2, &h3) != 4) {
-        debug(trans, 0, std::string("Failed to understand `" + ipStr +
+        ms_dbg_a(trans, 0, std::string("Failed to understand `" + ipStr +
             "' as a valid IP address, assuming domain format input"));
 
         addr = ipStr + "." + m_service;
@@ -47,7 +47,7 @@ std::string Rbl::mapIpToAddress(std::string ipStr, Transaction *trans) {
     }
 
     if (m_demandsPassword && key.empty()) {
-        debug(trans, 0, std::string("Missing RBL key, cannot continue " \
+        ms_dbg_a(trans, 0, std::string("Missing RBL key, cannot continue " \
             "with the operator execution, please set the key using: " \
             "SecHttpBlKey"));
         return addr;
@@ -76,12 +76,12 @@ void Rbl::futherInfo_httpbl(struct sockaddr_in *sin, std::string ipStr,
     respBl = inet_ntoa(sin->sin_addr);
 
     if (sscanf(respBl, "%d.%d.%d.%d", &first, &days, &score, &type) != 4) {
-        debug(trans, 4, "RBL lookup of " + ipStr + " failed: bad response");
+        ms_dbg_a(trans, 4, "RBL lookup of " + ipStr + " failed: bad response");
         return;
     }
 
     if (first != 127) {
-        debug(trans, 4, "RBL lookup of " + ipStr + " failed: bad response");
+        ms_dbg_a(trans, 4, "RBL lookup of " + ipStr + " failed: bad response");
         return;
     }
 
@@ -114,7 +114,7 @@ void Rbl::futherInfo_httpbl(struct sockaddr_in *sin, std::string ipStr,
             ptype = " ";
     }
 
-    debug(trans, 4, "RBL lookup of " + ipStr + " succeeded. %s: " \
+    ms_dbg_a(trans, 4, "RBL lookup of " + ipStr + " succeeded. %s: " \
         + std::to_string(days) + " " \
         "days since last activity, threat score " \
         + std::to_string(score) +  ". Case: " + ptype);
@@ -126,23 +126,23 @@ void Rbl::futherInfo_spamhaus(unsigned int high8bits, std::string ipStr,
     switch (high8bits) {
         case 2:
         case 3:
-            debug(trans, 4, "RBL lookup of " + ipStr + " succeeded " \
+            ms_dbg_a(trans, 4, "RBL lookup of " + ipStr + " succeeded " \
                 "(Static UBE sources).");
             break;
         case 4:
         case 5:
         case 6:
         case 7:
-            debug(trans, 4, "RBL lookup of " + ipStr + " succeeded " \
+            ms_dbg_a(trans, 4, "RBL lookup of " + ipStr + " succeeded " \
                 "(Illegal 3rd party exploits).");
             break;
         case 10:
         case 11:
-            debug(trans, 4, "RBL lookup of " + ipStr + " succeeded " \
+            ms_dbg_a(trans, 4, "RBL lookup of " + ipStr + " succeeded " \
                 "(Delivering unauthenticated SMTP email).");
             break;
         default:
-            debug(trans, 4, "RBL lookup of " + ipStr + " succeeded ");
+            ms_dbg_a(trans, 4, "RBL lookup of " + ipStr + " succeeded ");
             break;
     }
 }
@@ -152,24 +152,24 @@ void Rbl::futherInfo_uribl(unsigned int high8bits, std::string ipStr,
     Transaction *trans) {
     switch (high8bits) {
         case 2:
-            debug(trans, 4, "RBL lookup of " + ipStr + " succeeded (BLACK).");
+            ms_dbg_a(trans, 4, "RBL lookup of " + ipStr + " succeeded (BLACK).");
         break;
         case 4:
-            debug(trans, 4, "RBL lookup of " + ipStr + " succeeded (GREY).");
+            ms_dbg_a(trans, 4, "RBL lookup of " + ipStr + " succeeded (GREY).");
             break;
         case 8:
-            debug(trans, 4, "RBL lookup of " + ipStr + " succeeded (RED).");
+            ms_dbg_a(trans, 4, "RBL lookup of " + ipStr + " succeeded (RED).");
             break;
         case 14:
-            debug(trans, 4, "RBL lookup of " + ipStr + " succeeded " \
+            ms_dbg_a(trans, 4, "RBL lookup of " + ipStr + " succeeded " \
                 "(BLACK,GREY,RED).");
             break;
         case 255:
-            debug(trans, 4, "RBL lookup of " + ipStr + " succeeded " \
+            ms_dbg_a(trans, 4, "RBL lookup of " + ipStr + " succeeded " \
                 "(DNS IS BLOCKED).");
             break;
         default:
-            debug(trans, 4, "RBL lookup of " + ipStr + " succeeded (WHITE).");
+            ms_dbg_a(trans, 4, "RBL lookup of " + ipStr + " succeeded (WHITE).");
             break;
     }
 }
@@ -181,7 +181,7 @@ void Rbl::furtherInfo(struct sockaddr_in *sin, std::string ipStr,
 
     switch (m_provider) {
         case RblProvider::UnknownProvider:
-            debug(trans, 2, "RBL lookup of " + ipStr + " succeeded.");
+            ms_dbg_a(trans, 2, "RBL lookup of " + ipStr + " succeeded.");
             break;
         case RblProvider::httpbl:
             futherInfo_httpbl(sin, ipStr, trans);
@@ -213,7 +213,7 @@ bool Rbl::evaluate(Transaction *t, Rule *rule,
         if (info != NULL) {
             freeaddrinfo(info);
         }
-        debug(t, 5, "RBL lookup of " + ipStr + " failed.");
+        ms_dbg_a(t, 5, "RBL lookup of " + ipStr + " failed.");
         return false;
     }
 
@@ -225,10 +225,8 @@ bool Rbl::evaluate(Transaction *t, Rule *rule,
     if (rule && t && rule->m_containsCaptureAction) {
         t->m_collections.m_tx_collection->storeOrUpdateFirst(
         "0", std::string(ipStr));
-#ifndef NO_LOGS
+        ms_dbg_a(t, 7, "Added RXL match TX.0: " + \
-        t->debug(7, "Added RXL match TX.0: " + \
             std::string(ipStr));
-#endif
     }
 
     return true;

src/operators/rx.cc

@@ -60,10 +60,8 @@ bool Rx::evaluate(Transaction *transaction, Rule *rule,
         for (const SMatch& a : matches) {
             transaction->m_collections.m_tx_collection->storeOrUpdateFirst(
                 std::to_string(i), a.match);
-#ifndef NO_LOGS
+            ms_dbg_a(transaction, 7, "Added regex subexpression TX." +
-            transaction->debug(7, "Added regex subexpression TX." +
                 std::to_string(i) + ": " + a.match);
-#endif
             transaction->m_matched.push_back(a.match);
             i++;
         }

src/operators/validate_dtd.cc

@@ -50,25 +50,19 @@ 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
+        ms_dbg_a(t, 4, err);
-        t->debug(4, err);
-#endif
         return true;
     }
 
     if (t->m_xml->m_data.doc == NULL) {
-#ifndef NO_LOGS
+        ms_dbg_a(t, 4, "XML document tree could not "\
-        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
+        ms_dbg_a(t, 4, "XML: DTD validation failed because " \
-        t->debug(4, "XML: DTD validation failed because " \
             "content is not well formed.");
-#endif
         return true;
     }
 
@@ -84,9 +78,7 @@ bool ValidateDTD::evaluate(Transaction *t, const std::string &str) {
 
     cvp = xmlNewValidCtxt();
     if (cvp == NULL) {
-#ifndef NO_LOGS
+        ms_dbg_a(t, 4, "XML: Failed to create a validation context.");
-        t->debug(4, "XML: Failed to create a validation context.");
-#endif
         return true;
     }
 
@@ -96,17 +88,13 @@ 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
+        ms_dbg_a(t, 4, "XML: DTD validation failed.");
-        t->debug(4, "XML: DTD validation failed.");
-#endif
         xmlFreeValidCtxt(cvp);
         return true;
     }
 
-#ifndef NO_LOGS
+    ms_dbg_a(t, 4, std::string("XML: Successfully validated " \
-    t->debug(4, std::string("XML: Successfully validated " \
         "payload against DTD: ") + m_resource);
-#endif
 
     xmlFreeValidCtxt(cvp);
 

src/operators/validate_dtd.h

@@ -63,9 +63,7 @@ class ValidateDTD : public Operator {
         if (len > 0) {
             s = "XML Error: " + std::string(buf);
         }
-#ifndef NO_LOGS
+        ms_dbg_a(t, 4, s);
-        t->debug(4, s);
-#endif
     }
 
 
@@ -82,9 +80,7 @@ class ValidateDTD : public Operator {
         if (len > 0) {
             s = "XML Warning: " + std::string(buf);
         }
-#ifndef NO_LOGS
+        ms_dbg_a(t, 4, s);
-        t->debug(4, s);
-#endif
     }
 
 

src/operators/validate_schema.cc

@@ -52,9 +52,7 @@ bool ValidateSchema::evaluate(Transaction *t,
         if (m_err.empty() == false) {
             err << m_err;
         }
-#ifndef NO_LOGS
+        ms_dbg_a(t, 4, err.str());
-        t->debug(4, err.str());
-#endif
         return true;
     }
 
@@ -77,9 +75,7 @@ bool ValidateSchema::evaluate(Transaction *t,
         if (m_err.empty() == false) {
             err << " " << m_err;
         }
-#ifndef NO_LOGS
+        ms_dbg_a(t, 4, err.str());
-        t->debug(4, err.str());
-#endif
         xmlSchemaFreeParserCtxt(m_parserCtx);
         return true;
     }
@@ -90,9 +86,7 @@ bool ValidateSchema::evaluate(Transaction *t,
         if (m_err.empty() == false) {
             err << " " << m_err;
         }
-#ifndef NO_LOGS
+        ms_dbg_a(t, 4, err.str());
-        t->debug(4, err.str());
-#endif
         return true;
     }
 
@@ -102,46 +96,36 @@ bool ValidateSchema::evaluate(Transaction *t,
         (xmlSchemaValidityWarningFunc)warn_runtime, t);
 
     if (t->m_xml->m_data.doc == NULL) {
-#ifndef NO_LOGS
+        ms_dbg_a(t, 4, "XML document tree could not be found for " \
-        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
+        ms_dbg_a(t, 4, "XML: Schema validation failed because " \
-        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
+        ms_dbg_a(t, 4, "XML: Schema validation could not proceed due to previous"
-        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) {
-#ifndef NO_LOGS
+        ms_dbg_a(t, 4, "XML: Schema validation failed.");
-        t->debug(4, "XML: Schema validation failed.");
-#endif
         xmlSchemaFree(m_schema);
         xmlSchemaFreeParserCtxt(m_parserCtx);
         return true; /* No match. */
     }
 
-#ifndef NO_LOGS
+    ms_dbg_a(t, 4, "XML: Successfully validated payload against " \
-    t->debug(4, "XML: Successfully validated payload against " \
         "Schema: " + m_resource);
-#endif
     xmlSchemaFree(m_schema);
     xmlSchemaFreeParserCtxt(m_parserCtx);
 

src/operators/validate_schema.h

@@ -105,9 +105,7 @@ class ValidateSchema : public Operator {
         if (len > 0) {
             s = "XML Error: " + std::string(buf);
         }
-#ifndef NO_LOGS
+        ms_dbg_a(t, 4, s);
-        t->debug(4, s);
-#endif
     }
 
 
@@ -124,9 +122,7 @@ class ValidateSchema : public Operator {
         if (len > 0) {
             s = "XML Warning: " + std::string(buf);
         }
-#ifndef NO_LOGS
+        ms_dbg_a(t, 4, s);
-        t->debug(4, s);
-#endif
     }
 
     static void null_error(void *ctx, const char *msg, ...) {

src/operators/validate_url_encoding.cc

@@ -82,28 +82,22 @@ bool ValidateUrlEncoding::evaluate(Transaction *transaction, Rule *rule,
         case 1 :
             /* Encoding is valid */
             if (transaction) {
-#ifndef NO_LOGS
+                ms_dbg_a(transaction, 7, "Valid URL Encoding at '" +input + "'");
-                transaction->debug(7, "Valid URL Encoding at '" +input + "'");
-#endif
             }
             res = false;
             break;
         case -2 :
             if (transaction) {
-#ifndef NO_LOGS
+                ms_dbg_a(transaction, 7, "Invalid URL Encoding: Non-hexadecimal "
-                transaction->debug(7, "Invalid URL Encoding: Non-hexadecimal "
                     "digits used at '" + input + "'");
-#endif
                 logOffset(ruleMessage, offset, input.size());
             }
             res = true; /* Invalid match. */
             break;
         case -3 :
             if (transaction) {
-#ifndef NO_LOGS
+                ms_dbg_a(transaction, 7, "Invalid URL Encoding: Not enough " \
-                transaction->debug(7, "Invalid URL Encoding: Not enough " \
                 "characters at the end of input at '" + input + "'");
-#endif
                 logOffset(ruleMessage, offset, input.size());
             }
             res = true; /* Invalid match. */
@@ -111,11 +105,9 @@ bool ValidateUrlEncoding::evaluate(Transaction *transaction, Rule *rule,
         case -1 :
         default :
             if (transaction) {
-#ifndef NO_LOGS
+                ms_dbg_a(transaction, 7, "Invalid URL Encoding: Internal " \
-                transaction->debug(7, "Invalid URL Encoding: Internal " \
                     "Error (rc = " + std::to_string(rc) + ") at '" +
                     input + "'");
-#endif
                 logOffset(ruleMessage, offset, input.size());
             }
             res = true;

src/operators/validate_utf8_encoding.cc

@@ -126,58 +126,48 @@ bool ValidateUtf8Encoding::evaluate(Transaction *transaction, Rule *rule,
         switch (rc) {
             case UNICODE_ERROR_CHARACTERS_MISSING :
                 if (transaction) {
-#ifndef NO_LOGS
+                    ms_dbg_a(transaction, 8, "Invalid UTF-8 encoding: "
-                    transaction->debug(8, "Invalid UTF-8 encoding: "
                         "not enough bytes in character "
                         "at " + str + ". [offset \"" +
                         std::to_string(i) + "\"]");
-#endif
                 }
                 return true;
                 break;
             case UNICODE_ERROR_INVALID_ENCODING :
                 if (transaction) {
-#ifndef NO_LOGS
+                    ms_dbg_a(transaction, 8, "Invalid UTF-8 encoding: "
-                    transaction->debug(8, "Invalid UTF-8 encoding: "
                         "invalid byte value in character "
                         "at " + str + ". [offset \"" +
                         std::to_string(i) + "\"]");
-#endif
                     logOffset(ruleMessage, i, str.size());
                 }
                 return true;
                 break;
             case UNICODE_ERROR_OVERLONG_CHARACTER :
                 if (transaction) {
-#ifndef NO_LOGS
+                    ms_dbg_a(transaction, 8, "Invalid UTF-8 encoding: "
-                    transaction->debug(8, "Invalid UTF-8 encoding: "
                         "overlong character detected "
                         "at " + str + ". [offset \"" +
                         std::to_string(i) + "\"]");
-#endif
                     logOffset(ruleMessage, i, str.size());
                 }
                 return true;
                 break;
             case UNICODE_ERROR_RESTRICTED_CHARACTER :
                 if (transaction) {
-#ifndef NO_LOGS
+                    ms_dbg_a(transaction, 8, "Invalid UTF-8 encoding: "
-                    transaction->debug(8, "Invalid UTF-8 encoding: "
                         "use of restricted character "
                         "at " + str + ". [offset \"" +
                         std::to_string(i) + "\"]");
-#endif
                     logOffset(ruleMessage, i, str.size());
                 }
                 return true;
                 break;
             case UNICODE_ERROR_DECODING_ERROR :
                 if (transaction) {
-#ifndef NO_LOGS
+                    ms_dbg_a(transaction, 8, "Error validating UTF-8 decoding "
-                    transaction->debug(8, "Error validating UTF-8 decoding "
                         "at " + str + ". [offset \"" +
                         std::to_string(i) + "\"]");
-#endif
                     logOffset(ruleMessage, i, str.size());
                 }
                 return true;
@@ -186,11 +176,9 @@ bool ValidateUtf8Encoding::evaluate(Transaction *transaction, Rule *rule,
 
         if (rc <= 0) {
             if (transaction) {
-#ifndef NO_LOGS
+                ms_dbg_a(transaction, 8, "Internal error during UTF-8 validation "
-                transaction->debug(8, "Internal error during UTF-8 validation "
                     "at " + str + ". [offset \"" +
                     std::to_string(i) + "\"]");
-#endif
                 logOffset(ruleMessage, i, str.size());
             }
             return true;

src/operators/verify_cc.cc

@@ -145,16 +145,12 @@ bool VerifyCC::evaluate(Transaction *t, Rule *rule,
                     if (rule && t && rule->m_containsCaptureAction) {
                         t->m_collections.m_tx_collection->storeOrUpdateFirst(
                             "0", std::string(match));
-#ifndef NO_LOGS
+                        ms_dbg_a(t, 7, "Added VerifyCC match TX.0: " + \
-                        t->debug(7, "Added VerifyCC match TX.0: " + \
                             std::string(match));
-#endif
                     }
-#ifndef NO_LOGS
+                    ms_dbg_a(t, 9, "CC# match \"" + m_param +
-                    t->debug(9, "CC# match \"" + m_param +
                         "\" at " + i + ". [offset " +
                         std::to_string(offset) + "]");
-#endif
                 }
                 return true;
             }

src/operators/verify_cpf.cc

@@ -136,10 +136,8 @@ bool VerifyCPF::evaluate(Transaction *t, Rule *rule,
                 if (rule && t && rule->m_containsCaptureAction) {
                     t->m_collections.m_tx_collection->storeOrUpdateFirst(
                         "0", std::string(i.match));
-#ifndef NO_LOGS
+                    ms_dbg_a(t, 7, "Added VerifyCPF match TX.0: " + \
-                    t->debug(7, "Added VerifyCPF match TX.0: " + \
                         std::string(i.match));
-#endif
                 }
 
                 goto out;

src/operators/verify_ssn.cc

@@ -127,10 +127,8 @@ bool VerifySSN::evaluate(Transaction *t, Rule *rule,
                 if (rule && t && rule->m_containsCaptureAction) {
                     t->m_collections.m_tx_collection->storeOrUpdateFirst(
                         "0", std::string(i.match));
-#ifndef NO_LOGS
+                    ms_dbg_a(t, 7, "Added VerifySSN match TX.0: " + \
-                    t->debug(7, "Added VerifySSN match TX.0: " + \
                         std::string(i.match));
-#endif
                 }
 
                 goto out;

src/request_body_processor/json.h

@@ -79,12 +79,6 @@ class JSON {
     static int yajl_start_array(void *ctx);
     static int yajl_end_array(void *ctx);
 
-#ifndef NO_LOGS
-    void debug(int a, std::string str) {
-        m_transaction->debug(a, str);
-    }
-#endif
-
     bool isPreviousArray() {
         JSONContainerArray *prev = NULL;
         if (m_containers.size() < 1) {

src/request_body_processor/multipart.cc

@@ -69,12 +69,11 @@ Multipart::Multipart(std:: string header, Transaction *transaction)
 
 
 Multipart::~Multipart() {
-#ifndef NO_LOGS
+    ms_dbg_a(m_transaction, 4,
-    debug(4, "Multipart: Cleanup started (remove files " \
+        "Multipart: Cleanup started (remove files " \
         + RulesProperties::configBooleanString(
             m_transaction->m_rules->m_uploadKeepFiles) \
         + ")");
-#endif
 
     if (m_transaction->m_rules->m_uploadKeepFiles
         != RulesProperties::TrueConfigBoolean) {
@@ -86,21 +85,21 @@ Multipart::~Multipart() {
                         close(m->m_tmp_file_fd);
                         m->m_tmp_file_fd = -1;
                     }
-#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) \"" \
+                        ms_dbg_a(m_transaction, 1,
+                            "Multipart: Failed to delete file (part) \"" \
                             + m->m_tmp_file_name + "\" because " \
                             + std::to_string(errno) +  "(" \
                             + strerror(errno) + ")");
                     } else {
-                        debug(4, "Multipart: Failed to delete file (part) \"" \
+                        ms_dbg_a(m_transaction, 4,
+                            "Multipart: Failed to delete file (part) \"" \
                             + m->m_tmp_file_name + "\"");
                     }
-#endif
+
                 }
             }
         }
@@ -211,11 +210,10 @@ void Multipart::validate_quotes(const char *data)  {
 
     for (i = 0; i < len; i++)   {
         if (data[i] == '\'') {
-#ifndef NO_LOGS
+            ms_dbg_a(m_transaction, 9,
-            debug(9, "Multipart: Invalid quoting detected: " \
+                "Multipart: Invalid quoting detected: " \
                 + std::string(data) + " length " \
                 + std::to_string(len) + " bytes");
-#endif
             m_flag_invalid_quoting = 1;
         }
     }
@@ -356,36 +354,32 @@ 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
+                ms_dbg_a(m_transaction, 4,
-                debug(4, "Multipart: Warning: Duplicate Content-Disposition " \
+                    "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
+            ms_dbg_a(m_transaction, 9,
-            debug(9, "Multipart: Content-Disposition name: " + value + ".");
+                "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
+                ms_dbg_a(m_transaction, 4,
-                debug(4, "Multipart: Warning: Duplicate Content-Disposition " \
+                    "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
+            ms_dbg_a(m_transaction, 9,
-            debug(9, "Multipart: Content-Disposition filename: " \
+                "Multipart: Content-Disposition filename: " \
                 + value + ".");
-#endif
         } else {
             return -11;
         }
@@ -402,11 +396,10 @@ int Multipart::parse_content_disposition(const char *c_d_value, int offset) {
             if (*p != ';') {
                 p--;
                 if (*p == '\'' || *p == '\"') {
-#ifndef NO_LOGS
+                    ms_dbg_a(m_transaction, 9,
-                    debug(9, "Multipart: Invalid quoting detected: " \
+                        "Multipart: Invalid quoting detected: " \
                         + std::string(p) + " length " \
                         + std::to_string(strlen(p)) + " bytes");
-#endif
                     m_flag_invalid_quoting = 1;
                 }
                 p++;
@@ -497,12 +490,11 @@ 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) {
-#ifndef NO_LOGS
+                ms_dbg_a(m_transaction, 1,
-                debug(1, "Multipart: Upload file limit exceeded " \
+                    "Multipart: Upload file limit exceeded " \
-                + std::to_string(
+                    + std::to_string(
-                    m_transaction->m_rules->m_uploadFileLimit.m_value) \
+                        m_transaction->m_rules->m_uploadFileLimit.m_value) \
-                + ". Use SecUploadFileLimit to change the limit.");
+                    + ". 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) \
@@ -525,10 +517,9 @@ 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
+                    ms_dbg_a(m_transaction, 1,
-                    debug(1, "Multipart: Failed to create file: " \
+                        "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;
@@ -537,21 +528,19 @@ int Multipart::process_part_data(std::string *error, size_t offset) {
 
                 m_nfiles++;
 
-#ifndef NO_LOGS
+                ms_dbg_a(m_transaction, 4,
-                debug(4, "Multipart: Created temporary file " \
+                    "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
+                    ms_dbg_a(m_transaction, 1,
-                    debug(1, "Multipart: writing to \"" \
+                        "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;
@@ -570,10 +559,9 @@ 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
+                ms_dbg_a(m_transaction, 1,
-                debug(1, "Multipart: writing to \"" \
+                    "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;
@@ -627,14 +615,13 @@ 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
+        ms_dbg_a(m_transaction, 9,
-        debug(9, "Multipart: Added data to variable: " + d);
+            "Multipart: Added data to variable: " + d);
-#endif
     } else {
-#ifndef NO_LOGS
+        ms_dbg_a(m_transaction, 1,
-        debug(1, "Multipart: unknown part type: " \
+            "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;
@@ -664,9 +651,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
+            ms_dbg_a(m_transaction, 1,
-            debug(1, "Multipart: Nul byte in part headers.");
+                "Multipart: Nul byte in part headers.");
-#endif
+
             error->assign("Multipart: Nul byte in part headers.");
             return false;
         }
@@ -693,9 +680,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
+            ms_dbg_a(m_transaction, 1,
-            debug(1, "Multipart: Part missing Content-Disposition header.");
+                "Multipart: Part missing Content-Disposition header.");
-#endif
+
             error->assign("Multipart: Part missing " \
                 "Content-Disposition header.");
             return false;
@@ -705,20 +692,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
+            ms_dbg_a(m_transaction, 1,
-            debug(1, "Multipart: Invalid Content-Disposition header ("
+                "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
+            ms_dbg_a(m_transaction, 1,
-            debug(1, "Multipart: Content-Disposition header missing " \
+                "Multipart: Content-Disposition header missing " \
                 "name field.");
-#endif
+
             error->assign("Multipart: Content-Disposition header missing " \
                 "name field.");
 
@@ -731,10 +718,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
+                ms_dbg_a(m_transaction, 1,
-                debug(1, "Multipart: Invalid Content-Disposition " \
+                    "Multipart: Invalid Content-Disposition " \
                     "header (filename).");
-#endif
+
                 error->assign("Multipart: Invalid Content-Disposition " \
                     "header (filename).");
                 return false;
@@ -766,9 +753,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
+                ms_dbg_a(m_transaction, 1,
-                debug(1, "Multipart: Invalid part header (folding error).");
+                    "Multipart: Invalid part header (folding error).");
-#endif
+
                 error->assign("Multipart: Invalid part header " \
                     "(folding error).");
                 return false;
@@ -796,16 +783,14 @@ 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
+            ms_dbg_a(m_transaction, 9,
-            debug(9, "Multipart: Continued folder header \"" \
+                "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
+                ms_dbg_a(m_transaction, 1, "Multipart: Part header too long.");
-                debug(1, "Multipart: Part header too long.");
+
-#endif
                 error->assign("Multipart: Part header too long.");
                 return false;
             }
@@ -821,10 +806,10 @@ int Multipart::process_part_header(std::string *error, int offset) {
                 i++;
             }
             if (*data == '\0') {
-#ifndef NO_LOGS
+                ms_dbg_a(m_transaction, 1,
-                debug(1, "Multipart: Invalid part header (colon missing): " \
+                    "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;
@@ -833,10 +818,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
+                ms_dbg_a(m_transaction, 1,
-                debug(1, "Multipart: Invalid part header " \
+                    "Multipart: Invalid part header " \
                     "(header name missing).");
-#endif
+
                 error->assign("Multipart: Invalid part header " \
                     "(header name missing).");
                  return false;
@@ -854,10 +839,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
+                ms_dbg_a(m_transaction, 1,
-                debug(1, "Multipart: Duplicate part header: " \
+                    "Multipart: Duplicate part header: " \
                     + header_name + ".");
-#endif
+
                 return false;
             }
 
@@ -868,11 +853,9 @@ int Multipart::process_part_header(std::string *error, int offset) {
                 std::string(header_name), std::make_pair(offset - len + i,
                     std::string(header_value)));
 
-
+            ms_dbg_a(m_transaction, 9,
-#ifndef NO_LOGS
+                "Multipart: Added part header \"" + header_name \
-            debug(9, "Multipart: Added part header \"" + header_name \
                 + "\" \"" + header_value + "\".");
-#endif
         }
     }
 
@@ -904,27 +887,28 @@ 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 \"" \
+                ms_dbg_a(m_transaction, 9,
+                    "Multipart: Added file part to the list: name \"" \
                     + m_mpp->m_name + "\" "
                     "file name \"" + m_mpp->m_filename + "\" (offset " \
                     + std::to_string(m_mpp->m_offset) +
                     ", length " + std::to_string(m_mpp->m_length) + ")");
             } else {
-                debug(9, "Multipart: Added part to the list: name \"" \
+                ms_dbg_a(m_transaction, 9,
+                    "Multipart: Added part to the list: name \"" \
                     + m_mpp->m_name + "\" "
                     "(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
+            ms_dbg_a(m_transaction, 3,
-            debug(3, "Multipart: Skipping invalid part (part name missing): "
+                "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;
         }
 
@@ -960,45 +944,40 @@ int Multipart::multipart_complete(std::string *error) {
         std::to_string(m_flag_data_before),
         m_transaction->m_variableOffset);
     if (m_flag_data_before) {
-#ifndef NO_LOGS
+        ms_dbg_a(m_transaction, 4,
-        debug(4, "Multipart: Warning: seen data before first boundary.");
+            "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
+        ms_dbg_a(m_transaction, 4,
-        debug(4, "Multipart: Warning: seen data after last boundary.");
+            "Multipart: Warning: seen data after last boundary.");
-#endif
     }
 
     m_transaction->m_variableMultipartBoundaryQuoted.set(
         std::to_string(m_flag_boundary_quoted),
         m_transaction->m_variableOffset);
     if (m_flag_boundary_quoted) {
-#ifndef NO_LOGS
+        ms_dbg_a(m_transaction, 4,
-        debug(4, "Multipart: Warning: boundary was quoted.");
+            "Multipart: Warning: boundary was quoted.");
-#endif
     }
 
     m_transaction->m_variableMultipartBoundaryWhiteSpace.set(
         std::to_string(m_flag_boundary_whitespace),
         m_transaction->m_variableOffset);
     if (m_flag_boundary_whitespace) {
-#ifndef NO_LOGS
+        ms_dbg_a(m_transaction, 4,
-        debug(4, "Multipart: Warning: boundary whitespace in C-T header.");
+            "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
+        ms_dbg_a(m_transaction, 4,
-        debug(4, "Multipart: Warning: header folding used.");
+            "Multipart: Warning: header folding used.");
-#endif
     }
     m_transaction->m_variableMultipartLFLine.set(
         std::to_string(m_flag_lf_line),
@@ -1007,47 +986,41 @@ 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
+        ms_dbg_a(m_transaction, 4,
-        debug(4, "Multipart: Warning: mixed line endings used (CRLF/LF).");
+            "Multipart: Warning: mixed line endings used (CRLF/LF).");
-#endif
     } else if (m_flag_lf_line) {
-#ifndef NO_LOGS
+        ms_dbg_a(m_transaction, 4,
-        debug(4, "Multipart: Warning: incorrect line endings used (LF).");
+            "Multipart: Warning: incorrect line endings used (LF).");
-#endif
     }
     m_transaction->m_variableMultipartMissingSemicolon.set(
         std::to_string(m_flag_missing_semicolon),
         m_transaction->m_variableOffset);
     if (m_flag_missing_semicolon) {
-#ifndef NO_LOGS
+        ms_dbg_a(m_transaction, 4,
-        debug(4, "Multipart: Warning: missing semicolon in C-T header.");
+            "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
+        ms_dbg_a(m_transaction, 4,
-        debug(4, "Multipart: Warning: invalid quoting used.");
+            "Multipart: Warning: invalid quoting used.");
-#endif
     }
     m_transaction->m_variableMultipartInvalidPart.set(
         std::to_string(m_flag_invalid_part),
         m_transaction->m_variableOffset);
     if (m_flag_invalid_part) {
-#ifndef NO_LOGS
+        ms_dbg_a(m_transaction, 4,
-        debug(4, "Multipart: Warning: invalid part parsing.");
+            "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
+        ms_dbg_a(m_transaction, 4,
-        debug(4, "Multipart: Warning: invalid header folding used.");
+            "Multipart: Warning: invalid header folding used.");
-#endif
     }
 
     m_transaction->m_variableMultipartStrictError.set(
@@ -1086,16 +1059,14 @@ int Multipart::multipart_complete(std::string *error) {
             }
 
             if (m_is_complete == 0) {
-#ifndef NO_LOGS
+                ms_dbg_a(m_transaction, 1,
-                debug(1, "Multipart: Final boundary missing.");
+                    "Multipart: Final boundary missing.");
-#endif
                 error->assign("Multipart: Final boundary missing.");
                 return false;
             }
         } else {
-#ifndef NO_LOGS
+            ms_dbg_a(m_transaction, 1,
-            debug(1, "Multipart: No boundaries found in payload.");
+                "Multipart: No boundaries found in payload.");
-#endif
             error->assign("Multipart: No boundaries found in payload.");
             return false;
         }
@@ -1143,10 +1114,9 @@ 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
+            ms_dbg_a(m_transaction, 4,
-            debug(4, "Adding request argument (BODY): name \"" +
+                "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,
@@ -1217,27 +1187,23 @@ bool Multipart::init(std::string *error) {
 
     if (m_header.empty()) {
         m_flag_error = true;
-#ifndef NO_LOGS
+        ms_dbg_a(m_transaction, 4,
-        debug(4, "Multipart: Content-Type header not available.");
+            "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
+        ms_dbg_a(m_transaction, 4,
-        debug(4, "Multipart: Invalid boundary in C-T (length).");
+            "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
+        ms_dbg_a(m_transaction, 4, "Multipart: Invalid MIME type.");
-        debug(4, "Multipart: Invalid MIME type.");
-#endif
         error->assign("Multipart: Invalid MIME type.");
         return false;
     }
@@ -1245,9 +1211,8 @@ 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
+        ms_dbg_a(m_transaction, 4,
-        debug(4, "Multipart: Multiple boundary parameters in C-T.");
+            "Multipart: Multiple boundary parameters in C-T.");
-#endif
         error->assign("Multipart: Multiple boundary parameters in C-T.");
         return false;
     }
@@ -1268,10 +1233,9 @@ bool Multipart::init(std::string *error) {
                     seen_semicolon = 1; /* It is OK to have one semicolon. */
                 } else {
                     m_flag_error = 1;
-#ifndef NO_LOGS
+                    ms_dbg_a(m_transaction, 4,
-                    debug(4, "Multipart: Invalid boundary in C-T " \
+                        "Multipart: Invalid boundary in C-T " \
                         "(malformed).");
-#endif
                     error->assign("Multipart: Invalid boundary in C-T " \
                         "(malformed).");
                     return false;
@@ -1287,9 +1251,8 @@ bool Multipart::init(std::string *error) {
         b = strchr(m_boundary_tmp + 8, '=');
         if (b == NULL) {
             m_flag_error = 1;
-#ifndef NO_LOGS
+            ms_dbg_a(m_transaction, 4,
-            debug(4, "Multipart: Invalid boundary in C-T (malformed).");
+                "Multipart: Invalid boundary in C-T (malformed).");
-#endif
             error->assign("Multipart: Invalid boundary in C-T (malformed).");
             return false;
         }
@@ -1305,10 +1268,9 @@ bool Multipart::init(std::string *error) {
                     m_flag_boundary_whitespace = 1;
                 } else {
                     m_flag_error = 1;
-#ifndef NO_LOGS
+                    ms_dbg_a(m_transaction, 4,
-                    debug(4, "Multipart: Invalid boundary in C-T " \
+                        "Multipart: Invalid boundary in C-T " \
                         "(parameter name).");
-#endif
                     error->assign("Multipart: Invalid boundary in C-T " \
                         "(parameter name).");
                     return false;
@@ -1339,9 +1301,8 @@ bool Multipart::init(std::string *error) {
             if ((*b == '"')
                 || ((len >= 2) && (*(b + len - 1) == '"'))) {
                 m_flag_error = 1;
-#ifndef NO_LOGS
+                ms_dbg_a(m_transaction, 4,
-                debug(4, "Multipart: Invalid boundary in C-T (quote).");
+                    "Multipart: Invalid boundary in C-T (quote).");
-#endif
                 error->assign("Multipart: Invalid boundary in C-T (quote).");
                 return false;
             }
@@ -1357,9 +1318,8 @@ 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
+            ms_dbg_a(m_transaction, 4,
-            debug(4, "Multipart: Invalid boundary in C-T (content).");
+                "Multipart: Invalid boundary in C-T (content).");
-#endif
             error->assign("Multipart: Invalid boundary in C-T (content).");
             return false;
         }
@@ -1367,25 +1327,21 @@ 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
+            ms_dbg_a(m_transaction, 4,
-            debug(4, "Multipart: Invalid boundary in C-T (characters).");
+                "Multipart: Invalid boundary in C-T (characters).");
-#endif
             error->assign("Multipart: Invalid boundary in C-T (characters).");
             return false;
         }
 
-#ifndef NO_LOGS
+        ms_dbg_a(m_transaction, 9, "Multipart: Boundary" +
-        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
+            ms_dbg_a(m_transaction, 4,
-            debug(4, "Multipart: Invalid boundary in C-T (empty).");
+                "Multipart: Invalid boundary in C-T (empty).");
-#endif
             error->assign("Multipart: Invalid boundary in C-T (empty).");
             return false;
         }
@@ -1395,17 +1351,14 @@ 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
+            ms_dbg_a(m_transaction, 4,
-            debug(4, "Multipart: Invalid boundary in C-T (case sensitivity).");
+                "Multipart: Invalid boundary in C-T (case sensitivity).");
-#endif
             error->assign("Multipart: Invalid boundary in C-T " \
                 "(case sensitivity).");
             return false;
         }
 
-#ifndef NO_LOGS
+        ms_dbg_a(m_transaction, 4, "Multipart: Boundary not found in C-T.");
-        debug(4, "Multipart: Boundary not found in C-T.");
-#endif
         error->assign("Multipart: Boundary not found in C-T.");
         return false;
     }
@@ -1430,20 +1383,18 @@ bool Multipart::process(const std::string& data, std::string *error,
     if (m_is_complete) {
         m_flag_data_before = true;
 
-#ifndef NO_LOGS
+        ms_dbg_a(m_transaction, 4,
-        debug(4, "Multipart: Ignoring data after last boundary (received " \
+            "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
+        ms_dbg_a(m_transaction, 4,
-        debug(4, "Multipart: Internal error in process_chunk: no space left " \
+            "Multipart: Internal error in process_chunk: no space left " \
             "in the buffer");
-#endif
         return false;
     }
 
@@ -1503,10 +1454,10 @@ bool Multipart::process(const std::string& data, std::string *error,
 
                         if (m_is_complete != 0) {
                             m_flag_error = 1;
-#ifndef NO_LOGS
+                            ms_dbg_a(m_transaction, 4,
-                            debug(4, "Multipart: Invalid boundary " \
+                                "Multipart: Invalid boundary " \
                                 "(final duplicate).");
-#endif
+
                             error->assign("Multipart: Invalid boundary " \
                                 "(final duplicate).");
                             return false;
@@ -1539,10 +1490,9 @@ bool Multipart::process(const std::string& data, std::string *error,
                     } else {
                         /* error */
                         m_flag_error = 1;
-#ifndef NO_LOGS
+                        ms_dbg_a(m_transaction, 4,
-                        debug(4, "Multipart: Invalid boundary: " \
+                            "Multipart: Invalid boundary: " \
                             + std::string(m_buf));
-#endif
                         error->assign("Multipart: Invalid boundary: " \
                             + std::string(m_buf));
                         return false;
@@ -1559,9 +1509,8 @@ 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
+                        ms_dbg_a(m_transaction, 4,
-                        debug(4, "Multipart: Invalid boundary (quotes).");
+                            "Multipart: Invalid boundary (quotes).");
-#endif
                         error->assign("Multipart: Invalid boundary (quotes).");
                         return false;
                     }
@@ -1577,9 +1526,8 @@ 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
+                        ms_dbg_a(m_transaction, 4,
-                        debug(4, "Multipart: Invalid boundary (whitespace).");
+                            "Multipart: Invalid boundary (whitespace).");
-#endif
                         error->assign("Multipart: Invalid boundary " \
                             "(whitespace).");
                         return false;
@@ -1612,11 +1560,9 @@ bool Multipart::process(const std::string& data, std::string *error,
             if (processed_as_boundary == 0) {
                 if (m_mpp == NULL) {
                     m_flag_data_before = 1;
-
+                    ms_dbg_a(m_transaction, 4,
-#ifndef NO_LOGS
+                        "Multipart: Ignoring data before first " \
-                    debug(4, "Multipart: Ignoring data before first " \
                         "boundary.");
-#endif
                 } else {
                     if (m_mpp_state == 0) {
                         if ((m_bufleft == 0) || (process_buffer)) {
@@ -1624,11 +1570,10 @@ bool Multipart::process(const std::string& data, std::string *error,
                              * MULTIPART_BUF_SIZE bytes
                              */
                             m_flag_error = 1;
-#ifndef NO_LOGS
+                            ms_dbg_a(m_transaction, 4,
-                            debug(4, "Multipart: Part header line over " \
+                                "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");
@@ -1665,11 +1610,9 @@ bool Multipart::process(const std::string& data, std::string *error,
 
         if ((m_is_complete) && (inleft != 0)) {
             m_flag_data_after = 1;
-#ifndef NO_LOGS
+            ms_dbg_a(m_transaction, 4,
-            debug(4, "Multipart: Ignoring data after last boundary (" \
+                "Multipart: Ignoring data after last boundary (" \
                 + std::to_string(inleft) + "bytes left)");
-#endif
-
             return true;
         }
     }

src/request_body_processor/multipart.h

@@ -189,12 +189,6 @@ class Multipart {
     int m_flag_invalid_header_folding;
     int m_flag_file_limit_exceeded;
 
-#ifndef NO_LOGS
-    void debug(int a, std::string str) {
-        m_transaction->debug(a, str);
-    }
-#endif
-
  private:
     std::string m_header;
     Transaction *m_transaction;

src/request_body_processor/xml.cc

@@ -75,9 +75,7 @@ bool XML::processChunk(const char *buf, unsigned int size,
     if (m_data.parsing_ctx == NULL) {
         /* First invocation. */
 
-#ifndef NO_LOGS
+        ms_dbg_a(m_transaction, 4, "XML: Initialising parser.");
-        debug(4, "XML: Initialising parser.");
-#endif
 
         /* NOTE When Sax interface is used libxml will not
          *      create the document object, but we need it.
@@ -96,9 +94,8 @@ bool XML::processChunk(const char *buf, unsigned int size,
             buf, size, "body.xml");
 
         if (m_data.parsing_ctx == NULL) {
-#ifndef NO_LOGS
+            ms_dbg_a(m_transaction, 4,
-            debug(4, "XML: Failed to create parsing context.");
+                "XML: Failed to create parsing context.");
-#endif
             error->assign("XML: Failed to create parsing context.");
             return false;
         }
@@ -109,9 +106,7 @@ 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
+        ms_dbg_a(m_transaction, 4, "XML: Failed parsing document.");
-        debug(4, "XML: Failed parsing document.");
-#endif
         return false;
     }
 
@@ -132,16 +127,12 @@ bool XML::complete(std::string *error) {
         /* Clean up everything else. */
         xmlFreeParserCtxt(m_data.parsing_ctx);
         m_data.parsing_ctx = NULL;
-#ifndef NO_LOGS
+        ms_dbg_a(m_transaction, 4, "XML: Parsing complete (well_formed " \
-        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
+            ms_dbg_a(m_transaction, 4, "XML: Failed parsing document.");
-            debug(4, "XML: Failed parsing document.");
-#endif
             return false;
         }
     }

src/request_body_processor/xml.h

@@ -53,11 +53,6 @@ class XML {
     static xmlParserInputBufferPtr unloadExternalEntity(const char *URI,
         xmlCharEncoding enc);
 
-#ifndef NO_LOGS
-    void debug(int a, std::string str) {
-        m_transaction->debug(a, str);
-    }
-#endif
     xml_data m_data;
 
  private:

src/rule.cc

@@ -245,9 +245,7 @@ void Rule::cleanUpActions() {
 
 inline void Rule::updateMatchedVars(Transaction *trans, const std::string &key,
     const std::string &value) {
-#ifndef NO_LOGS
+    ms_dbg_a(trans, 9, "Matched vars updated.");
-    trans->debug(9, "Matched vars updated.");
-#endif
     trans->m_variableMatchedVar.set(value, trans->m_variableOffset);
     trans->m_variableMatchedVarName.set(key, trans->m_variableOffset);
 
@@ -257,9 +255,7 @@ inline void Rule::updateMatchedVars(Transaction *trans, const std::string &key,
 
 
 inline void Rule::cleanMatchedVars(Transaction *trans) {
-#ifndef NO_LOGS
+    ms_dbg_a(trans, 9, "Matched vars cleaned.");
-    trans->debug(9, "Matched vars cleaned.");
-#endif
     trans->m_variableMatchedVar.unset();
     trans->m_variableMatchedVars.unset();
     trans->m_variableMatchedVarName.unset();
@@ -271,10 +267,9 @@ void Rule::executeActionsIndependentOfChainedRuleResult(Transaction *trans,
     bool *containsBlock, std::shared_ptr<RuleMessage> ruleMessage) {
 
     for (actions::SetVar *a : m_actionsSetVar) {
-#ifndef NO_LOGS
+        ms_dbg_a(trans, 4, "Running [independent] (non-disruptive) " \
-        trans->debug(4, "Running [independent] (non-disruptive) " \
             "action: " + a->m_name);
-#endif
+
         a->evaluate(this, trans);
     }
 
@@ -285,15 +280,11 @@ void Rule::executeActionsIndependentOfChainedRuleResult(Transaction *trans,
         }
         actions::Action *a = dynamic_cast<actions::Action*>(b.second.get());
         if (a->isDisruptive() == true && a->m_name == "block") {
-#ifndef NO_LOGS
+            ms_dbg_a(trans, 9, "Rule contains a `block' action");
-            trans->debug(9, "Rule contains a `block' action");
                 *containsBlock = true;
-#endif
         } else if (a->m_name == "setvar") {
-#ifndef NO_LOGS
+            ms_dbg_a(trans, 4, "Running [independent] (non-disruptive) " \
-            trans->debug(4, "Running [independent] (non-disruptive) " \
                 "action: " + a->m_name);
-#endif
             a->evaluate(this, trans, ruleMessage);
         }
     }
@@ -321,14 +312,9 @@ bool Rule::executeOperatorAt(Transaction *trans, std::string key,
 #endif
     bool ret;
 
-#ifndef NO_LOGS
+    ms_dbg_a(trans, 9, "Target value: \"" + utils::string::limitTo(80,
-    if (trans && trans->m_rules && trans->m_rules->m_debugLog
+        utils::string::toHexIfNeeded(value)) \
-        && trans->m_rules->m_debugLog->getDebugLogLevel() >= 9) {
+        + "\" (Variable: " + key + ")");
-        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) {
@@ -339,10 +325,8 @@ bool Rule::executeOperatorAt(Transaction *trans, std::string key,
     end = clock();
     elapsed_s = static_cast<double>(end - begin) / CLOCKS_PER_SEC;
 
-#ifndef NO_LOGS
+    ms_dbg_a(trans, 5, "Operator completed in " + \
-    trans->debug(5, "Operator completed in " + \
         std::to_string(elapsed_s) + " seconds");
-#endif
 #endif
     return ret;
 }
@@ -375,12 +359,10 @@ inline void Rule::executeTransformation(actions::Action *a,
         path->append("," + a->m_name);
     }
 
-#ifndef NO_LOGS
+    ms_dbg_a(trans, 9, " T (" + \
-    trans->debug(9, " T (" + \
         std::to_string(*nth) + ") " + \
         a->m_name + ": \"" + \
         utils::string::limitTo(80, newValue) +"\"");
-#endif
 }
 
 
@@ -461,11 +443,9 @@ std::list<std::pair<std::shared_ptr<std::string>,
     }
 
     if (m_containsMultiMatchAction == true) {
-#ifndef NO_LOGS
+        ms_dbg_a(trans, 9, "multiMatch is enabled. " \
-        trans->debug(9, "multiMatch is enabled. " \
             + std::to_string(ret.size()) + \
             " values to be tested.");
-#endif
     }
 
     if (!m_containsMultiMatchAction) {
@@ -570,35 +550,27 @@ void Rule::executeAction(Transaction *trans,
     bool containsBlock, std::shared_ptr<RuleMessage> ruleMessage,
     Action *a, bool defaultContext) {
     if (a->isDisruptive() == false) {
-#ifndef NO_LOGS
+        ms_dbg_a(trans, 9, "Running " \
-        trans->debug(9, "Running " \
             "action: " + a->m_name);
-#endif
         a->evaluate(this, trans, ruleMessage);
         return;
     }
 
     if (defaultContext && !containsBlock) {
-#ifndef NO_LOGS
+        ms_dbg_a(trans, 4, "Ignoring action: " + a->m_name + \
-        trans->debug(4, "Ignoring action: " + a->m_name + \
             " (rule does not cotains block)");
-#endif
         return;
     }
 
     if (trans->getRuleEngineState() == Rules::EnabledRuleEngine) {
-#ifndef NO_LOGS
+        ms_dbg_a(trans, 4, "Running (disruptive)     action: " + a->m_name + \
-        trans->debug(4, "Running (disruptive)     action: " + a->m_name + \
             ".");
-#endif
         a->evaluate(this, trans, ruleMessage);
         return;
     }
 
-#ifndef NO_LOGS
+    ms_dbg_a(trans, 4, "Not running disruptive action: " \
-    trans->debug(4, "Not running disruptive action: " \
         + a->m_name + ". SecRuleEngine is not On.");
-#endif
 }
 
 
@@ -617,10 +589,8 @@ void Rule::executeActionsAfterFullMatch(Transaction *trans,
     }
 
     for (actions::Tag *a : this->m_actionsTag) {
-#ifndef NO_LOGS
+        ms_dbg_a(trans, 4, "Running (non-disruptive) action: " \
-        trans->debug(4, "Running (non-disruptive) action: " \
             + a->m_name);
-#endif
         a->evaluate(this, trans, ruleMessage);
     }
 
@@ -671,10 +641,8 @@ bool Rule::evaluate(Transaction *trans,
     }
 
     if (m_unconditional == true) {
-#ifndef NO_LOGS
+        ms_dbg_a(trans, 4, "(Rule: " + std::to_string(m_ruleId) \
-        trans->debug(4, "(Rule: " + std::to_string(m_ruleId) \
             + ") Executing unconditional rule...");
-#endif
         executeActionsIndependentOfChainedRuleResult(trans,
             &containsBlock, ruleMessage);
         goto end_exec;
@@ -684,10 +652,8 @@ bool Rule::evaluate(Transaction *trans,
         if (m_ruleId != i) {
             continue;
         }
-#ifndef NO_LOGS
+        ms_dbg_a(trans, 9, "Rule id: " + std::to_string(m_ruleId) +
-        trans->debug(9, "Rule id: " + std::to_string(m_ruleId) +
             " was skipped due to a ruleRemoveById action...");
-#endif
         return true;
     }
 
@@ -700,21 +666,17 @@ bool Rule::evaluate(Transaction *trans,
         } else {
             eparam = "\"" + eparam + "\"";
         }
-#ifndef NO_LOGS
+    ms_dbg_a(trans, 4, "(Rule: " + std::to_string(m_ruleId) \
-    trans->debug(4, "(Rule: " + std::to_string(m_ruleId) \
         + ") Executing operator \"" + this->m_op->m_op \
         + "\" with param " \
         + eparam \
         + " against " \
         + variables + ".");
-#endif
     } else {
-#ifndef NO_LOGS
+        ms_dbg_a(trans, 4, "(Rule: " + std::to_string(m_ruleId) \
-    trans->debug(4, "(Rule: " + std::to_string(m_ruleId) \
+            + ") Executing operator \"" + this->m_op->m_op \
-        + ") Executing operator \"" + this->m_op->m_op \
+            + " against " \
-        + " against " \
+            + variables + ".");
-        + variables + ".");
-#endif
     }
 
     getFinalVars(&vars, &exclusion, trans);
@@ -795,32 +757,23 @@ bool Rule::evaluate(Transaction *trans,
     }
 
     if (globalRet == false) {
-#ifndef NO_LOGS
+        ms_dbg_a(trans, 4, "Rule returned 0.");
-        trans->debug(4, "Rule returned 0.");
-#endif
         cleanMatchedVars(trans);
         goto end_clean;
     }
-
+    ms_dbg_a(trans, 4, "Rule returned 1.");
-#ifndef NO_LOGS
-    trans->debug(4, "Rule returned 1.");
-#endif
 
     if (this->m_chained == false) {
         goto end_exec;
     }
 
     if (this->m_chainedRuleChild == NULL) {
-#ifndef NO_LOGS
+        ms_dbg_a(trans, 4, "Rule is marked as chained but there " \
-        trans->debug(4, "Rule is marked as chained but there " \
             "isn't a subsequent rule.");
-#endif
         goto end_clean;
     }
 
-#ifndef NO_LOGS
+    ms_dbg_a(trans, 4, "Executing chained rule.");
-    trans->debug(4, "Executing chained rule.");
-#endif
     recursiveGlobalRet = this->m_chainedRuleChild->evaluate(trans, ruleMessage);
 
     if (recursiveGlobalRet == true) {

src/rule_script.cc

@@ -24,9 +24,8 @@ bool RuleScript::init(std::string *err) {
 
 bool RuleScript::evaluate(Transaction *trans,
     std::shared_ptr<RuleMessage> ruleMessage) {
-#ifndef NO_LOGS
+    ms_dbg_a(trans, 4, " Executing script: " + m_name + ".");
-    trans->debug(4, " Executing script: " + m_name + ".");
+
-#endif
     bool containsDisruptive = false;
 
     if (ruleMessage == NULL) {

src/rules.cc

@@ -158,18 +158,18 @@ int Rules::evaluate(int phase, Transaction *t) {
 
     std::vector<Rule *> rules = m_rules[phase];
 
-    t->debug(9, "This phase consists of " \
+    ms_dbg_a(t, 9, "This phase consists of " \
         + std::to_string(rules.size()) + " rule(s).");
 
     if (t->m_allowType == actions::disruptive::FromNowOnAllowType
         && phase != modsecurity::Phases::LoggingPhase) {
-        t->debug(9, "Skipping all rules evaluation on this phase as request " \
+        ms_dbg_a(t, 9, "Skipping all rules evaluation on this phase as request " \
             "through the utilization of an `allow' action.");
         return true;
     }
     if (t->m_allowType == actions::disruptive::RequestAllowType
         && phase <= modsecurity::Phases::RequestBodyPhase) {
-        t->debug(9, "Skipping all rules evaluation on this phase as request " \
+        ms_dbg_a(t, 9, "Skipping all rules evaluation on this phase as request " \
             "through the utilization of an `allow' action.");
         return true;
     }
@@ -180,17 +180,16 @@ int Rules::evaluate(int phase, Transaction *t) {
     for (int i = 0; i < rules.size(); i++) {
         Rule *rule = rules[i];
         if (t->m_marker.empty() == false) {
-#ifndef NO_LOGS
+            ms_dbg_a(t, 9, "Skipped rule id '" + std::to_string(rule->m_ruleId) \
-            t->debug(9, "Skipped rule id '" + std::to_string(rule->m_ruleId) \
                 + "' due to a SecMarker: " + t->m_marker);
-            m_secmarker_skipped++;
-            t->debug(9, "Rule: " + rule->m_marker);
-#endif
-            if (rule->m_secMarker && rule->m_marker == t->m_marker) {
 #ifndef NO_LOGS
-                t->debug(4, "Out of a SecMarker after skip " \
+            m_secmarker_skipped++;
-                    + std::to_string(m_secmarker_skipped) + " rules.");
 #endif
+            ms_dbg_a(t, 9, "Rule: " + rule->m_marker);
+
+            if (rule->m_secMarker && rule->m_marker == t->m_marker) {
+                ms_dbg_a(t, 4, "Out of a SecMarker after skip " \
+                    + std::to_string(m_secmarker_skipped) + " rules.");
                 t->m_marker.clear();
 #ifndef NO_LOGS
                 m_secmarker_skipped = 0;
@@ -198,22 +197,22 @@ int Rules::evaluate(int phase, Transaction *t) {
             }
         } else if (t->m_skip_next > 0) {
             t->m_skip_next--;
-            t->debug(9, "Skipped rule id '" + std::to_string(rule->m_ruleId) \
+            ms_dbg_a(t, 9, "Skipped rule id '" + std::to_string(rule->m_ruleId) \
                 + "' due to a `skip' action. Still " + \
                 std::to_string(t->m_skip_next) + " to be skipped.");
         } else if (t->m_allowType
             != actions::disruptive::NoneAllowType) {
-            t->debug(9, "Skipped rule id '" + std::to_string(rule->m_ruleId) \
+            ms_dbg_a(t, 9, "Skipped rule id '" + std::to_string(rule->m_ruleId) \
                 + "' as request trough the utilization of an `allow' action.");
         } else if (m_exceptions.contains(rule->m_ruleId)) {
-            t->debug(9, "Skipped rule id '" + std::to_string(rule->m_ruleId) \
+            ms_dbg_a(t, 9, "Skipped rule id '" + std::to_string(rule->m_ruleId) \
                 + "'. Removed by an SecRuleRemove directive.");
         } else {
             bool remove_rule = false;
             if (m_exceptions.m_remove_rule_by_msg.empty() == false) {
                 for (auto &z : m_exceptions.m_remove_rule_by_msg) {
                     if (rule->containsMsg(z, t) == true) {
-                        t->debug(9, "Skipped rule id '" \
+                        ms_dbg_a(t, 9, "Skipped rule id '" \
                             + std::to_string(rule->m_ruleId) \
                             + "'. Removed by a SecRuleRemoveByMsg directive.");
                         remove_rule = true;
@@ -228,7 +227,7 @@ int Rules::evaluate(int phase, Transaction *t) {
             if (m_exceptions.m_remove_rule_by_tag.empty() == false) {
                 for (auto &z : m_exceptions.m_remove_rule_by_tag) {
                     if (rule->containsTag(z, t) == true) {
-                        t->debug(9, "Skipped rule id '" \
+                        ms_dbg_a(t, 9, "Skipped rule id '" \
                             + std::to_string(rule->m_ruleId) \
                             + "'. Removed by a SecRuleRemoveByTag directive.");
                         remove_rule = true;
@@ -242,7 +241,7 @@ int Rules::evaluate(int phase, Transaction *t) {
 
             for (auto &z : t->m_ruleRemoveByTag) {
                 if (rule->containsTag(z, t) == true) {
-                    t->debug(9, "Skipped rule id '" \
+                    ms_dbg_a(t, 9, "Skipped rule id '" \
                         + std::to_string(rule->m_ruleId) \
                         + "'. Skipped due to a ruleRemoveByTag action.");
                     remove_rule = true;
@@ -252,7 +251,7 @@ int Rules::evaluate(int phase, Transaction *t) {
 
             rule->evaluate(t, NULL);
             if (t->m_it.disruptive == true) {
-                t->debug(8, "Skipping this phase as this " \
+                ms_dbg_a(t, 8, "Skipping this phase as this " \
                     "request was already intercepted.");
                 break;
             }

src/transaction.cc

@@ -138,9 +138,7 @@ Transaction::Transaction(ModSecurity *ms, Rules *rules, void *logCbData)
 
     m_variableUrlEncodedError.set("0", 0);
 
-#ifndef NO_LOGS
+    ms_dbg(4, "Initializing transaction");
-    this->debug(4, "Initializing transaction");
-#endif
 
     intervention::clean(&m_it);
 }
@@ -183,9 +181,7 @@ Transaction::Transaction(ModSecurity *ms, Rules *rules, char *id, void *logCbDat
 
     m_variableUrlEncodedError.set("0", 0);
 
-#ifndef NO_LOGS
+    ms_dbg(4, "Initializing transaction");
-    this->debug(4, "Initializing transaction");
-#endif
 
     intervention::clean(&m_it);
 }
@@ -262,10 +258,9 @@ int Transaction::processConnection(const char *client, int cPort,
     this->m_serverIpAddress = server;
     this->m_clientPort = cPort;
     this->m_serverPort = sPort;
-#ifndef NO_LOGS
+    ms_dbg(4, "Transaction context created.");
-    debug(4, "Transaction context created.");
+    ms_dbg(4, "Starting phase CONNECTION. (SecRules 0)");
-    debug(4, "Starting phase CONNECTION. (SecRules 0)");
+
-#endif
 
     m_variableRemoteHost.set(m_clientIpAddress, m_variableOffset);
     m_variableUniqueID.set(m_id, m_variableOffset);
@@ -344,10 +339,8 @@ 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
+    ms_dbg(4, "Adding request argument (" + orig + "): name \"" + \
-    debug(4, "Adding request argument (" + orig + "): name \"" + \
                 key + "\", value \"" + value + "\"");
-#endif
 
     size_t k_offset = offset;
     offset = offset + key.size() + 1;
@@ -400,9 +393,7 @@ bool Transaction::addArgument(const std::string& orig, const std::string& key,
 int Transaction::processURI(const char *uri, const char *method,
     const char *http_version) {
 
-#ifndef NO_LOGS
+    ms_dbg(4, "Starting phase URI. (SecRules 0 + 1/2)");
-    debug(4, "Starting phase URI. (SecRules 0 + 1/2)");
-#endif
 
     m_httpVersion = http_version;
     m_uri = uri;
@@ -519,14 +510,10 @@ int Transaction::processURI(const char *uri, const char *method,
  *
  */
 int Transaction::processRequestHeaders() {
-#ifndef NO_LOGS
+    ms_dbg(4, "Starting phase REQUEST_HEADERS.  (SecRules 1)");
-    debug(4, "Starting phase REQUEST_HEADERS.  (SecRules 1)");
-#endif
 
     if (getRuleEngineState() == Rules::DisabledRuleEngine) {
-#ifndef NO_LOGS
+        ms_dbg(4, "Rule engine disabled, returning...");
-        debug(4, "Rule engine disabled, returning...");
-#endif
         return true;
     }
 
@@ -692,14 +679,10 @@ int Transaction::addRequestHeader(const unsigned char *key, size_t key_n,
  *
  */
 int Transaction::processRequestBody() {
-#ifndef NO_LOGS
+    ms_dbg(4, "Starting phase REQUEST_BODY. (SecRules 2)");
-    debug(4, "Starting phase REQUEST_BODY. (SecRules 2)");
-#endif
 
     if (getRuleEngineState() == RulesProperties::DisabledRuleEngine) {
-#ifndef NO_LOGS
+        ms_dbg(4, "Rule engine disabled, returning...");
-        debug(4, "Rule engine disabled, returning...");
-#endif
         return true;
     }
 
@@ -813,24 +796,18 @@ int Transaction::processRequestBody() {
 
     if (m_rules->m_secRequestBodyAccess == RulesProperties::FalseConfigBoolean) {
         if (m_requestBodyAccess != RulesProperties::TrueConfigBoolean) {
-#ifndef NO_LOGS
+            ms_dbg(4, "Request body processing is disabled");
-            debug(4, "Request body processing is disabled");
-#endif
             return true;
         } else {
-#ifndef NO_LOGS
+            ms_dbg(4, "Request body processing is disabled, but " \
-            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
+            ms_dbg(4, "Request body processing is enabled, but " \
-            debug(4, "Request body processing is enabled, but " \
                 "disabled to this transaction due to ctl:requestBodyAccess " \
                 "action");
-#endif
             return true;
         }
     }
@@ -896,9 +873,7 @@ int Transaction::requestBodyFromFile(const char *path) {
     std::string str;
 
     if (request_body.is_open() == false) {
-#ifndef NO_LOGS
+        ms_dbg(3, "Failed to open request body at: " + std::string(path));
-        debug(3, "Failed to open request body at: " + std::string(path));
-#endif
         return false;
     }
 
@@ -906,9 +881,7 @@ int Transaction::requestBodyFromFile(const char *path) {
     try {
         str.reserve(request_body.tellg());
     } catch (...) {
-#ifndef NO_LOGS
+        ms_dbg(3, "Failed to allocate memory to load request body.");
-        debug(3, "Failed to allocate memory to load request body.");
-#endif
         return false;
     }
     request_body.seekg(0, std::ios::beg);
@@ -918,11 +891,9 @@ int Transaction::requestBodyFromFile(const char *path) {
     const char *buf = str.c_str();
     int len = request_body.tellg();
 
-#ifndef NO_LOGS
+    ms_dbg(9, "Adding request body: " + std::to_string(len) + " bytes. " \
-    debug(9, "Adding request body: " + std::to_string(len) + " bytes. " \
         "Limit set to: "
         + std::to_string(this->m_rules->m_requestBodyLimit.m_value));
-#endif
 
     return appendRequestBody(reinterpret_cast<const unsigned char*>(buf), len);
 }
@@ -930,35 +901,28 @@ int Transaction::requestBodyFromFile(const char *path) {
 int Transaction::appendRequestBody(const unsigned char *buf, size_t len) {
     int current_size = this->m_requestBody.tellp();
 
-#ifndef NO_LOGS
+    ms_dbg(9, "Appending request body: " + std::to_string(len) + " bytes. " \
-    debug(9, "Appending request body: " + std::to_string(len) + " bytes. " \
         "Limit set to: "
         + std::to_string(this->m_rules->m_requestBodyLimit.m_value));
-#endif
 
     if (this->m_rules->m_requestBodyLimit.m_value > 0
         && this->m_rules->m_requestBodyLimit.m_value < len + current_size) {
         m_variableInboundDataError.set("1", m_variableOffset);
-#ifndef NO_LOGS
+        ms_dbg(5, "Request body is bigger than the maximum expected.");
-        debug(5, "Request body is bigger than the maximum expected.");
+
-#endif
         if (this->m_rules->m_requestBodyLimitAction ==
             Rules::BodyLimitAction::ProcessPartialBodyLimitAction) {
             size_t spaceLeft = this->m_rules->m_requestBodyLimit.m_value
                 - current_size;
             this->m_requestBody.write(reinterpret_cast<const char*>(buf),
                 spaceLeft);
-#ifndef NO_LOGS
+            ms_dbg(5, "Request body limit is marked to process partial");
-            debug(5, "Request body limit is marked to process partial");
-#endif
             return false;
         } else {
             if (this->m_rules->m_requestBodyLimitAction ==
                 Rules::BodyLimitAction::RejectBodyLimitAction) {
-#ifndef NO_LOGS
+                ms_dbg(5, "Request body limit is marked to reject the " \
-                debug(5, "Request body limit is marked to reject the " \
                     "request");
-#endif
                 intervention::free(&m_it);
                 m_it.log = strdup("Request body limit is marked to " \
                         "reject the request");
@@ -993,18 +957,14 @@ int Transaction::appendRequestBody(const unsigned char *buf, size_t len) {
  *
  */
 int Transaction::processResponseHeaders(int code, const std::string& proto) {
-#ifndef NO_LOGS
+    ms_dbg(4, "Starting phase RESPONSE_HEADERS. (SecRules 3)");
-    debug(4, "Starting phase RESPONSE_HEADERS. (SecRules 3)");
-#endif
 
     this->m_httpCodeReturned = code;
     m_variableResponseStatus.set(std::to_string(code), m_variableOffset);
     m_variableResponseProtocol.set(proto, m_variableOffset);
 
     if (getRuleEngineState() == Rules::DisabledRuleEngine) {
-#ifndef NO_LOGS
+        ms_dbg(4, "Rule engine disabled, returning...");
-        debug(4, "Rule engine disabled, returning...");
-#endif
         return true;
     }
 
@@ -1122,21 +1082,15 @@ int Transaction::addResponseHeader(const unsigned char *key, size_t key_n,
  *
  */
 int Transaction::processResponseBody() {
-#ifndef NO_LOGS
+    ms_dbg(4, "Starting phase RESPONSE_BODY. (SecRules 4)");
-    debug(4, "Starting phase RESPONSE_BODY. (SecRules 4)");
-#endif
 
     if (getRuleEngineState() == Rules::DisabledRuleEngine) {
-#ifndef NO_LOGS
+        ms_dbg(4, "Rule engine disabled, returning...");
-        debug(4, "Rule engine disabled, returning...");
-#endif
         return true;
     }
 
     if (m_rules->m_secResponseBodyAccess != RulesProperties::TrueConfigBoolean) {
-#ifndef NO_LOGS
+        ms_dbg(4, "Response body is disabled, returning... " + std::to_string(m_rules->m_secResponseBodyAccess));
-        debug(4, "Response body is disabled, returning... " + std::to_string(m_rules->m_secResponseBodyAccess));
-#endif
         return true;
     }
 
@@ -1145,8 +1099,7 @@ int Transaction::processResponseBody() {
     auto t = bi.find(m_variableResponseContentType.m_value);
     if (t == bi.end()
         && m_rules->m_responseBodyTypeToBeInspected.m_set == true) {
-#ifndef NO_LOGS
+        ms_dbg(5, "Response Content-Type is " \
-        debug(5, "Response Content-Type is " \
             + m_variableResponseContentType.m_value \
             + ". It is not marked to be inspected.");
         std::string validContetTypes("");
@@ -1154,9 +1107,8 @@ int Transaction::processResponseBody() {
              i != bi.end(); i++) {
             validContetTypes.append(*i + " ");
         }
-        debug(8, "Content-Type(s) marked to be inspected: " \
+        ms_dbg(8, "Content-Type(s) marked to be inspected: " \
             + validContetTypes);
-#endif
         return true;
     }
     if (m_variableOutboundDataError.m_value.empty() == true) {
@@ -1197,44 +1149,34 @@ int Transaction::appendResponseBody(const unsigned char *buf, size_t len) {
         this->m_rules->m_responseBodyTypeToBeInspected.m_value;
     auto t = bi.find(m_variableResponseContentType.m_value);
     if (t == bi.end() && bi.empty() == false) {
-#ifndef NO_LOGS
+        ms_dbg(4, "Not appending response body. " \
-        debug(4, "Not appending response body. " \
             "Response Content-Type is " \
             + m_variableResponseContentType.m_value \
             + ". It is not marked to be inspected.");
-#endif
         return true;
     }
 
-#ifndef NO_LOGS
+    ms_dbg(9, "Appending response body: " + std::to_string(len + current_size)
-    debug(9, "Appending response body: " + std::to_string(len + current_size)
         + " bytes. Limit set to: " +
         std::to_string(this->m_rules->m_responseBodyLimit.m_value));
-#endif
 
     if (this->m_rules->m_responseBodyLimit.m_value > 0
         && this->m_rules->m_responseBodyLimit.m_value < len + current_size) {
         m_variableOutboundDataError.set("1", m_variableOffset);
-#ifndef NO_LOGS
+        ms_dbg(5, "Response body is bigger than the maximum expected.");
-        debug(5, "Response body is bigger than the maximum expected.");
-#endif
         if (this->m_rules->m_responseBodyLimitAction ==
             Rules::BodyLimitAction::ProcessPartialBodyLimitAction) {
             size_t spaceLeft = this->m_rules->m_responseBodyLimit.m_value \
                 - current_size;
             this->m_responseBody.write(reinterpret_cast<const char*>(buf),
                 spaceLeft);
-#ifndef NO_LOGS
+            ms_dbg(5, "Response body limit is marked to process partial");
-            debug(5, "Response body limit is marked to process partial");
-#endif
             return false;
         } else {
             if (this->m_rules->m_responseBodyLimitAction ==
                 Rules::BodyLimitAction::RejectBodyLimitAction) {
-#ifndef NO_LOGS
+                ms_dbg(5, "Response body limit is marked to reject the " \
-                debug(5, "Response body limit is marked to reject the " \
                     "request");
-#endif
                 intervention::free(&m_it);
                 m_it.log = strdup("Response body limit is marked to reject " \
                     "the request");
@@ -1323,14 +1265,10 @@ size_t Transaction::getRequestBodyLength() {
  *
  */
 int Transaction::processLogging() {
-#ifndef NO_LOGS
+    ms_dbg(4, "Starting phase LOGGING. (SecRules 5)");
-    debug(4, "Starting phase LOGGING. (SecRules 5)");
-#endif
 
     if (getRuleEngineState() == Rules::DisabledRuleEngine) {
-#ifndef NO_LOGS
+        ms_dbg(4, "Rule engine disabled, returning...");
-        debug(4, "Rule engine disabled, returning...");
-#endif
         return true;
     }
 
@@ -1339,20 +1277,14 @@ int Transaction::processLogging() {
     /* If relevant, save this transaction information at the audit_logs */
     if (m_rules != NULL && m_rules->m_auditLog != NULL) {
         int parts = this->m_rules->m_auditLog->getParts();
-#ifndef NO_LOGS
+        ms_dbg(8, "Checking if this request is suitable to be " \
-        debug(8, "Checking if this request is suitable to be " \
             "saved as an audit log.");
-#endif
 
         if (this->m_auditLogModifier.size() > 0) {
-#ifndef NO_LOGS
+            ms_dbg(4, "There was an audit log modifier for this transaction.");
-            debug(4, "There was an audit log modifier for this transaction.");
-#endif
             std::list<std::pair<int, std::string>>::iterator it;
-#ifndef NO_LOGS
+            ms_dbg(7, "AuditLog parts before modification(s): " +
-            debug(7, "AuditLog parts before modification(s): " +
                 std::to_string(parts) + ".");
-#endif
             for (it = m_auditLogModifier.begin();
                 it != m_auditLogModifier.end(); ++it) {
                 std::pair <int, std::string> p = *it;
@@ -1365,16 +1297,12 @@ int Transaction::processLogging() {
                 }
             }
         }
-#ifndef NO_LOGS
+        ms_dbg(8, "Checking if this request is relevant to be " \
-        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
+            ms_dbg(8, "Request was relevant to be saved. Parts: " +
-            debug(8, "Request was relevant to be saved. Parts: " +
                 std::to_string(parts));
-#endif
         }
     }
 

src/variables/xml.cc

@@ -82,42 +82,32 @@ 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
+        ms_dbg_a(t, 1, "XML: Unable to create new XPath context. : ");
-        t->debug(1, "XML: Unable to create new XPath context. : ");
-#endif
         return;
     }
 
     if (rule == NULL) {
-#ifndef NO_LOGS
+        ms_dbg_a(t, 2, "XML: Can't look for xmlns, internal error.");
-        t->debug(2, "XML: Can't look for xmlns, internal error.");
-#endif
     } else {
         std::vector<actions::Action *> acts = rule->getActionsByName("xmlns", t);
         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
+                ms_dbg_a(t, 1, "Failed to register XML namespace href \"" + \
-                t->debug(1, "Failed to register XML namespace href \"" + \
                     z->m_href + "\" prefix \"" + z->m_scope + "\".");
-#endif
                 return;
             }
 
-#ifndef NO_LOGS
+            ms_dbg_a(t, 4, "Registered XML namespace href \"" + z->m_href + \
-            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
+        ms_dbg_a(t, 1, "XML: Unable to evaluate xpath expression.");
-        t->debug(1, "XML: Unable to evaluate xpath expression.");
-#endif
         xmlXPathFreeContext(xpathCtx);
         return;
     }

test/regression/regression.cc

@@ -169,6 +169,7 @@ void perform_unit_test(ModSecurityTest<RegressionTest> *test,
             continue;
         }
 
+        modsec_rules->load("SecDebugLogLevel 9");
         if (modsec_rules->load(t->rules.c_str(), filename) < 0) {
             /* Parser error */
             if (t->parser_error.empty() == true) {

test/test-cases/regression/collection-tx.json

@@ -272,5 +272,66 @@
       "SecRule REQUEST_HEADERS \"@contains PHPSESSID\" \"id:3,t:lowercase,t:none,setvar:TX.something=-5\"",
       "SecRule TX \"@contains to_test\" \"id:4,t:lowercase,t:none\""
     ]
+  },
+  {
+    "enabled":1,
+    "version_min":300000,
+    "version_max":0,
+    "title":"Testing collection :: TX (5/n)",
+    "client":{  
+      "ip":"200.249.12.31",
+      "port":2313
+    },
+    "server":{  
+      "ip":"200.249.12.31",
+      "port":80
+    },
+    "request":{  
+      "headers":{  
+        "User-Agent":"Mozilla\/5.0 (Windows; U; Windows NT 6.1; en-US; rv:1.9.1.5) Gecko\/20091102 Firefox\/3.5.5 (.NET CLR 3.5.30729)",
+        "Accept":"text\/html,application\/xhtml+xml,application\/xml;q=0.9,*\/*;q=0.8",
+        "Accept-Language":"en-us,en;q=0.5",
+        "Accept-Encoding":"gzip,deflate",
+        "Accept-Charset":"ISO-8859-1,utf-8;q=0.7,*;q=0.7",
+        "Keep-Alive":"300",
+        "Connection":"keep-alive",
+        "Cookie":"PHPSESSID=rAAAAAAA2t5uvjq435r4q7ib3vtdjq120 - cookie I",
+        "Cookie2":"PHPSESSID=rAAAAAAA2t5uvjq435r4q7ib3vtdjq120 - cookie II",
+        "Pragma":"no-cache",
+        "Cache-Control":"no-cache"
+      },
+      "uri":"\/test.pl?param1=   test   &param2=test2",
+      "method":"GET",
+      "http_version":1.1,
+      "body":""
+    },
+    "response":{  
+      "headers":{  
+        "Content-Type":"text\/xml; charset=utf-8\n\r",
+        "Content-Length":"length\n\r"
+      },
+      "body":[  
+        "<?xml version=\"1.0\" encoding=\"utf-8\"?>\n\r",
+        "<soap:Envelope xmlns:xsi=\"http:\/\/www.w3.org\/2001\/XMLSchema-instance\" xmlns:xsd=\"http:\/\/www.w3.org\/2001\/XMLSchema\" xmlns:soap=\"http:\/\/schemas.xmlsoap.org\/soap\/envelope\/\">\n\r",
+        "  <soap:Body>\n\r",
+        "  <EnlightenResponse xmlns=\"http:\/\/clearforest.com\/\">\n\r",
+        "  <EnlightenResult>string<\/EnlightenResult>\n\r",
+        "  <\/EnlightenResponse>\n\r",
+        "  <\/soap:Body>\n\r",
+        "<\/soap:Envelope>\n\r"
+      ]
+    },
+    "expected":{  
+      "audit_log":"",
+      "debug_log":"Target value: \"40\" \\(Variable: TX:anomaly_score\\)",
+      "error_log":""
+    },
+    "rules":[  
+      "SecRuleEngine On",
+      "SecRule REQUEST_HEADERS:Cookie \"@contains PHPSESSID\" \"id:1,setvar:tx.critical_anomaly_score=5\"",
+      "SecRule REQUEST_HEADERS:Cookie \"@contains PHPSESSID\" \"id:2,setvar:tx.anomaly_score=10\"",
+      "SecRule REQUEST_HEADERS:Cookie|REQUEST_HEADERS:Cookie2 \"@contains ookie\" \"id:4,t:lowercase,t:removewhitespace,multimatch,setvar:tx.anomaly_score=+%{tx.critical_anomaly_score}\"",
+      "SecRule TX \"@contains to_test\" \"id:100\""
+    ]
   }
 ]