diff --git a/CHANGES b/CHANGES index ae74fcf8..5d346114 100644 --- a/CHANGES +++ b/CHANGES @@ -1,8 +1,6 @@ -11 Feb 2010 - trunk +14 Feb 2010 - trunk ------------------- - * Fix some portability issues on Windows. - * Add REQUEST_BODY_LENGTH, which contains the number of request body bytes read. [Ivan Ristic] @@ -52,6 +50,21 @@ * Cleanup build files that were from the Apache source. +14 Feb 2010 - 2.5.13-dev1 +------------------------- + + * Cleaned up some mlogc code and debugging output. + + * Remove the ability to use a relative path to a piped audit logger + (i.e. mlogc) as Apache does not support it in their piped loggers + and it was breaking Windows and probably other platforms that + use spaces in filesystem paths. Discovered by Tom Donovan. + + * Fix memory leak freeing regex. Discovered by Tom Donovan. + + * Fix some portability issues on Windows. + + 04 Feb 2010 - 2.5.12 -------------------- diff --git a/README_WINDOWS.TXT b/README_WINDOWS.TXT new file mode 100644 index 00000000..6fa91f12 --- /dev/null +++ b/README_WINDOWS.TXT @@ -0,0 +1,181 @@ +============================================================ +Build notes for Windows from Tom Donovan +============================================================ +These are the raw build notes from Tom Donovan for building +ModSecurity 2.5.12 with Apache httpd 2.2.14 on Windows. Some +day these should be incorporated into the official docs, but +there has not yet been time, so they are included here in +their raw format for now. +============================================================ + +I build Apache 2.2.14 from source in C:\work\httpd-2.2.14 +I have a VC9 build of Apache 2.2.14 installed in C:\Apache2214 + +My PATH includes VC9 and CMAKE 2.6 + +BEFORE BUILDING - if OpenSSL and Zlib support is desired in LIBXML2 and CURL + + REM #### set an env variable to my Apache build directory + SET HTTPD_BUILD=C:\work\httpd-2.2.14 + + REM #### ensure that CURL and LIBXML2 can find the OpenSSL and Zlib includes and libraries that Apache was built with + SET INCLUDE=%INCLUDE%;%HTTPD_BUILD%\srclib\openssl\inc32;%HTTPD_BUILD%\srclib\zlib + SET LIB=%LIB%;%HTTPD_BUILD%\srclib\openssl\out32dll;%HTTPD_BUILD%\srclib\zlib + + REM #### ensure that CURL doesn't use the static zlib library: zlib.lib. Force it to use zdll.lib instead, which points to zlib1.dll + IF EXIST %HTTPD_BUILD%\srclib\zlib\zlib.lib DEL %HTTPD_BUILD%\srclib\zlib\zlib.lib + +BUILD PCRE-7.9 + + Downloaded pcre-7.9.tar.gz from ftp://ftp.csx.cam.ac.uk/pub/software/programming/pcre/ + untar'd into C:\work\ creating C:\work\pcre-7.9 + + CD C:\work\pcre-7.9 + CMAKE -G "NMake Makefiles" -DCMAKE_BUILD_TYPE=RelWithDebInfo -DBUILD_SHARED_LIBS=True + NMAKE + +BUILD LIBXML2-2.7.6 + + Downloaded libxml2-2.7.6.tar.gz from ftp://xmlsoft.org/libxml2/ + untar'd into C:\work\ creating C:\work\libxml2-2.7.6 + + CD C:\work\libxml2-2.7.6\win32 + CSCRIPT configure.js iconv=no vcmanifest=yes zlib=yes + NMAKE -f Makefile.msvc + +BUILD LUA-5.1.4 + + Downloaded lua-5.1.4.tar.gz from http://www.lua.org/ftp/ + untar'd into C:\work\ creating C:\work\lua-5.1.4 + + CD C:\work\lua-5.1.4\src + CL /Ox /arch:SSE2 /GF /GL /Gy /FD /EHsc /MD /Zi /TC /wd4005 /D "_MBCS" /D "LUA_CORE" /D "LUA_BUILD_AS_DLL" /D "_CRT_SECURE_NO_WARNINGS" /D "WIN32" /D "NDEBUG" /D "_CONSOLE" /D "_WIN32" /D "_WINDLL" /c *.c + DEL lua.obj luac.obj + LINK /DLL /LTCG /DEBUG /OUT:lua5.1.dll *.obj + IF EXIST lua5.1.dll.manifest MT -manifest lua5.1.dll.manifest -outputresource:lua5.1.dll;2 + +BUILD CURL-7.20.0 + Downloaded curl-7.20.0.tar.gz from http://curl.haxx.se/download.html + untar'd into C:\work\ creating C:\work\curl-7.20.0 + + CD C:\work\curl-7.20.0 + + *** Fixed Bug: https://sourceforge.net/tracker/?func=detail&aid=2951269&group_id=976&atid=100976 *** + Edited the file include\curl\curlbuild.h.cmake near line 160 - put double-quotes around all CURL_FORMAT* values. + e.g. change: ${CURL_FORMAT_CURL_OFF_T} to: "${CURL_FORMAT_CURL_OFF_T}" + + /* curl_off_t formatting string directive without "%" conversion specifier. */ + #cmakedefine CURL_FORMAT_CURL_OFF_T "${CURL_FORMAT_CURL_OFF_T}" + + /* unsigned curl_off_t formatting string without "%" conversion specifier. */ + #cmakedefine CURL_FORMAT_CURL_OFF_TU "${CURL_FORMAT_CURL_OFF_TU}" + + /* curl_off_t formatting string directive with "%" conversion specifier. */ + #cmakedefine CURL_FORMAT_OFF_T "${CURL_FORMAT_OFF_T}" + + CMAKE -G "NMake Makefiles" -DCMAKE_BUILD_TYPE=RelWithDebInfo -DBUILD_SHARED_LIBS=True -DCURL_ZLIB=True + + NMAKE + +BUILD MOD_SECURITY-2.5.12 + + Edited the top of C:\work\mod_security-2.5.12\apache2\Makefile.win and set my local paths + (note that pcre.lib is not in $(PCRE)\LibR as it is in the original Makefile.win ) + + # Path to Apache httpd installation + BASE = C:\Apache2214 + + # Paths to required libraries + LIBXML2 = C:\work\libxml2-2.7.6 + LUA = C:\work\lua-5.1.4\src + PCRE = C:\work\pcre-7.9 + + # Linking libraries + LIBS = $(BASE)\lib\libhttpd.lib \ + $(BASE)\lib\libapr-1.lib \ + $(BASE)\lib\libaprutil-1.lib \ + $(PCRE)\pcre.lib \ + $(LIBXML2)\win32\bin.msvc\libxml2.lib \ + $(LUA)\lua5.1.lib \ + wsock32.lib + + CD C:\work\mod_security-2.5.12\apache2 + NMAKE -f Makefile.win + +BUILD MOD_SECURITY-2.5.12 MLOGC program + + Edited the top of C:\work\mod_security-2.5.12\apache2\mlogc-src\Makefile.win and set my local paths + + # Path to Apache httpd installation + BASE = C:\Apache2214 + + # Paths to required libraries + PCRE = C:\work\pcre-7.9 + CURL = C:\work\curl-7.20.0 + + # Linking libraries + LIBS = $(BASE)\lib\libapr-1.lib \ + $(BASE)\lib\libaprutil-1.lib \ + $(PCRE)\pcre.lib \ + $(CURL)\libcurl_imp.lib \ + wsock32.lib + + + CD C:\work\mod_security-2.5.12\apache2\mlogc-src + NMAKE -f Makefile.win + +INSTALL AND RUN + + Copied these five files to C:\Apache2214\bin: + C:\work\pcre-7.9\pcre.dll + C:\work\lua-5.1.4\src\lua5.1.dll + C:\work\libxml2-2.7.6\win32\bin.msvc\libxml2.dll + C:\work\curl-7.20.0\libcurl.dll + C:\work\mod_security-2.5.12\apache2\mlogc-src\mlogc.exe + + Copied this one file to C:\Apache2214\modules: + + C:\work\mod_security-2.5.12\apache2\mod_security2.so + + You could also copy C:\work\curl-7.20.0\\curl.exe to C:\Apache2214\bin, if you want to use the cURL command-line. + + Downloaded the core rules from http://sourceforge.net/projects/mod-security/files/modsecurity-crs/0-CURRENT/ + and unzipped them in C:\Apache2214\conf\modsecurity_crs + + Added this to my conf\httpd.conf: + + LoadModule unique_id_module modules/mod_unique_id.so + LoadModule security2_module modules/mod_security2.so + + Include conf/modsecurity_crs/*.conf + Include conf/modsecurity_crs/base_rules/*.conf + SecDataDir logs + SecAuditEngine RelevantOnly + SecAuditLogRelevantStatus "^(?:5|4\d[^4])" + SecAuditLogType Concurrent + SecAuditLogParts ABCDEFGHZ + SecAuditLogStorageDir logs/data/ + SecAuditLog "|bin/mlogc.exe" + + + My conf\mlogc.conf has this: + CollectorRoot "C:/Apache2214/logs" + ConsoleURI "https://localhost:8888/rpc/auditLogReceiver" + SensorUsername "test" + SensorPassword "testtest" + LogStorageDir "data" + TransactionLog "mlogc-transaction.log" + QueuePath "mlogc-queue.log" + ErrorLog "mlogc-error.log" + LockFile "mlogc.lck" + KeepEntries 0 + ErrorLogLevel 2 + MaxConnections 10 + MaxWorkerRequests 1000 + TransactionDelay 50 + StartupDelay 5000 + CheckpointInterval 15 + ServerErrorTimeout 60 + + +Mod_security appears to work OK with the "ModSecurity Community Console". diff --git a/apache2/apache2_config.c b/apache2/apache2_config.c index c06fe122..3a8589c0 100644 --- a/apache2/apache2_config.c +++ b/apache2/apache2_config.c @@ -922,7 +922,7 @@ static const char *cmd_audit_log(cmd_parms *cmd, void *_dcfg, const char *p1) dcfg->auditlog_name = (char *)p1; if (dcfg->auditlog_name[0] == '|') { - const char *pipe_name = ap_server_root_relative(cmd->pool, dcfg->auditlog_name + 1); + const char *pipe_name = dcfg->auditlog_name + 1; piped_log *pipe_log; pipe_log = ap_open_piped_log(cmd->pool, pipe_name); diff --git a/apache2/mlogc-src/mlogc.c b/apache2/mlogc-src/mlogc.c index c935a62b..b22ec2d9 100644 --- a/apache2/mlogc-src/mlogc.c +++ b/apache2/mlogc-src/mlogc.c @@ -43,7 +43,8 @@ static void logc_shutdown(int rc); static void create_new_worker(int lock); -static void error_log(int level, void *thread, const char *text, ...) PRINTF_ATTRIBUTE(3,4); +static void error_log(int level, void *thread, + const char *text, ...) PRINTF_ATTRIBUTE(3,4); /* -- Constants -- */ @@ -85,7 +86,9 @@ do { \ #define STATUSBUF_SIZE 256 -#define ISHEXCHAR(X) (((X >= '0')&&(X <= '9')) || ((X >= 'a')&&(X <= 'f')) || ((X >= 'A')&&(X <= 'F'))) +#define ISHEXCHAR(X) ( ((X >= '0')&&(X <= '9')) \ + || ((X >= 'a')&&(X <= 'f')) \ + || ((X >= 'A')&&(X <= 'F')) ) /* -- Regex Patterns -- */ @@ -95,7 +98,7 @@ do { \ * treated as a single parameter to allow for invalid * requests. */ -const char logline_pattern[] = +static const char logline_pattern[] = "^(\\S+)" "\\ (\\S+)\\ (\\S+)\\ (\\S+)" "\\ \\[([^:]+):(\\d+:\\d+:\\d+)\\ ([^\\]]+)\\]" @@ -113,7 +116,7 @@ const char logline_pattern[] = * a REQUEST_LINE field into method, URI, and * protocol. */ -const char requestline_pattern[] = +static const char requestline_pattern[] = "(\\S+)\\ (.*?)\\ (\\S+)"; @@ -128,58 +131,58 @@ typedef struct { /* -- Global variables -- */ -pid_t logc_pid = 0; -const char *conffile = NULL; -const char *lockfile = NULL; -int have_read_data = 0; -int checkpoint_interval = 60; -apr_time_t checkpoint_time_last = 0; -const char *collector_root = NULL; -apr_table_t *conf = NULL; -const char *console_uri = NULL; -apr_array_header_t *curl_handles = NULL; -int current_workers = 0; -int management_thread_active = 0; -unsigned long int entry_counter = 1; -const char *error_log_path = NULL; -apr_file_t *error_log_fd = NULL; -int error_log_level = 2; -apr_hash_t *in_progress = NULL; -int keep_alive = 150; /* Not used yet. */ -int keep_alive_timeout = 300; /* Not used yet. */ -int keep_entries = 0; -const char *log_repository = NULL; -void *logline_regex = NULL; -int max_connections = 10; -int max_worker_requests = 1000; -apr_global_mutex_t *gmutex = NULL; -apr_thread_mutex_t *mutex = NULL; -apr_pool_t *pool = NULL; -apr_pool_t *thread_pool = NULL; -apr_pool_t *recv_pool = NULL; -apr_array_header_t *queue = NULL; -const char *queue_path = NULL; -/* apr_time_t queue_time = 0; */ -void *requestline_regex = NULL; -int running = 0; -const char *sensor_password = NULL; -const char *sensor_username = NULL; -int server_error = 0; -apr_time_t server_error_last_check_time = 0; -int server_error_timeout = 60; -int startup_delay = 100; -int transaction_delay = 100; -const char *transaction_log_path = NULL; -apr_file_t *transaction_log_fd = NULL; +static pid_t logc_pid = 0; +static const char *conffile = NULL; +static const char *lockfile = NULL; +static int have_read_data = 0; +static int checkpoint_interval = 60; +static apr_time_t checkpoint_time_last = 0; +static const char *collector_root = NULL; +static apr_table_t *conf = NULL; +static const char *console_uri = NULL; +static apr_array_header_t *curl_handles = NULL; +static int current_workers = 0; +static int management_thread_active = 0; +static unsigned long int entry_counter = 1; +static const char *error_log_path = NULL; +static apr_file_t *error_log_fd = NULL; +static int error_log_level = 2; +static apr_hash_t *in_progress = NULL; +static int keep_alive = 150; /* Not used yet. */ +static int keep_alive_timeout = 300; /* Not used yet. */ +static int keep_entries = 0; +static const char *log_repository = NULL; +static void *logline_regex = NULL; +static int max_connections = 10; +static int max_worker_requests = 1000; +static apr_global_mutex_t *gmutex = NULL; +static apr_thread_mutex_t *mutex = NULL; +static apr_pool_t *pool = NULL; +static apr_pool_t *thread_pool = NULL; +static apr_pool_t *recv_pool = NULL; +static apr_array_header_t *queue = NULL; +static const char *queue_path = NULL; +/* static apr_time_t queue_time = 0; */ +static void *requestline_regex = NULL; +static int running = 0; +static const char *sensor_password = NULL; +static const char *sensor_username = NULL; +static int server_error = 0; +static apr_time_t server_error_last_check_time = 0; +static int server_error_timeout = 60; +static int startup_delay = 100; +static int transaction_delay = 100; +static const char *transaction_log_path = NULL; +static apr_file_t *transaction_log_fd = NULL; /* -- Commandline opts -- */ -int opt_force = 0; - +static int opt_force = 0; /* -- Code -- */ -static char *_log_escape(apr_pool_t *mp, const char *input, apr_size_t input_len) +static char *_log_escape(apr_pool_t *mp, const char *input, + apr_size_t input_len) { static const char c2x_table[] = "0123456789abcdef"; unsigned char *d = NULL; @@ -316,7 +319,8 @@ static const char *file_path(const char *path) if (path == NULL) return NULL; - rc = apr_filepath_merge(&newpath, collector_root, path, APR_FILEPATH_TRUENAME, pool); + rc = apr_filepath_merge(&newpath, collector_root, + path, APR_FILEPATH_TRUENAME, pool); if ((newpath != NULL) && (rc == APR_SUCCESS || APR_STATUS_IS_EPATHWILD(rc) || APR_STATUS_IS_ENOENT(rc) || APR_STATUS_IS_ENOTDIR(rc))) { @@ -359,7 +363,9 @@ static void error_log(int level, void *thread, const char *text, ...) va_start(ap, text); apr_vsnprintf(msg1, sizeof(msg1), text, ap); - apr_snprintf(msg2, sizeof(msg2), "[%s] [%d] [%" APR_PID_T_FMT "/%pp] %s\n", current_logtime(datetime, sizeof(datetime)), level, logc_pid, (thread ? thread : 0), msg1); + apr_snprintf(msg2, sizeof(msg2), "[%s] [%d] [%" APR_PID_T_FMT "/%pp] %s\n", + current_logtime(datetime, sizeof(datetime)), + level, logc_pid, (thread ? thread : 0), msg1); if (error_log_fd != NULL) { apr_size_t nbytes_written; @@ -399,8 +405,12 @@ static void add_entry(const char *data, int start_worker) /* Add the new audit log entry to the queue. */ *(entry_t **)apr_array_push(queue) = entry; - /* Create a new worker if we can, but not if there is a known problem with the server. */ - if ((start_worker != 0)&&(current_workers < max_connections)&&(server_error == 0)) { + /* Create a new worker if we can, but not if there is a + * known problem with the server. + */ + if ( (start_worker != 0) + && (current_workers < max_connections)&&(server_error == 0)) + { create_new_worker(0); } @@ -476,9 +486,11 @@ static void transaction_log_init(void) apr_snprintf(old_queue_path, sizeof(old_queue_path), "%s.old", queue_path); /* Put a lock in place to ensure exclusivity. */ - error_log(LOG_DEBUG, NULL, "Transaction initialization locking global mutex."); + error_log(LOG_DEBUG, NULL, + "Transaction initialization locking global mutex."); if (APR_STATUS_IS_EBUSY(apr_global_mutex_trylock(gmutex))) { - error_log(LOG_DEBUG, NULL, "Transaction initialization waiting on global mutex."); + error_log(LOG_DEBUG, NULL, + "Transaction initialization waiting on global mutex."); apr_global_mutex_lock(gmutex); } @@ -496,20 +508,24 @@ static void transaction_log_init(void) apr_file_close(queue_fd); if (line_count > 0) { - error_log(LOG_NOTICE, NULL, "Loaded %d entries from the queue file.", line_count); + error_log(LOG_NOTICE, NULL, + "Loaded %d entries from the queue file.", line_count); } } /* Try the old queue file. */ - else if (apr_file_open(&queue_fd, old_queue_path, APR_READ | APR_FILE_NOCLEANUP, - 0, pool) == APR_SUCCESS) + else if (apr_file_open(&queue_fd, old_queue_path, + APR_READ | APR_FILE_NOCLEANUP, + 0, pool) == APR_SUCCESS) { int line_count = read_queue_entries(queue_fd, &queue_time); apr_file_close(queue_fd); - error_log(LOG_NOTICE, NULL, "Loaded %d entries from the OLD queue file.", line_count); + error_log(LOG_NOTICE, NULL, + "Loaded %d entries from the OLD queue file.", line_count); apr_file_rename(old_queue_path, queue_path, pool); } else { - error_log(LOG_NOTICE, NULL, "Queue file not found. New one will be created."); + error_log(LOG_NOTICE, NULL, + "Queue file not found. New one will be created."); } /* Delete the old queue file. */ @@ -523,11 +539,15 @@ static void transaction_log_init(void) * testing. Truncating would erase the log of a currently running * instance. */ - if (apr_file_open(&transaction_log_fd, transaction_log_path, APR_WRITE | APR_CREATE - | APR_APPEND | APR_XTHREAD, APR_OS_DEFAULT, pool) != APR_SUCCESS) + if (apr_file_open(&transaction_log_fd, transaction_log_path, + APR_WRITE | APR_CREATE | APR_APPEND | APR_XTHREAD, + APR_OS_DEFAULT, pool) != APR_SUCCESS) { - error_log(LOG_ERROR, NULL, "Failed to open the transaction log: %s\n", transaction_log_path); - error_log(LOG_DEBUG, NULL, "Transaction initialization unlocking global mutex."); + error_log(LOG_ERROR, NULL, + "Failed to open the transaction log: %s\n", + transaction_log_path); + error_log(LOG_DEBUG, NULL, + "Transaction initialization unlocking global mutex."); apr_global_mutex_unlock(gmutex); logc_shutdown(1); } @@ -535,7 +555,8 @@ static void transaction_log_init(void) error_log(LOG_DEBUG, NULL, "Transaction initialization completed."); /* Unlock */ - error_log(LOG_DEBUG, NULL, "Transaction initialization unlocking global mutex."); + error_log(LOG_DEBUG, NULL, + "Transaction initialization unlocking global mutex."); apr_global_mutex_unlock(gmutex); } @@ -548,7 +569,8 @@ static void transaction_log(int direction, const char *entry) apr_size_t nbytes, nbytes_written; char msg[8196] = ""; - apr_snprintf(msg, sizeof(msg), "%u %s: %s\n", (unsigned int)apr_time_sec(apr_time_now()), + apr_snprintf(msg, sizeof(msg), "%u %s: %s\n", + (unsigned int)apr_time_sec(apr_time_now()), (direction == TXIN ? "IN" : "OUT"), entry); nbytes = strlen(msg); apr_file_write_full(transaction_log_fd, msg, nbytes, &nbytes_written); @@ -572,7 +594,8 @@ static void transaction_checkpoint(void) apr_snprintf(new_queue_path, sizeof(new_queue_path), "%s.new", queue_path); apr_snprintf(old_queue_path, sizeof(old_queue_path), "%s.old", queue_path); - apr_snprintf(msg, sizeof(msg), "%u\n", (unsigned int)apr_time_sec(apr_time_now())); + apr_snprintf(msg, sizeof(msg), "%u\n", + (unsigned int)apr_time_sec(apr_time_now())); if (! have_read_data) { error_log(LOG_DEBUG, NULL, "Checkpoint not required."); @@ -591,8 +614,10 @@ static void transaction_checkpoint(void) apr_pool_create(&cpool, NULL); /* Dump active entries into a new queue file. */ - if (apr_file_open(&queue_fd, new_queue_path, APR_WRITE | APR_CREATE - | APR_EXCL | APR_TRUNCATE | APR_FILE_NOCLEANUP, APR_OS_DEFAULT, cpool) != APR_SUCCESS) + if (apr_file_open(&queue_fd, new_queue_path, + APR_WRITE | APR_CREATE | APR_EXCL | + APR_TRUNCATE | APR_FILE_NOCLEANUP, + APR_OS_DEFAULT, cpool) != APR_SUCCESS) { error_log(LOG_ERROR, NULL, "Failed to create file: %s", new_queue_path); error_log(LOG_DEBUG, NULL, "Checkpoint unlocking global mutex."); @@ -610,11 +635,14 @@ static void transaction_checkpoint(void) apr_file_write_full(queue_fd, entry->line, entry->line_size, NULL); apr_file_write_full(queue_fd, &"\n", 1, NULL); } - error_log(LOG_DEBUG2, NULL, "Checkpoint wrote %d queued entries to new queue.", i); + error_log(LOG_DEBUG2, NULL, + "Checkpoint wrote %d queued entries to new queue.", i); /* Then dump the ones that are currently being processed. */ i = 0; - for (hi = apr_hash_first(NULL, in_progress); hi != NULL; hi = apr_hash_next(hi)) { + for (hi = apr_hash_first(NULL, in_progress); + hi != NULL; hi = apr_hash_next(hi))\ + { void *e; entry_t *entry = NULL; @@ -624,7 +652,8 @@ static void transaction_checkpoint(void) apr_file_write_full(queue_fd, entry->line, entry->line_size, NULL); apr_file_write_full(queue_fd, &"\n", 1, NULL); } - error_log(LOG_DEBUG2, NULL, "Checkpoint wrote %d additional entries to new queue.", i); + error_log(LOG_DEBUG2, NULL, + "Checkpoint wrote %d additional entries to new queue.", i); apr_file_close(queue_fd); @@ -713,7 +742,8 @@ static void read_configuration(void) rc = apr_file_open(&fd, conffile, APR_READ | APR_FILE_NOCLEANUP, 0, pool); if (rc != APR_SUCCESS) { - error_log(LOG_ERROR, NULL, "Unable to open configuration file: %s", conffile); + error_log(LOG_ERROR, NULL, + "Unable to open configuration file: %s", conffile); logc_shutdown(1); } @@ -722,7 +752,8 @@ static void read_configuration(void) rc = apr_file_gets(linebuf, 4096, fd); if (rc == APR_EOF) return; if (rc != APR_SUCCESS) { - error_log(LOG_ERROR, NULL, "Error reading from the configuration file."); + error_log(LOG_ERROR, NULL, + "Error reading from the configuration file."); logc_shutdown(1); } @@ -760,15 +791,17 @@ static void init_configuration(void) error_log_level = atoi(s); } - if ((rc = apr_file_open(&error_log_fd, error_log_path, APR_WRITE | APR_CREATE | APR_APPEND, - APR_OS_DEFAULT, pool)) != APR_SUCCESS) + if ((rc = apr_file_open(&error_log_fd, error_log_path, + APR_WRITE | APR_CREATE | APR_APPEND, + APR_OS_DEFAULT, pool)) != APR_SUCCESS) { error_log(LOG_ERROR, NULL, "Failed to open the error log %s: %s\n", error_log_path, apr_strerror(rc, errstr, 1024)); logc_shutdown(1); } - error_log(LOG_NOTICE, NULL, "Configuring ModSecurity Audit Log Collector %s.", VERSION); + error_log(LOG_NOTICE, NULL, + "Configuring ModSecurity Audit Log Collector %s.", VERSION); /* Startup Delay */ s = apr_table_get(conf, "StartupDelay"); @@ -777,9 +810,11 @@ static void init_configuration(void) } if ( startup_delay > 0 ) { - error_log(LOG_NOTICE, NULL, "Delaying execution for %dms.", startup_delay); + error_log(LOG_NOTICE, NULL, + "Delaying execution for %dms.", startup_delay); apr_sleep(startup_delay * 1000); - error_log(LOG_DEBUG, NULL, "Continuing execution after %dms delay.", startup_delay); + error_log(LOG_DEBUG, NULL, + "Continuing execution after %dms delay.", startup_delay); } /* Remaining Configuration */ @@ -792,7 +827,8 @@ static void init_configuration(void) s = apr_table_get(conf, "CheckpointInterval"); if (s != NULL) { checkpoint_interval = atoi(s); - error_log(LOG_DEBUG2, NULL, "CheckpointInterval=%d", checkpoint_interval); + error_log(LOG_DEBUG2, NULL, + "CheckpointInterval=%d", checkpoint_interval); } s = apr_table_get(conf, "QueuePath"); @@ -801,7 +837,8 @@ static void init_configuration(void) error_log(LOG_DEBUG2, NULL, "QueuePath=%s", queue_path); } else { - error_log(LOG_ERROR, NULL, "QueuePath not defined in the configuration file."); + error_log(LOG_ERROR, NULL, + "QueuePath not defined in the configuration file."); logc_shutdown(1); } @@ -814,7 +851,8 @@ static void init_configuration(void) s = apr_table_get(conf, "ServerErrorTimeout"); if (s != NULL) { server_error_timeout = atoi(s); - error_log(LOG_DEBUG2, NULL, "ServerErrorTimeout=%d", server_error_timeout); + error_log(LOG_DEBUG2, NULL, + "ServerErrorTimeout=%d", server_error_timeout); } s = apr_table_get(conf, "TransactionDelay"); @@ -840,7 +878,8 @@ static void init_configuration(void) if (s != NULL) { int v = atoi(s); if (v >= 0) max_worker_requests = v; - error_log(LOG_DEBUG2, NULL, "MaxWorkerRequests=%d", max_worker_requests); + error_log(LOG_DEBUG2, NULL, + "MaxWorkerRequests=%d", max_worker_requests); } s = apr_table_get(conf, "KeepAlive"); @@ -863,7 +902,8 @@ static void init_configuration(void) error_log(LOG_DEBUG2, NULL, "LogStorageDir=%s", log_repository); } else { - error_log(LOG_ERROR, NULL, "Missing mandatory parameter LogStorageDir.\n"); + error_log(LOG_ERROR, NULL, + "Missing mandatory parameter LogStorageDir.\n"); logc_shutdown(1); } @@ -883,7 +923,8 @@ static void init_configuration(void) error_log(LOG_DEBUG2, NULL, "SensorUsername=%s", sensor_username); } else { - error_log(LOG_ERROR, NULL, "Missing mandatory parameter SensorUsername.\n"); + error_log(LOG_ERROR, NULL, + "Missing mandatory parameter SensorUsername.\n"); logc_shutdown(1); } @@ -893,7 +934,8 @@ static void init_configuration(void) error_log(LOG_DEBUG2, NULL, "SensorPassword=%s", sensor_password); } else { - error_log(LOG_ERROR, NULL, "Missing mandatory parameter SensorPassword.\n"); + error_log(LOG_ERROR, NULL, + "Missing mandatory parameter SensorPassword.\n"); logc_shutdown(1); } @@ -934,10 +976,14 @@ static void logc_shutdown(int rc) } if (rc == 0) { - error_log(LOG_NOTICE, NULL, "ModSecurity Audit Log Collector %s terminating normally.", VERSION); + error_log(LOG_NOTICE, NULL, + "ModSecurity Audit Log Collector %s terminating normally.", + VERSION); } else { - error_log(LOG_NOTICE, NULL, "ModSecurity Audit Log Collector %s terminating with error %d", VERSION, rc); + error_log(LOG_NOTICE, NULL, + "ModSecurity Audit Log Collector %s " + "terminating with error %d", VERSION, rc); } if (error_log_fd != NULL) { @@ -954,27 +1000,29 @@ static void logc_shutdown(int rc) static int handle_signals(int signum) { switch (signum) { - case SIGINT: - error_log(LOG_NOTICE, NULL, "Caught SIGINT, shutting down."); - logc_shutdown(0); - case SIGTERM: - error_log(LOG_NOTICE, NULL, "Caught SIGTERM, shutting down."); - logc_shutdown(0); + case SIGINT: + error_log(LOG_NOTICE, NULL, "Caught SIGINT, shutting down."); + logc_shutdown(0); + case SIGTERM: + error_log(LOG_NOTICE, NULL, "Caught SIGTERM, shutting down."); + logc_shutdown(0); #ifndef WIN32 - case SIGHUP: - error_log(LOG_NOTICE, NULL, "Caught SIGHUP, ignored."); - /* ENH: reload config? */ - return 0; - case SIGALRM: - error_log(LOG_DEBUG, NULL, "Caught SIGALRM, ignored."); - return 0; - case SIGTSTP: - error_log(LOG_DEBUG, NULL, "Caught SIGTSTP, ignored."); - return 0; + case SIGHUP: + error_log(LOG_NOTICE, NULL, "Caught SIGHUP, ignored."); + /* ENH: reload config? */ + return 0; + case SIGALRM: + error_log(LOG_DEBUG, NULL, "Caught SIGALRM, ignored."); + return 0; + case SIGTSTP: + error_log(LOG_DEBUG, NULL, "Caught SIGTSTP, ignored."); + return 0; #endif /* WIN32 */ } #ifndef WIN32 - error_log(LOG_NOTICE, NULL, "Caught unexpected signal %d: %s", signum, apr_signal_description_get(signum)); + error_log(LOG_NOTICE, NULL, + "Caught unexpected signal %d: %s", + signum, apr_signal_description_get(signum)); #else error_log(LOG_NOTICE, NULL, "Caught unexpected signal %d", signum); #endif /* WIN32 */ @@ -983,13 +1031,24 @@ static int handle_signals(int signum) return 0; /* should never reach */ } +#ifdef WIN32 +/** + * This function is invoked by Curl to read the source file on Windows + */ +static size_t curl_readfunction(void *ptr, size_t size, + size_t nmemb, void *stream) +{ + return fread(ptr, size, nmemb, (FILE *)stream); +} +#endif /** * This function is invoked by Curl to read the response * body. Since we don't care about the response body the function * pretends it is retrieving data where it isn't. */ -size_t curl_writefunction(void *ptr, size_t size, size_t nmemb, void *stream) +static size_t curl_writefunction(void *ptr, size_t size, + size_t nmemb, void *stream) { unsigned char *data = (unsigned char *)ptr; unsigned char *status = (unsigned char *)stream; @@ -1032,9 +1091,10 @@ size_t curl_writefunction(void *ptr, size_t size, size_t nmemb, void *stream) /** * This function is invoked by Curl whenever it has something * to say. We forward its messages to the error log at level - * DEBUG. + * DEBUG or DEBUG2 depending on the verbosity. */ -int curl_debugfunction(CURL *curl, curl_infotype infotype, char *data, size_t datalen, void *ourdata) +static int curl_debugfunction(CURL *curl, curl_infotype infotype, + char *data, size_t datalen, void *ourdata) { apr_size_t i, effectivelen; apr_thread_t *thread = (apr_thread_t *)ourdata; @@ -1049,24 +1109,49 @@ int curl_debugfunction(CURL *curl, curl_infotype infotype, char *data, size_t da } } - if (error_log_level >= LOG_DEBUG) { - if (infotype == CURLINFO_TEXT) { - error_log(LOG_DEBUG, thread, "CURL: %s", _log_escape(apr_thread_pool_get(thread), data, effectivelen)); - } - } - if (error_log_level >= LOG_DEBUG2) { - if (infotype == CURLINFO_HEADER_IN) { - error_log(LOG_DEBUG2, thread, "CURL: HEADER_IN %s", _log_escape(apr_thread_pool_get(thread), data, effectivelen)); - } - else if (infotype == CURLINFO_HEADER_OUT) { - error_log(LOG_DEBUG2, thread, "CURL: HEADER_OUT %s", _log_escape(apr_thread_pool_get(thread), data, effectivelen)); - } - else if (infotype == CURLINFO_DATA_IN) { - error_log(LOG_DEBUG2, thread, "CURL: DATA_IN %s", _log_escape(apr_thread_pool_get(thread), data, effectivelen)); - } - else if (infotype == CURLINFO_DATA_OUT) { - error_log(LOG_DEBUG2, thread, "CURL: DATA_OUT %s", _log_escape(apr_thread_pool_get(thread), data, effectivelen)); - } + switch (infotype) { + case CURLINFO_TEXT: + /* More verbose data starts with an indent */ + if (apr_isspace(data[0])) { + char *dataptr = data + 1; + + /* Skip initial whitespace (indent) */ + while ( ((size_t)(dataptr - data) > datalen) + && apr_isspace(*dataptr)) dataptr++; + dataptr++; + error_log(LOG_DEBUG2, thread, "CURL: %s", + _log_escape(apr_thread_pool_get(thread), dataptr, + effectivelen - (dataptr - data))); + } + else { + error_log(LOG_DEBUG, thread, "CURL: %s", + _log_escape(apr_thread_pool_get(thread), data, + effectivelen)); + } + break; + case CURLINFO_HEADER_IN: + error_log(LOG_DEBUG, thread, "CURL: HEADER_IN %s", + _log_escape(apr_thread_pool_get(thread), data, + effectivelen)); + break; + case CURLINFO_HEADER_OUT: + error_log(LOG_DEBUG, thread, "CURL: HEADER_OUT %s", + _log_escape(apr_thread_pool_get(thread), data, + effectivelen)); + break; + case CURLINFO_DATA_IN: + error_log(LOG_DEBUG2, thread, "CURL: DATA_IN %s", + _log_escape(apr_thread_pool_get(thread), data, + effectivelen)); + break; + case CURLINFO_DATA_OUT: + error_log(LOG_DEBUG2, thread, "CURL: DATA_OUT %s", + _log_escape(apr_thread_pool_get(thread), data, + effectivelen)); + break; + default: + /* Ignore anything else */ + break; } return 0; @@ -1095,13 +1180,17 @@ static void logc_init(void) logc_shutdown(1); } - if ((rc = apr_global_mutex_create(&gmutex, lockfile, APR_LOCK_DEFAULT, pool)) != APR_SUCCESS) { + if ((rc = apr_global_mutex_create(&gmutex, lockfile, + APR_LOCK_DEFAULT, pool)) != APR_SUCCESS) + { error_log(LOG_ERROR, NULL, "Failed to create global mutex: %s", apr_strerror(rc, errstr, 1024)); logc_shutdown(1); } - if ((rc = apr_thread_mutex_create(&mutex, APR_THREAD_MUTEX_UNNESTED, pool)) != APR_SUCCESS) { + if ((rc = apr_thread_mutex_create(&mutex, APR_THREAD_MUTEX_UNNESTED, + pool)) != APR_SUCCESS) + { error_log(LOG_ERROR, NULL, "Failed to create thread mutex: %s", apr_strerror(rc, errstr, 1024)); logc_shutdown(1); @@ -1140,15 +1229,19 @@ static void logc_init(void) *(CURL **)apr_array_push(curl_handles) = curl; } - logline_regex = pcre_compile(logline_pattern, PCRE_CASELESS, &errptr, &erroffset, NULL); + logline_regex = pcre_compile(logline_pattern, PCRE_CASELESS, + &errptr, &erroffset, NULL); if (logline_regex == NULL) { - error_log(LOG_ERROR, NULL, "Failed to compile pattern: %s\n", logline_pattern); + error_log(LOG_ERROR, NULL, + "Failed to compile pattern: %s\n", logline_pattern); logc_shutdown(1); } - requestline_regex = pcre_compile(requestline_pattern, PCRE_CASELESS, &errptr, &erroffset, NULL); + requestline_regex = pcre_compile(requestline_pattern, + PCRE_CASELESS, &errptr, &erroffset, NULL); if (requestline_regex == NULL) { - error_log(LOG_ERROR, NULL, "Failed to compile pattern: %s\n", requestline_pattern); + error_log(LOG_ERROR, NULL, + "Failed to compile pattern: %s\n", requestline_pattern); logc_shutdown(1); } } @@ -1162,7 +1255,8 @@ static void logc_init(void) * 2) If it is KEEP_ENTRIES_REMOVE_TIME, then remove the file. * 3) Otherwise set the date and let the other mlogc remove it. */ -static void keep_entries_hack(apr_pool_t *mp, apr_thread_t *thread, const char *fn) +static void keep_entries_hack(apr_pool_t *mp, + apr_thread_t *thread, const char *fn) { apr_file_t *f = NULL; apr_finfo_t finfo; @@ -1170,15 +1264,26 @@ static void keep_entries_hack(apr_pool_t *mp, apr_thread_t *thread, const char * apr_status_t rc; /* Opening for write as required for exclusive lock */ - if ((rc = apr_file_open(&f, fn, APR_READ|APR_WRITE|APR_APPEND, APR_OS_DEFAULT, mp)) != APR_SUCCESS) { - error_log(LOG_ERROR, thread, "Could not open \"%s\": %s", fn, apr_strerror(rc, errstr, 1024)); + if ((rc = apr_file_open(&f, fn, + APR_READ|APR_WRITE|APR_APPEND, + APR_OS_DEFAULT, mp)) != APR_SUCCESS) + { + error_log(LOG_ERROR, thread, + "Could not open \"%s\": %s", + fn, apr_strerror(rc, errstr, 1024)); return; } - if ((rc = apr_file_lock(f, APR_FLOCK_EXCLUSIVE|APR_FLOCK_NONBLOCK)) != APR_SUCCESS) { - error_log(LOG_DEBUG2, thread, "Waiting for lock on \"%s\": %s", fn, apr_strerror(rc, errstr, 1024)); + if ((rc = apr_file_lock(f, + APR_FLOCK_EXCLUSIVE|APR_FLOCK_NONBLOCK)) != APR_SUCCESS) + { + error_log(LOG_DEBUG2, thread, + "Waiting for lock on \"%s\": %s", + fn, apr_strerror(rc, errstr, 1024)); if ((rc = apr_file_lock(f, APR_FLOCK_EXCLUSIVE)) != APR_SUCCESS) { - error_log(LOG_ERROR, thread, "Could not lock \"%s\": %s", fn, apr_strerror(rc, errstr, 1024)); + error_log(LOG_ERROR, thread, + "Could not lock \"%s\": %s", + fn, apr_strerror(rc, errstr, 1024)); apr_file_close(f); return; } @@ -1189,20 +1294,34 @@ static void keep_entries_hack(apr_pool_t *mp, apr_thread_t *thread, const char * TEST_WITH_RAND_SLEEP(2); if ((rc = apr_stat(&finfo, fn, APR_FINFO_MIN, mp)) != APR_SUCCESS) { - error_log(LOG_ERROR, thread, "Could not stat \"%s\": %s", fn, apr_strerror(rc, errstr, 1024)); + error_log(LOG_ERROR, thread, + "Could not stat \"%s\": %s", + fn, apr_strerror(rc, errstr, 1024)); error_log(LOG_DEBUG2, thread, "Unlocked: %s", fn); apr_file_close(f); return; } if (error_log_level >= LOG_DEBUG) { - error_log(LOG_DEBUG, thread, "STAT \"%s\" {uid=%d; gid=%d; size=%" APR_OFF_T_FMT "; csize=%" APR_OFF_T_FMT "; atime=%" APR_TIME_T_FMT "; ctime=%" APR_TIME_T_FMT "; mtime=%" APR_TIME_T_FMT "}", fn, finfo.user, finfo.group, finfo.size, finfo.csize, finfo.atime, finfo.ctime, finfo.mtime); + error_log(LOG_DEBUG, thread, + "STAT \"%s\" {" + "uid=%d; gid=%d; size=%" APR_OFF_T_FMT "; " + "csize=%" APR_OFF_T_FMT "; atime=%" APR_TIME_T_FMT "; " + "ctime=%" APR_TIME_T_FMT "; mtime=%" APR_TIME_T_FMT + "}", + fn, finfo.user, finfo.group, finfo.size, + finfo.csize, finfo.atime, finfo.ctime, finfo.mtime); } if (finfo.mtime != KEEP_ENTRIES_REMOVE_TIME) { error_log(LOG_DEBUG2, thread, "Set mtime: %s", fn); - if ((rc = apr_file_mtime_set(fn, (apr_time_t)KEEP_ENTRIES_REMOVE_TIME, mp)) != APR_SUCCESS) { - error_log(LOG_ERROR, thread, "Could not set mtime on \"%s\": %s", fn, apr_strerror(rc, errstr, 1024)); + if ((rc = apr_file_mtime_set(fn, + (apr_time_t)KEEP_ENTRIES_REMOVE_TIME, mp)) + != APR_SUCCESS) + { + error_log(LOG_ERROR, thread, + "Could not set mtime on \"%s\": %s", + fn, apr_strerror(rc, errstr, 1024)); } error_log(LOG_DEBUG2, thread, "Unlocked: %s", fn); apr_file_close(f); @@ -1279,7 +1398,8 @@ static void * APR_THREAD_FUNC thread_worker(apr_thread_t *thread, void *data) if (take_new) { error_log(LOG_DEBUG, thread, "Worker fetch locking thread mutex."); if (APR_STATUS_IS_EBUSY(apr_thread_mutex_trylock(mutex))) { - error_log(LOG_DEBUG, thread, "Worker fetch waiting on thread mutex."); + error_log(LOG_DEBUG, thread, + "Worker fetch waiting on thread mutex."); apr_thread_mutex_lock(mutex); } @@ -1287,7 +1407,8 @@ static void * APR_THREAD_FUNC thread_worker(apr_thread_t *thread, void *data) /* Deal with the previous entry. */ if (entry != NULL) { - error_log(LOG_DEBUG, thread, "Removing previous entry from storage."); + error_log(LOG_DEBUG, thread, + "Removing previous entry from storage."); transaction_log(TXOUT, entry->line); /* Remove previous entry from storage. */ @@ -1304,9 +1425,11 @@ static void * APR_THREAD_FUNC thread_worker(apr_thread_t *thread, void *data) /* Get one entry. */ entryptr = (entry_t **)apr_array_pop(queue); if (entryptr == NULL) { - error_log(LOG_DEBUG, thread, "Worker fetch unlocking thread mutex."); + error_log(LOG_DEBUG, thread, + "Worker fetch unlocking thread mutex."); apr_thread_mutex_unlock(mutex); - error_log(LOG_DEBUG, thread, "No more work for this thread, exiting."); + error_log(LOG_DEBUG, thread, + "No more work for this thread, exiting."); goto THREAD_SHUTDOWN; } @@ -1316,7 +1439,8 @@ static void * APR_THREAD_FUNC thread_worker(apr_thread_t *thread, void *data) error_log(LOG_DEBUG, thread, "Worker fetch completed."); - error_log(LOG_DEBUG, thread, "Worker fetch unlocking thread mutex."); + error_log(LOG_DEBUG, thread, + "Worker fetch unlocking thread mutex."); apr_thread_mutex_unlock(mutex); } @@ -1333,12 +1457,16 @@ static void * APR_THREAD_FUNC thread_worker(apr_thread_t *thread, void *data) rc = pcre_exec(logline_regex, NULL, entry->line, entry->line_size, 0, 0, capturevector, CAPTUREVECTORSIZE); if (rc == PCRE_ERROR_NOMATCH) { /* No match. */ - error_log(LOG_WARNING, thread, "Invalid entry (failed to match regex): %s", _log_escape(tpool, entry->line, entry->line_size)); + error_log(LOG_WARNING, thread, + "Invalid entry (failed to match regex): %s", + _log_escape(tpool, entry->line, entry->line_size)); take_new = 1; nodelay = 1; } else if (rc < 0) { /* Error condition. */ - error_log(LOG_WARNING, thread, "Invalid entry (PCRE error %d): %s", rc, _log_escape(tpool, entry->line, entry->line_size)); + error_log(LOG_WARNING, thread, + "Invalid entry (PCRE error %d): %s", + rc, _log_escape(tpool, entry->line, entry->line_size)); take_new = 1; nodelay = 1; } @@ -1355,13 +1483,18 @@ static void * APR_THREAD_FUNC thread_worker(apr_thread_t *thread, void *data) TEST_WITH_RAND_SLEEP(2); uniqueid = apr_psprintf(tpool, "%.*s", - (capturevector[2*13+1] - capturevector[2*13]), (entry->line + capturevector[2*13])); + (capturevector[2*13+1] - capturevector[2*13]), + (entry->line + capturevector[2*13])); auditlogentry = apr_psprintf(tpool, "%s/%.*s", log_repository, - (capturevector[2*15+1] - capturevector[2*15]), (entry->line + capturevector[2*15])); + (capturevector[2*15+1] - capturevector[2*15]), + (entry->line + capturevector[2*15])); hash = apr_psprintf(tpool, "X-Content-Hash: %.*s", - (capturevector[2*18+1] - capturevector[2*15]), (entry->line + capturevector[2*18])); - summary = apr_psprintf(tpool, "X-ForensicLog-Summary: %s", entry->line); - credentials = apr_psprintf(tpool, "%s:%s", sensor_username, sensor_password); + (capturevector[2*18+1] - capturevector[2*15]), + (entry->line + capturevector[2*18])); + summary = apr_psprintf(tpool, "X-ForensicLog-Summary: %s", + entry->line); + credentials = apr_psprintf(tpool, "%s:%s", + sensor_username, sensor_password); rc = apr_stat(&finfo, auditlogentry, APR_FINFO_SIZE, tpool); if (rc == APR_SUCCESS) { @@ -1370,7 +1503,17 @@ static void * APR_THREAD_FUNC thread_worker(apr_thread_t *thread, void *data) CURLcode res; if (error_log_level >= LOG_DEBUG) { - error_log(LOG_DEBUG, thread, "STAT \"%s\" {uid=%d; gid=%d; size=%" APR_OFF_T_FMT "; csize=%" APR_OFF_T_FMT "; atime=%" APR_TIME_T_FMT "; ctime=%" APR_TIME_T_FMT "; mtime=%" APR_TIME_T_FMT "}", auditlogentry, finfo.user, finfo.group, finfo.size, finfo.csize, finfo.atime, finfo.ctime, finfo.mtime); + error_log(LOG_DEBUG, thread, + "STAT \"%s\" {" + "uid=%d; gid=%d; size=%" APR_OFF_T_FMT "; " + "csize=%" APR_OFF_T_FMT "; " + "atime=%" APR_TIME_T_FMT "; " + "ctime=%" APR_TIME_T_FMT "; " + "mtime=%" APR_TIME_T_FMT + "}", + auditlogentry, finfo.user, finfo.group, + finfo.size, finfo.csize, finfo.atime, + finfo.ctime, finfo.mtime); } /* Initialize the respone buffer with a hidden value */ @@ -1378,18 +1521,23 @@ static void * APR_THREAD_FUNC thread_worker(apr_thread_t *thread, void *data) response_buf[1] = 1; if (finfo.size == 0) { - error_log(LOG_WARNING, thread, "File found (%" APR_SIZE_T_FMT " bytes), skipping.", finfo.size); + error_log(LOG_WARNING, thread, + "File found (%" APR_SIZE_T_FMT + " bytes), skipping.", finfo.size); take_new = 1; nodelay = 1; goto THREAD_CLEANUP; } else { - error_log(LOG_DEBUG, thread, "File found (%" APR_SIZE_T_FMT " bytes), activating cURL.", finfo.size); + error_log(LOG_DEBUG, thread, + "File found (%" APR_SIZE_T_FMT + " bytes), activating cURL.", finfo.size); } curl_easy_setopt(curl, CURLOPT_VERBOSE, 1); - curl_easy_setopt(curl, CURLOPT_DEBUGFUNCTION, curl_debugfunction); + curl_easy_setopt(curl, CURLOPT_DEBUGFUNCTION, + curl_debugfunction); curl_easy_setopt(curl, CURLOPT_DEBUGDATA, thread); curl_easy_setopt(curl, CURLOPT_ERRORBUFFER, curl_error_buffer); curl_easy_setopt(curl, CURLOPT_USERPWD, credentials); @@ -1402,7 +1550,9 @@ static void * APR_THREAD_FUNC thread_worker(apr_thread_t *thread, void *data) hd_src = fopen(auditlogentry, "rb"); if (hd_src == NULL) { - error_log(LOG_WARNING, thread, "Invalid entry (failed to open file for reading): %s", auditlogentry); + error_log(LOG_WARNING, thread, + "Invalid entry (failed to open file for " + "reading): %s", auditlogentry); take_new = 1; nodelay = 1; goto THREAD_CLEANUP; @@ -1410,9 +1560,10 @@ static void * APR_THREAD_FUNC thread_worker(apr_thread_t *thread, void *data) curl_easy_setopt(curl, CURLOPT_READDATA, hd_src); curl_easy_setopt(curl, CURLOPT_INFILESIZE_LARGE, finfo.size); -#if 0 - mandatory on win32? - curl_easy_setopt(curl, CURLOPT_READFUNCTION, read_callback); + +#ifdef WIN32 + /* Mandatory on win32 */ + curl_easy_setopt(curl, CURLOPT_READFUNCTION, curl_readfunction); #endif res = curl_easy_perform(curl); @@ -1422,22 +1573,32 @@ static void * APR_THREAD_FUNC thread_worker(apr_thread_t *thread, void *data) if (res == 0) { long response_code = 0; - res = curl_easy_getinfo(curl, CURLINFO_RESPONSE_CODE, &response_code); - error_log(LOG_DEBUG, thread, "Request returned with status \"%ld %s\": %s", response_code, response_buf, uniqueid); + res = curl_easy_getinfo(curl, CURLINFO_RESPONSE_CODE, + &response_code); + error_log(LOG_DEBUG, thread, + "Request returned with status \"%ld %s\": %s", + response_code, response_buf, uniqueid); if (response_code == 0) { /* Assume problem with connection */ - error_log(LOG_WARNING, thread, "Flagging server as errored after failure to retrieve response code for entry %s (cURL code %d): Possible SSL negotiation error", - uniqueid, res); + error_log(LOG_WARNING, thread, + "Flagging server as errored after failure " + "to retrieve response code for entry %s " + "(cURL code %d): Possible SSL negotiation " + "error", + uniqueid, res); apr_sleep(1000 * 1000); take_new = 0; server_error = 1; server_error_last_check_time = apr_time_now(); } else if (res != 0) { - error_log(LOG_WARNING, thread, "Flagging server as errored after failure to retrieve response code for entry %s (cURL code %d): %s", - uniqueid, res, curl_error_buffer); + error_log(LOG_WARNING, thread, + "Flagging server as errored after failure " + "to retrieve response code for entry %s " + "(cURL code %d): %s", + uniqueid, res, curl_error_buffer); apr_sleep(1000 * 1000); take_new = 0; server_error = 1; @@ -1448,37 +1609,51 @@ static void * APR_THREAD_FUNC thread_worker(apr_thread_t *thread, void *data) double total_time, upload_size; if (server_error == 1) { - error_log(LOG_NOTICE, thread, "Clearing the server error flag after successful entry submission: %s", uniqueid); + error_log(LOG_NOTICE, thread, + "Clearing the server error flag " + "after successful entry " + "submission: %s", uniqueid); } server_error = 0; server_error_last_check_time = 0; - curl_easy_getinfo(curl, CURLINFO_TOTAL_TIME, &total_time); - curl_easy_getinfo(curl, CURLINFO_SIZE_UPLOAD, &upload_size); + curl_easy_getinfo(curl, CURLINFO_TOTAL_TIME, + &total_time); + curl_easy_getinfo(curl, CURLINFO_SIZE_UPLOAD, + &upload_size); if (!keep_entries) { - error_log(LOG_DEBUG, thread, "Removing: %s", auditlogentry); + error_log(LOG_DEBUG, thread, + "Removing: %s", auditlogentry); apr_file_remove(auditlogentry, tpool); } - else if (keep_entries == KEEP_ENTRIES_REMOVE_HACK) { + else if (keep_entries == KEEP_ENTRIES_REMOVE_HACK) + { keep_entries_hack(tpool, thread, auditlogentry); } - error_log(LOG_NOTICE, thread, "Entry completed (%.3f seconds, %.0f bytes): %s", - total_time, upload_size, - uniqueid); + error_log(LOG_NOTICE, thread, + "Entry completed (%.3f seconds, %.0f " + "bytes): %s", + total_time, upload_size, + uniqueid); take_new = 1; } else if (response_code == 409) { /* Assume problem with audit log entry. */ - error_log(LOG_WARNING, thread, "Failed to submit entry with \"409 %s\": %s", - response_buf, uniqueid); + error_log(LOG_WARNING, thread, + "Failed to submit entry with " + "\"409 %s\": %s", + response_buf, uniqueid); take_new = 1; } else { /* Assume problem with server. */ - error_log(LOG_WARNING, thread, "Flagging server as errored after failure to submit entry %s with HTTP response code %ld: %s", - uniqueid, response_code, response_buf); + error_log(LOG_WARNING, thread, + "Flagging server as errored after " + "failure to submit entry %s with " + "HTTP response code %ld: %s", + uniqueid, response_code, response_buf); server_error = 1; server_error_last_check_time = apr_time_now(); take_new = 0; @@ -1486,7 +1661,11 @@ static void * APR_THREAD_FUNC thread_worker(apr_thread_t *thread, void *data) } } else { /* Something isn't right. */ - error_log(LOG_WARNING, thread, "Flagging server as errored after failure to submit entry %s (cURL code %d): %s", uniqueid, res, curl_error_buffer); + error_log(LOG_WARNING, thread, + "Flagging server as errored after " + "failure to submit entry %s " + "(cURL code %d): %s", + uniqueid, res, curl_error_buffer); server_error = 1; server_error_last_check_time = apr_time_now(); take_new = 0; @@ -1494,7 +1673,9 @@ static void * APR_THREAD_FUNC thread_worker(apr_thread_t *thread, void *data) } } else { - error_log(LOG_WARNING, thread, "Invalid entry (file not found %d): %s", rc, auditlogentry); + error_log(LOG_WARNING, thread, + "Invalid entry (file not found %d): %s", + rc, auditlogentry); take_new = 1; nodelay = 1; } @@ -1503,7 +1684,9 @@ static void * APR_THREAD_FUNC thread_worker(apr_thread_t *thread, void *data) * over our threshold. */ if (num_requests && (num_requests >= max_worker_requests)) { - error_log(LOG_NOTICE, thread, "Reached max requests (%d) for this worker, exiting.", max_worker_requests); + error_log(LOG_NOTICE, thread, + "Reached max requests (%d) for this worker, exiting.", + max_worker_requests); goto THREAD_SHUTDOWN; } @@ -1514,7 +1697,8 @@ static void * APR_THREAD_FUNC thread_worker(apr_thread_t *thread, void *data) /* Sleep if we sent data to the server so we do not flood */ /* ENH: Need to sleep for 1ms in a loop checking for shutdown */ if ((nodelay == 0) && (transaction_delay > 0)) { - error_log(LOG_DEBUG, thread, "Sleeping for %d msec.", transaction_delay); + error_log(LOG_DEBUG, thread, + "Sleeping for %d msec.", transaction_delay); apr_sleep(transaction_delay * 1000); } @@ -1532,7 +1716,8 @@ static void * APR_THREAD_FUNC thread_worker(apr_thread_t *thread, void *data) error_log(LOG_DEBUG, thread, "Worker shutdown locking thread mutex."); if (APR_STATUS_IS_EBUSY(apr_thread_mutex_trylock(mutex))) { - error_log(LOG_DEBUG, thread, "Worker shutdown waiting on thread mutex."); + error_log(LOG_DEBUG, thread, + "Worker shutdown waiting on thread mutex."); apr_thread_mutex_lock(mutex); } @@ -1583,7 +1768,8 @@ static void create_new_worker(int lock) if (lock) { error_log(LOG_DEBUG, NULL, "Worker creation locking thread mutex."); if (APR_STATUS_IS_EBUSY(apr_thread_mutex_trylock(mutex))) { - error_log(LOG_DEBUG, NULL, "Worker creation waiting on thread mutex."); + error_log(LOG_DEBUG, NULL, + "Worker creation waiting on thread mutex."); apr_thread_mutex_lock(mutex); } } @@ -1596,7 +1782,8 @@ static void create_new_worker(int lock) */ if (current_workers >= max_connections) { if (lock) { - error_log(LOG_DEBUG, NULL, "Worker creation unlocking thread mutex."); + error_log(LOG_DEBUG, NULL, + "Worker creation unlocking thread mutex."); apr_thread_mutex_unlock(mutex); } return; @@ -1622,13 +1809,16 @@ static void create_new_worker(int lock) apr_threadattr_detach_set(thread_attrs, 1); apr_threadattr_stacksize_set(thread_attrs, 1024); - rc = apr_thread_create(&thread, thread_attrs, thread_worker, *curlptr, thread_pool); + rc = apr_thread_create(&thread, thread_attrs, + thread_worker, *curlptr, thread_pool); if (rc != APR_SUCCESS) { if (lock) { - error_log(LOG_DEBUG, NULL, "Worker creation unlocking thread mutex."); + error_log(LOG_DEBUG, NULL, + "Worker creation unlocking thread mutex."); apr_thread_mutex_unlock(mutex); } - error_log(LOG_ERROR, NULL, "Failed to create new worker thread: %d", rc); + error_log(LOG_ERROR, NULL, + "Failed to create new worker thread: %d", rc); logc_shutdown(1); } @@ -1636,7 +1826,8 @@ static void create_new_worker(int lock) } else { if (lock) { - error_log(LOG_DEBUG, NULL, "Worker creation unlocking thread mutex."); + error_log(LOG_DEBUG, NULL, + "Worker creation unlocking thread mutex."); apr_thread_mutex_unlock(mutex); } error_log(LOG_ERROR, NULL, "No more cURL handles (Internal Error)."); @@ -1668,13 +1859,16 @@ static void * APR_THREAD_FUNC thread_manager(apr_thread_t *thread, void *data) /* Should we stop running? */ if (running == 0) { /* We need to be last */ - error_log(LOG_DEBUG, thread, "Management thread: Waiting for worker threads to finish."); + error_log(LOG_DEBUG, thread, + "Management thread: Waiting for worker " + "threads to finish."); while(current_workers > 0) { apr_sleep(10 * 1000); } if (have_read_data) { - error_log(LOG_NOTICE, thread, "Running final transaction checkpoint."); + error_log(LOG_NOTICE, thread, + "Running final transaction checkpoint."); transaction_checkpoint(); } @@ -1698,30 +1892,43 @@ static void * APR_THREAD_FUNC thread_manager(apr_thread_t *thread, void *data) */ if (server_error) { if ((current_workers == 0)&& - (apr_time_sec(now - server_error_last_check_time) > server_error_timeout)) + (apr_time_sec(now - server_error_last_check_time) + > server_error_timeout)) { server_error_last_check_time = now; - error_log(LOG_DEBUG, thread, "Management thread: Creating worker thread to investigate server."); + error_log(LOG_DEBUG, thread, + "Management thread: Creating worker thread to " + "investigate server."); create_new_worker(1); } } else { - if ((current_workers < max_connections)&&(queue->nelts > current_workers)) { - error_log(LOG_DEBUG, thread, "Management thread: Creating worker thread to catch up with the queue."); + if ( (current_workers < max_connections) + && (queue->nelts > current_workers) ) + { + error_log(LOG_DEBUG, thread, + "Management thread: Creating worker thread to " + "catch up with the queue."); create_new_worker(1); } } - /* Initiate a transaction log checkpoint if enough time passed since the last one. */ + /* Initiate a transaction log checkpoint if enough time passed + * since the last one. + */ if (apr_time_sec(now - checkpoint_time_last) > checkpoint_interval) { - error_log(LOG_DEBUG, thread, "Management thread: Initiating a checkpoint" - " (previous was %" APR_TIME_T_FMT " seconds ago).", apr_time_sec(now - checkpoint_time_last)); + error_log(LOG_DEBUG, thread, + "Management thread: Initiating a checkpoint " + "(previous was %" APR_TIME_T_FMT " seconds ago).", + apr_time_sec(now - checkpoint_time_last)); checkpoint_time_last = now; transaction_checkpoint(); } else { - error_log(LOG_DEBUG2, thread, "Management thread: Last checkpoint was %" APR_TIME_T_FMT " seconds ago.", - apr_time_sec(now - checkpoint_time_last)); + error_log(LOG_DEBUG2, thread, + "Management thread: Last checkpoint was %" APR_TIME_T_FMT + " seconds ago.", + apr_time_sec(now - checkpoint_time_last)); } } @@ -1782,7 +1989,13 @@ static void receive_loop(void) { apr_status_t rc; if (error_log_level >= LOG_DEBUG2) { - error_log(LOG_DEBUG2, NULL, "Internal state: [evnt \"%" APR_SIZE_T_FMT "\"][curr \"%" APR_SIZE_T_FMT "\"][next \"%" APR_SIZE_T_FMT "\"][nbytes \"%" APR_SIZE_T_FMT "\"]", evnt, curr, next, nbytes); + error_log(LOG_DEBUG2, NULL, + "Internal state: " + "[evnt \"%" APR_SIZE_T_FMT "\"]" + "[curr \"%" APR_SIZE_T_FMT "\"]" + "[next \"%" APR_SIZE_T_FMT "\"]" + "[nbytes \"%" APR_SIZE_T_FMT "\"]", + evnt, curr, next, nbytes); } /* If we are not done and have the space, read more */ @@ -1792,17 +2005,24 @@ static void receive_loop(void) { rc = apr_file_read(fd_stdin, (buf + next), &nbytes); if (rc != APR_SUCCESS) { if (have_read_data) { - error_log(LOG_NOTICE, NULL, "No more data to read, emptying buffer: %s", apr_strerror(rc, errstr, 1024)); + error_log(LOG_NOTICE, NULL, + "No more data to read, emptying buffer: %s", + apr_strerror(rc, errstr, 1024)); } done = 1; } else { have_read_data = 1; if (error_log_level == LOG_DEBUG) { - error_log(LOG_DEBUG, NULL, "Read %" APR_SIZE_T_FMT " bytes from pipe", nbytes); + error_log(LOG_DEBUG, NULL, + "Read %" APR_SIZE_T_FMT " bytes from pipe", + nbytes); } else { - error_log(LOG_DEBUG2, NULL, "Read %" APR_SIZE_T_FMT " bytes from pipe: `%s'", nbytes, _log_escape(tmp_pool, (buf + next), nbytes)); + error_log(LOG_DEBUG2, NULL, + "Read %" APR_SIZE_T_FMT " bytes from pipe: `%s'", + nbytes, + _log_escape(tmp_pool, (buf + next), nbytes)); } } @@ -1826,13 +2046,22 @@ static void receive_loop(void) { /* We may have to drop this one if it previously failed */ if (drop_next) { - error_log(LOG_ERROR, NULL, "Dropping remaining portion of failed event: `%s'", _log_escape(tmp_pool, (buf + evnt), (curr - evnt))); + error_log(LOG_ERROR, NULL, + "Dropping remaining portion of failed " + "event: `%s'", + _log_escape(tmp_pool, + (buf + evnt), (curr - evnt))); drop_next = 0; } else { transaction_log(TXIN, buf + evnt); - error_log(LOG_DEBUG2, NULL, "Received audit log entry (count %lu queue %d workers %d): %s", - entry_counter, queue->nelts, current_workers, _log_escape(tmp_pool, (buf + evnt), strlen(buf + evnt))); + error_log(LOG_DEBUG2, NULL, + "Received audit log entry " + "(count %lu queue %d workers %d): %s", + entry_counter, queue->nelts, + current_workers, + _log_escape(tmp_pool, + (buf + evnt), strlen(buf + evnt))); add_entry(buf + evnt, 1); buffered_events++; } @@ -1841,21 +2070,28 @@ static void receive_loop(void) { evnt = curr = curr + 1; } else { - error_log(LOG_DEBUG2, NULL, "Event buffer contains partial event: `%s'", _log_escape(tmp_pool, (buf + evnt), (next - evnt))); + error_log(LOG_DEBUG2, NULL, + "Event buffer contains partial event: `%s'", + _log_escape(tmp_pool, (buf + evnt), (next - evnt))); break; } } if (buffered_events > 0) { - error_log(LOG_DEBUG, NULL, "Processed %d entries from buffer.", buffered_events); + error_log(LOG_DEBUG, NULL, + "Processed %d entries from buffer.", buffered_events); /* Move the unused portion of the buffer to the beginning */ next -= evnt; curr -= evnt; memmove(buf, (buf + evnt), next); - error_log(LOG_DEBUG2, NULL, "Shifted buffer back %" APR_SIZE_T_FMT " and offset %" APR_SIZE_T_FMT " bytes for next read: `%s'", evnt, next, _log_escape(tmp_pool, buf, next)); + error_log(LOG_DEBUG2, NULL, + "Shifted buffer back %" APR_SIZE_T_FMT + " and offset %" APR_SIZE_T_FMT + " bytes for next read: `%s'", + evnt, next, _log_escape(tmp_pool, buf, next)); evnt = 0; } @@ -1867,10 +2103,15 @@ static void receive_loop(void) { */ if (drop_next) { - error_log(LOG_ERROR, NULL, "Event continuation too large, dropping it as well: `%s'", _log_escape(tmp_pool, buf, PIPE_BUF_SIZE)); + error_log(LOG_ERROR, NULL, + "Event continuation too large, " + "dropping it as well: `%s'", + _log_escape(tmp_pool, buf, PIPE_BUF_SIZE)); } else { - error_log(LOG_ERROR, NULL, "Event too large, dropping event: `%s'", _log_escape(tmp_pool, buf, PIPE_BUF_SIZE)); + error_log(LOG_ERROR, NULL, + "Event too large, dropping event: `%s'", + _log_escape(tmp_pool, buf, PIPE_BUF_SIZE)); } /* Rewind buf and mark that we need to drop up to the next event */ @@ -1893,12 +2134,14 @@ static void receive_loop(void) { /* Wait for queue to empty if specified */ if ((server_error == 0) && (opt_force != 0) && (queue->nelts > 0)) { - error_log(LOG_NOTICE, NULL, "Waiting for queue to empty (%d active).", queue->nelts); + error_log(LOG_NOTICE, NULL, + "Waiting for queue to empty (%d active).", queue->nelts); while ((server_error == 0) && (opt_force != 0) && (queue->nelts > 0)) { apr_sleep(10 * 1000); } if (queue->nelts > 0) { - error_log(LOG_ERROR, NULL, "Could not empty queue (%d active).", queue->nelts); + error_log(LOG_ERROR, NULL, + "Could not empty queue (%d active).", queue->nelts); } } } @@ -1921,7 +2164,8 @@ static void start_management_thread(void) rc = apr_thread_create(&thread, thread_attrs, thread_manager, NULL, pool); if (rc != APR_SUCCESS) { - error_log(LOG_ERROR, NULL, "Failed to create new management thread: %d", rc); + error_log(LOG_ERROR, NULL, + "Failed to create new management thread: %d", rc); management_thread_active = 0; logc_shutdown(1); } @@ -1942,7 +2186,8 @@ static void start_signal_thread(void) rc = apr_thread_create(&thread, thread_attrs, thread_signals, NULL, pool); if (rc != APR_SUCCESS) { - error_log(LOG_ERROR, NULL, "Failed to create new signal thread: %d", rc); + error_log(LOG_ERROR, NULL, + "Failed to create new signal thread: %d", rc); logc_shutdown(1); } } @@ -1965,10 +2210,17 @@ static void usage(void) { * Version text. */ static void version(void) { - fprintf(stderr, "ModSecurity Log Collector (mlogc) v%s\n", VERSION); - fprintf(stderr, " APR: compiled=\"%s\"; loaded=\"%s\"\n", APR_VERSION_STRING, apr_version_string()); - fprintf(stderr, " PCRE: compiled=\"%d.%d\"; loaded=\"%s\"\n", PCRE_MAJOR, PCRE_MINOR, pcre_version()); - fprintf(stderr, " cURL: compiled=\"%s\"; loaded=\"%s\"\n", LIBCURL_VERSION, curl_version()); + fprintf(stderr, + "ModSecurity Log Collector (mlogc) v%s\n", VERSION); + fprintf(stderr, + " APR: compiled=\"%s\"; " + "loaded=\"%s\"\n", APR_VERSION_STRING, apr_version_string()); + fprintf(stderr, + " PCRE: compiled=\"%d.%d\"; " + "loaded=\"%s\"\n", PCRE_MAJOR, PCRE_MINOR, pcre_version()); + fprintf(stderr, + " cURL: compiled=\"%s\"; " + "loaded=\"%s\"\n", LIBCURL_VERSION, curl_version()); fprintf(stderr, "\n"); } @@ -2013,23 +2265,23 @@ int main(int argc, const char * const argv[]) { const char *val; rc = apr_getopt(opt, CMDLINE_OPTS, &ch, &val); switch (rc) { - case APR_SUCCESS: - switch (ch) { - case 'f': - opt_force = 1; - break; - case 'v': - version(); - logc_shutdown(0); - case 'h': - usage(); - logc_shutdown(0); - } - break; - case APR_BADCH: - case APR_BADARG: - usage(); - logc_shutdown(1); + case APR_SUCCESS: + switch (ch) { + case 'f': + opt_force = 1; + break; + case 'v': + version(); + logc_shutdown(0); + case 'h': + usage(); + logc_shutdown(0); + } + break; + case APR_BADCH: + case APR_BADARG: + usage(); + logc_shutdown(1); } } while (rc != APR_EOF); diff --git a/apache2/msc_pcre.c b/apache2/msc_pcre.c index 89f42a71..84f63801 100644 --- a/apache2/msc_pcre.c +++ b/apache2/msc_pcre.c @@ -29,7 +29,7 @@ apr_status_t msc_pcre_cleanup(msc_regex_t *regex) { regex->pe = NULL; } if (regex->re != NULL) { - free(regex->re); + pcre_free(regex->re); regex->re = NULL; } } diff --git a/doc/modsecurity2-apache-reference.xml b/doc/modsecurity2-apache-reference.xml index efb2e50d..3b509987 100644 --- a/doc/modsecurity2-apache-reference.xml +++ b/doc/modsecurity2-apache-reference.xml @@ -460,18 +460,29 @@ SecAuditLogStorageDir logs/audit Processing Phase: N/A Scope: Any Version: 2.0.0 - Dependencies/Notes: This file is open on startup when the server - typically still runs as root. You should not allow non-root users to - have write privileges for this file or for the directory it is stored in.. - This file will be used to store the audit log entries if serial audit logging format is - used. If concurrent audit logging format is used this file will be used as an index, and - contain a record of all audit log files created. If you are planning to use Concurrent audit - logging and sending your audit log data off to a remote Console host or commercial - ModSecurity Management Appliance, then you will need to configure and use the ModSecurity - Log Collector (mlogc) and use the following format for the audit log: - - SecAuditLog "|/path/to/mlogc /path/to/mlogc.conf" - + + Dependencies/Notes: This file is open on + startup when the server typically still runs as + root. You should not allow non-root users to have write + privileges for this file or for the directory it is stored in.. + + This file will be used to store the audit log entries if serial + audit logging format is used. If concurrent audit logging format is used + this file will be used as an index, and contain a record of all audit + log files created. If you are planning to use Concurrent audit logging + and sending your audit log data off to a remote Console host or + commercial ModSecurity Management Appliance, then you will need to + configure and use the ModSecurity Log Collector (mlogc) and use the + following format for the audit log: + + + Prior to 2.5.13 you may have been able to use a relative path to + a piped logger command, but this was broken on some platforms and the + feature was removed in 2.5.13 to make the platforms more + consitent. + + + SecAuditLog "|/path/to/mlogc /path/to/mlogc.conf"
<literal>SecAuditLog2</literal>