Refectoring on the DebugLog mechanism

The DebugLog implementation was modified to use shared memory
to keep the information about the opened files and file handles.
The modification was necessary to avoid race-conditions. This
commit also closes the issue SpiderLabs/ModSecurity-nginx#17

headers/modsecurity/debug_log.h

@@ -42,7 +42,7 @@ class DebugLog {
     bool isLogFileSet();
     bool isLogLevelSet();
     void setDebugLogLevel(int level);
-    void setDebugLogFile(const std::string &fileName);
+    void setDebugLogFile(const std::string &fileName, std::string *error);
     const std::string& getDebugLogFile();
     int getDebugLogLevel();
 

headers/modsecurity/rules_properties.h

@@ -330,10 +330,23 @@ class RulesProperties {
 
         if (from->m_debugLog && to->m_debugLog &&
             from->m_debugLog->isLogFileSet()) {
+            std::string error;
             to->m_debugLog->setDebugLogFile(
-                from->m_debugLog->getDebugLogFile());
+                from->m_debugLog->getDebugLogFile(),
+                &error);
+            if (error.size() > 0) {
+                *err << error;
+                return -1;
+            }
         }
 
+        if (from->m_debugLog && to->m_debugLog &&
+            from->m_debugLog->isLogLevelSet()) {
+            to->m_debugLog->setDebugLogLevel(
+                from->m_debugLog->getDebugLogLevel());
+        }
+
+
         return amount_of_rules;
     }
 

src/Makefile.am

@@ -244,7 +244,6 @@ libmodsecurity_la_SOURCES = \
 	utils.cc \
 	debug_log.cc \
 	debug_log_writer.cc \
-	debug_log_writer_agent.cc \
 	macro_expansion.cc \
 	rule.cc \
 	unique_id.cc \

src/debug_log.cc

@@ -29,13 +29,14 @@ DebugLog::~DebugLog() {
     DebugLogWriter::getInstance().close(m_fileName);
 }
 
-void DebugLog::setDebugLogFile(const std::string& fileName) {
-    m_fileName = fileName;
+void DebugLog::setDebugLogFile(const std::string& fileName, std::string *error) {
     if (isLogFileSet()) {
         DebugLogWriter::getInstance().close(m_fileName);
     }
 
-    DebugLogWriter::getInstance().open(m_fileName);
+    m_fileName = fileName;
+
+    DebugLogWriter::getInstance().open(m_fileName, error);
 }
 
 
@@ -70,8 +71,9 @@ int DebugLog::getDebugLogLevel() {
 
 void DebugLog::write(int level, const std::string &msg) {
     if (level <= m_debugLevel) {
-        DebugLogWriter::getInstance().write(m_fileName, "[" \
-            + std::to_string(level) + "] " + msg);
+        std::string msgf = "[" + std::to_string(level) + "] " + msg;
+        DebugLogWriter &d = DebugLogWriter::getInstance();
+        d.write_log(m_fileName, msgf);
     }
 }
 

src/debug_log_writer.cc

@@ -15,56 +15,227 @@
 
 #include "src/debug_log_writer.h"
 
-#include <stddef.h>
-
+#include <errno.h>
+#include <fcntl.h>
 #include <fstream>
-
-#include "src/debug_log_writer_agent.h"
+#include <pthread.h>
+#include <stddef.h>
+#include <stdio.h>
+#include <sys/ipc.h>
+#include <sys/shm.h>
+#include <sys/stat.h>
+#include <sys/types.h>
+#include <unistd.h>
 
 namespace modsecurity {
 
 
-void DebugLogWriter::open(const std::string& fileName) {
-    std::map<std::string, DebugLogWriterAgent *>::iterator it;
-    DebugLogWriterAgent *agent;
-
-    it = agents.find(fileName);
-    if (it != agents.end()) {
-        agent = it->second;
-    } else {
-        agent = new DebugLogWriterAgent(fileName);
-        agents[fileName] = agent;
+debug_log_file_handler_t *DebugLogWriter::find_handler(
+    const std::string &fileName) {
+    debug_log_file_handler_t *current = m_first;
+    while (current != NULL) {
+        if (current->file_name == fileName) {
+            return current;
+        }
+        current = (debug_log_file_handler_t *) current->next;
     }
-    agent->refCountIncrease();
+
+    return NULL;
+}
+
+
+debug_log_file_handler_t *DebugLogWriter::add_new_handler(
+    const std::string &fileName, std::string *error) {
+    debug_log_file_handler_t *current = m_first;
+    int shm_id;
+    key_t mem_key_structure;
+    key_t mem_key_file_name;
+    debug_log_file_handler_t *new_debug_log;
+    char *shm_ptr2;
+    FILE *fp;
+
+    fp = fopen(fileName.c_str(), "a");
+    if (fp <= 0) {
+        error->assign("Failed to open file: " + fileName);
+        goto err_fh;
+    }
+
+    mem_key_structure = ftok(fileName.c_str(), 1);
+    if (mem_key_structure < 0) {
+        error->assign("Failed to select key for the shared memory (1): ");
+        error->append(strerror(errno));
+        goto err_mem_key1;
+    }
+
+    mem_key_file_name = ftok(fileName.c_str(), 2);
+    if (mem_key_file_name < 0) {
+        error->assign("Failed to select key for the shared memory (2): ");
+        error->append(strerror(errno));
+        goto err_mem_key1;
+    }
+
+    shm_id = shmget(mem_key_structure, sizeof (debug_log_file_handler_t),
+        IPC_CREAT | 0666);
+    if (shm_id < 0) {
+        error->assign("Failed to allocate shared memory (1): ");
+        error->append(strerror(errno));
+        goto err_shmget1;
+    }
+
+    new_debug_log = (debug_log_file_handler_t *) shmat(shm_id, NULL, 0);
+    if (((char *)new_debug_log)[0] == -1) {
+        error->assign("Failed to attach shared memory (1): ");
+        error->append(strerror(errno));
+        goto err_shmat1;
+    }
+    memset(new_debug_log, '\0', sizeof(debug_log_file_handler_t));
+
+    pthread_mutex_init(&new_debug_log->lock, NULL);
+    new_debug_log->fp = fp;
+    new_debug_log->file_handler = fileno(new_debug_log->fp);
+    new_debug_log->next = NULL;
+    new_debug_log->previous = NULL;
+    new_debug_log->shm_id_structure = shm_id;
+    shm_id = shmget(mem_key_file_name, (fileName.size() + 1 * sizeof(char)),
+        IPC_CREAT | 0666);
+    if (shm_id < 0) {
+        error->assign("Failed to allocate shared memory (2): ");
+        error->append(strerror(errno));
+        goto err_shmget2;
+    }
+    new_debug_log->shm_id_file_name = shm_id;
+    shm_ptr2 = (char *) shmat(shm_id, NULL, 0);
+    if (shm_ptr2[0] == -1) {
+        error->assign("Failed to attach shared memory (2): ");
+        error->append(strerror(errno));
+        goto err_shmat2;
+    }
+    memset(shm_ptr2, '\0', sizeof (debug_log_file_handler_t));
+    memcpy(shm_ptr2, fileName.c_str(), fileName.size());
+
+    new_debug_log->file_name = shm_ptr2;
+
+    if (m_first == NULL) {
+        m_first = new_debug_log;
+    } else {
+        current = m_first;
+        while (current != NULL) {
+            if (current->next == NULL) {
+                current->next = new_debug_log;
+                new_debug_log->previous = current;
+                new_debug_log->next = NULL;
+                current = NULL;
+            } else {
+                current = (debug_log_file_handler_t *) current->next;
+            }
+        }
+    }
+
+    return new_debug_log;
+err_shmget2:
+err_shmat2:
+    shmdt(shm_ptr2);
+    fclose(new_debug_log->fp);
+err_shmget1:
+err_shmat1:
+    shmdt(new_debug_log);
+err_mem_key2:
+err_mem_key1:
+err_fh:
+    return NULL;
+}
+
+
+int DebugLogWriter::open(const std::string& fileName, std::string *error) {
+    debug_log_file_handler_t *a = find_handler(fileName);
+    if (a == NULL) {
+        a = add_new_handler(fileName, error);
+        if (error->size() > 0) {
+            return -1;
+        }
+    }
+    if (a == NULL) {
+        error->assign("Not able to open DebugLog: " + fileName);
+        return -1;
+    }
+
+    a->using_it++;
+
+    return 0;
 }
 
 
 void DebugLogWriter::close(const std::string& fileName) {
-    std::map<std::string, DebugLogWriterAgent *>::iterator it;
-    it = agents.find(fileName);
-    if (it != agents.end()) {
-        DebugLogWriterAgent *agent;
-        agent = it->second;
-        if (agent->refCountDecreaseAndCheck()) {
-            delete agent;
-            agents.erase(it);
+    debug_log_file_handler_t *a;
+    bool first = false;
+
+    if (fileName.empty()) {
+        return;
+    }
+
+    a = find_handler(fileName);
+    if (a == NULL) {
+        return;
+    }
+
+    a->using_it--;
+
+    if (a->using_it == 0) {
+        int shm_id1 = a->shm_id_structure;
+        int shm_id2 = a->shm_id_file_name;
+        debug_log_file_handler_t *p , *n;
+        pthread_mutex_lock(&a->lock);
+        fclose(a->fp);
+
+        p = (debug_log_file_handler_t *) a->previous;
+        n = (debug_log_file_handler_t *) a->next;
+        if (p != NULL) {
+            p->next = (debug_log_file_handler_t *) n;
         }
+        if (n != NULL) {
+            n->previous = (debug_log_file_handler_t *) p;
+        }
+        a->previous = NULL;
+        a->next = NULL;
+        pthread_mutex_unlock(&a->lock);
+        pthread_mutex_destroy(&a->lock);
+
+        if (a->file_name == m_first->file_name) {
+            first = true;
+        }
+
+        shmdt(a->file_name);
+        shmdt(a);
+
+        shmctl(shm_id1, IPC_RMID, NULL);
+        shmctl(shm_id2, IPC_RMID, NULL);
+
+        if (first) {
+            m_first == NULL;
+        }
+        a = NULL;
     }
 }
 
 
-void DebugLogWriter::write(const std::string& file, const std::string &msg) {
-    std::map<std::string, DebugLogWriterAgent *>::iterator it;
+void DebugLogWriter::write_log(const std::string& fileName,
+    const std::string &msg) {
+    std::string lmsg = msg + "\n";
+    size_t wrote;
 
-    it = agents.find(file);
-    if (it != agents.end()) {
-        DebugLogWriterAgent *agent = it->second;
-        agent->write(msg);
-    } else {
-        std::cout << file << ": " << msg << std::endl;
+    debug_log_file_handler_t *a = find_handler(fileName);
+    if (a == NULL) {
+        std::cerr << "debug log file is not open: " << msg << std::endl;
+        return;
     }
+
+    pthread_mutex_lock(&a->lock);
+    wrote = write(a->file_handler, (void *)lmsg.c_str(), lmsg.size());
+    if (wrote < msg.size()) {
+        std::cerr << "failed to write debug log: " << msg;
+    }
+    pthread_mutex_unlock(&a->lock);
 }
 
 
 }  // namespace modsecurity
-

src/debug_log_writer.h

@@ -17,14 +17,33 @@
 #include <map>
 #include <string>
 
+#include <cstring>
+#include <iostream>
+#include <stdio.h>
+#include <sys/ipc.h>
+#include <sys/shm.h>
+#include <sys/types.h>
+
 #ifndef SRC_DEBUG_LOG_WRITER_H_
 #define SRC_DEBUG_LOG_WRITER_H_
 
-#include "src/debug_log_writer_agent.h"
-
 
 namespace modsecurity {
 
+
+typedef struct debug_log_file_handler {
+    char *file_name;
+    FILE *fp;
+    int file_handler;
+    int shm_id_file_name;
+    int shm_id_structure;
+    int using_it;
+    pthread_mutex_t lock;
+    void *next;
+    void *previous;
+} debug_log_file_handler_t;
+
+
 /** @ingroup ModSecurity_CPP_API */
 class DebugLogWriter {
  public:
@@ -33,11 +52,18 @@ class DebugLogWriter {
         return instance;
     }
 
-    void write(const std::string& file, const std::string& msg);
+    void write_log(const std::string& file, const std::string& msg);
     void close(const std::string& m_fileName);
-    void open(const std::string& m_fileName);
+    int open(const std::string& m_fileName, std::string *error);
+
+ protected:
+    debug_log_file_handler_t *find_handler(const std::string &fileName);
+    debug_log_file_handler_t *add_new_handler(const std::string &fileName,
+        std::string *error);
+
  private:
-    DebugLogWriter() {}
+    DebugLogWriter() : m_first(NULL) { }
+    ~DebugLogWriter() { }
 
     // C++ 03
     // ========
@@ -47,8 +73,7 @@ class DebugLogWriter {
     DebugLogWriter(DebugLogWriter const&);
     void operator=(DebugLogWriter const&);
 
-
-    std::map<std::string, DebugLogWriterAgent *> agents;
+    struct debug_log_file_handler *m_first;
 };
 
 

src/debug_log_writer_agent.cc

@@ -1,44 +0,0 @@
-/*
- * ModSecurity, http://www.modsecurity.org/
- * Copyright (c) 2015 Trustwave Holdings, Inc. (http://www.trustwave.com/)
- *
- * You may not use this file except in compliance with
- * the License.  You may obtain a copy of the License at
- *
- *     http://www.apache.org/licenses/LICENSE-2.0
- *
- * If any of the files related to licensing are missing or if you have any
- * other questions related to licensing please contact Trustwave Holdings, Inc.
- * directly using the email address security@modsecurity.org.
- *
- */
-
-#include "src/debug_log_writer_agent.h"
-
-#include <stddef.h>
-
-#include <fstream>
-
-#include "src/debug_log_writer.h"
-
-
-namespace modsecurity {
-
-
-DebugLogWriterAgent::DebugLogWriterAgent(const std::string& fileName) :
-    m_referenceCount(0),
-    m_fileName(fileName) {
-    open(m_fileName, std::fstream::out | std::fstream::app);
-}
-
-void DebugLogWriterAgent::write(const std::string& msg) {
-    if (!is_open()) {
-        return;
-    }
-
-    *this << msg << std::endl;
-    *this << std::flush;
-}
-
-
-}  // namespace modsecurity

src/parser/seclang-parser.yy

@@ -644,7 +644,14 @@ expression:
     | CONFIG_DIR_DEBUG_LOG
       {
         if (driver.m_debugLog != NULL) {
-            driver.m_debugLog->setDebugLogFile($1);
+            std::string error;
+            driver.m_debugLog->setDebugLogFile($1, &error);
+            if (error.size() > 0) {
+                std::stringstream ss;
+                ss << "Failed to start DebugLog: " << error;
+                driver.error(@0, ss.str());
+                YYERROR;
+            }
         } else {
             std::stringstream ss;
             ss << "Internal error, there is no DebugLog ";

test/test-cases/secrules-language-tests

@@ -1 +1 @@
-Subproject commit aab4a899f6fdc20fe683d1a35195e2b182ceb2f7
+Subproject commit f754d84b4199253542f639e0671168b84e9f213f