From 46291898e1598f0c43bbf807e86c3ac8590521f5 Mon Sep 17 00:00:00 2001 From: Jacquin Antoine Date: Sat, 28 Feb 2026 20:28:40 +0100 Subject: [PATCH] =?UTF-8?q?fix:=20renforcer=20la=20robustesse=20du=20modul?= =?UTF-8?q?e=20et=20=C3=A9tendre=20les=20tests/CI?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Co-authored-by: aider (openrouter/openai/gpt-5.3-codex) --- .gitlab-ci.yml | 49 +-- CMakeLists.txt | 14 +- Makefile | 11 +- README.md | 2 + conf/mod_reqin_log.conf | 2 + src/mod_reqin_log.c | 425 +++++++++++++++++--------- src/mod_reqin_log.h | 1 + tests/integration/test_integration.py | 292 ++++++++---------- tests/unit/test_config_parsing.c | 160 ++++++++-- tests/unit/test_json_serialization.c | 226 ++++++++------ 10 files changed, 735 insertions(+), 447 deletions(-) diff --git a/.gitlab-ci.yml b/.gitlab-ci.yml index e36c2fe..df1367d 100644 --- a/.gitlab-ci.yml +++ b/.gitlab-ci.yml @@ -24,18 +24,14 @@ build-packages: - docker:24-dind script: # Build all packages (DEB + RPMs for el7, el8, el9) - - docker build -f Dockerfile.package - --target output - --build-arg VERSION=$VERSION - -t mod_reqin_log:packages . - + - docker build -f Dockerfile.package --target output --build-arg VERSION=$VERSION -t mod_reqin_log:packages . + # Create output directories - mkdir -p dist/deb dist/rpm - + # Extract packages from Docker image - - docker run --rm -v $(pwd)/dist:/output mod_reqin_log:packages - sh -c 'cp -r /packages/deb/* /output/deb/ && cp -r /packages/rpm/* /output/rpm/' - + - docker run --rm -v $(pwd)/dist:/output mod_reqin_log:packages sh -c 'cp -r /packages/deb/* /output/deb/ && cp -r /packages/rpm/* /output/rpm/' + # List built packages - echo "=== DEB Packages ===" - ls -la dist/deb/ @@ -59,7 +55,7 @@ unit-tests: script: # Build test image - docker build -f Dockerfile.tests -t mod_reqin_log:tests . - + # Run unit tests - docker run --rm mod_reqin_log:tests ctest --output-on-failure @@ -80,18 +76,10 @@ verify-rpm-el7: script: # Download artifacts - apk add --no-cache curl - - curl -L -o /tmp/rpm-el7.rpm "$CI_PROJECT_URL/-/jobs/$CI_JOB_ID/artifacts/dist/rpm/mod_reqin_log-$VERSION-1.el7.x86_64.rpm" - 2>/dev/null || echo "Artifact download via curl failed, trying alternative..." - + - curl -L -o /tmp/rpm-el7.rpm "$CI_PROJECT_URL/-/jobs/$CI_JOB_ID/artifacts/dist/rpm/mod_reqin_log-$VERSION-1.el7.x86_64.rpm" 2>/dev/null || echo "Artifact download via curl failed, trying alternative..." + # Alternative: extract from build artifact - - docker run --rm -v $(pwd)/dist:/packages centos:7 sh -c " - sed -i 's/mirror.centos.org/vault.centos.org/g' /etc/yum.repos.d/*.repo && - sed -i 's/#baseurl/baseurl/g' /etc/yum.repos.d/*.repo && - sed -i 's/metalink/#metalink/g' /etc/yum.repos.d/*.repo && - yum install -y /packages/rpm/*.el7.*.rpm && - httpd -M 2>&1 | grep reqin_log && - echo 'RPM el7 verification OK' - " + - docker run --rm -v $(pwd)/dist:/packages centos:7 sh -c "sed -i 's/mirror.centos.org/vault.centos.org/g' /etc/yum.repos.d/*.repo && sed -i 's/#baseurl/baseurl/g' /etc/yum.repos.d/*.repo && sed -i 's/metalink/#metalink/g' /etc/yum.repos.d/*.repo && yum install -y /packages/rpm/*.el7.*.rpm && httpd -M 2>&1 | grep reqin_log && echo 'RPM el7 verification OK'" allow_failure: true verify-rpm-el8: @@ -101,11 +89,7 @@ verify-rpm-el8: - docker:24-dind needs: [build-packages] script: - - docker run --rm -v $(pwd)/dist:/packages rockylinux:8 sh -c " - dnf install -y /packages/rpm/*.el8.*.rpm && - httpd -M 2>&1 | grep reqin_log && - echo 'RPM el8 verification OK' - " + - docker run --rm -v $(pwd)/dist:/packages rockylinux:8 sh -c "dnf install -y /packages/rpm/*.el8.*.rpm && httpd -M 2>&1 | grep reqin_log && echo 'RPM el8 verification OK'" verify-rpm-el9: stage: verify @@ -114,11 +98,7 @@ verify-rpm-el9: - docker:24-dind needs: [build-packages] script: - - docker run --rm -v $(pwd)/dist:/packages rockylinux:9 sh -c " - dnf install -y /packages/rpm/*.el9.*.rpm && - httpd -M 2>&1 | grep reqin_log && - echo 'RPM el9 verification OK' - " + - docker run --rm -v $(pwd)/dist:/packages rockylinux:9 sh -c "dnf install -y /packages/rpm/*.el9.*.rpm && httpd -M 2>&1 | grep reqin_log && echo 'RPM el9 verification OK'" verify-deb: stage: verify @@ -127,9 +107,4 @@ verify-deb: - docker:24-dind needs: [build-packages] script: - - docker run --rm -v $(pwd)/dist:/packages debian:stable sh -c " - apt-get update && - apt-get install -y /packages/deb/*.deb && - ls -la /usr/lib/apache2/modules/mod_reqin_log.so && - echo 'DEB verification OK' - " + - docker run --rm -v $(pwd)/dist:/packages debian:stable sh -c "apt-get update && apt-get install -y /packages/deb/*.deb && ls -la /usr/lib/apache2/modules/mod_reqin_log.so && echo 'DEB verification OK'" diff --git a/CMakeLists.txt b/CMakeLists.txt index 367a690..64bbe0c 100644 --- a/CMakeLists.txt +++ b/CMakeLists.txt @@ -20,12 +20,24 @@ include_directories(/usr/include/httpd) add_executable(test_module_real tests/unit/test_module_real.c) target_link_libraries(test_module_real ${CMOCKA_LIBRARIES} ${APR_LIBRARIES} ${APRUTIL_LIBRARIES} m) +add_executable(test_config_parsing tests/unit/test_config_parsing.c) +target_link_libraries(test_config_parsing ${CMOCKA_LIBRARIES}) + +add_executable(test_header_handling tests/unit/test_header_handling.c) +target_link_libraries(test_header_handling ${CMOCKA_LIBRARIES} ${APR_LIBRARIES}) + +add_executable(test_json_serialization tests/unit/test_json_serialization.c) +target_link_libraries(test_json_serialization ${CMOCKA_LIBRARIES} ${APR_LIBRARIES}) + # Enable testing enable_testing() add_test(NAME RealModuleTest COMMAND test_module_real) +add_test(NAME ConfigParsingTest COMMAND test_config_parsing) +add_test(NAME HeaderHandlingTest COMMAND test_header_handling) +add_test(NAME JsonSerializationTest COMMAND test_json_serialization) # Custom target for running tests add_custom_target(run_tests COMMAND ${CMAKE_CTEST_COMMAND} --output-on-failure - DEPENDS test_module_real + DEPENDS test_module_real test_config_parsing test_header_handling test_json_serialization ) diff --git a/Makefile b/Makefile index bdbdfc0..d433f10 100644 --- a/Makefile +++ b/Makefile @@ -43,7 +43,16 @@ $(MODULE_NAME).so: $(SRCS) install: $(MODULE_NAME).so @echo "Installing $(MODULE_NAME).so..." @mkdir -p $(DESTDIR)/usr/lib/apache2/modules - cp $(BUILD_DIR)/$(MODULE_NAME).so $(DESTDIR)/usr/lib/apache2/modules/ + @if [ -f $(INSTALL_DIR)/$(MODULE_NAME).so ]; then \ + cp $(INSTALL_DIR)/$(MODULE_NAME).so $(DESTDIR)/usr/lib/apache2/modules/; \ + elif [ -f $(BUILD_DIR)/.libs/$(MODULE_NAME).so ]; then \ + cp $(BUILD_DIR)/.libs/$(MODULE_NAME).so $(DESTDIR)/usr/lib/apache2/modules/; \ + elif [ -f $(BUILD_DIR)/$(MODULE_NAME).so ]; then \ + cp $(BUILD_DIR)/$(MODULE_NAME).so $(DESTDIR)/usr/lib/apache2/modules/; \ + else \ + echo "Error: $(MODULE_NAME).so not found"; \ + exit 1; \ + fi @echo "Installation complete." @echo "Enable the module by adding to your httpd.conf:" @echo " LoadModule reqin_log_module modules/mod_reqin_log.so" diff --git a/README.md b/README.md index b043cf7..2d57533 100644 --- a/README.md +++ b/README.md @@ -78,6 +78,8 @@ JsonSockLogReconnectInterval 10 JsonSockLogErrorReportInterval 10 ``` +> **Important startup validation:** if `JsonSockLogEnabled On` is set without a valid `JsonSockLogSocket`, Apache startup fails with a configuration error. + ### Configuration Directives | Directive | Type | Default | Description | diff --git a/conf/mod_reqin_log.conf b/conf/mod_reqin_log.conf index a5139a0..808f5a5 100644 --- a/conf/mod_reqin_log.conf +++ b/conf/mod_reqin_log.conf @@ -8,6 +8,8 @@ LoadModule reqin_log_module modules/mod_reqin_log.so JsonSockLogEnabled On # Unix domain socket path for JSON log output +# Important: if JsonSockLogEnabled is On and this directive is missing/empty, +# Apache startup fails due to strict configuration validation. JsonSockLogSocket "/var/run/mod_reqin_log.sock" # HTTP headers to include in the JSON log diff --git a/src/mod_reqin_log.c b/src/mod_reqin_log.c index 872abd0..c0958ed 100644 --- a/src/mod_reqin_log.c +++ b/src/mod_reqin_log.c @@ -10,6 +10,7 @@ #include "http_log.h" #include "http_protocol.h" #include "http_request.h" +#include "mod_reqin_log.h" #include "apr_strings.h" #include "apr_time.h" #include "apr_lib.h" @@ -24,12 +25,15 @@ #include #include #include - -#define MOD_REQIN_LOG_NAME "mod_reqin_log" +#include +#include /* Maximum Unix socket path length (sun_path is typically 108 bytes) */ #define MAX_SOCKET_PATH_LEN (sizeof(((struct sockaddr_un *)0)->sun_path) - 1) +/* Maximum JSON log line size (64KB) - prevents memory exhaustion DoS */ +#define MAX_JSON_SIZE (64 * 1024) + /* Default sensitive headers blacklist - prevents accidental logging of credentials */ static const char *const DEFAULT_SENSITIVE_HEADERS[] = { "Authorization", @@ -42,26 +46,6 @@ static const char *const DEFAULT_SENSITIVE_HEADERS[] = { NULL }; -/* Maximum JSON log line size (64KB) - prevents memory exhaustion DoS */ -#define MAX_JSON_SIZE (64 * 1024) - -/* Default configuration values */ -#define DEFAULT_MAX_HEADERS 10 -#define DEFAULT_MAX_HEADER_VALUE_LEN 256 -#define DEFAULT_RECONNECT_INTERVAL 10 -#define DEFAULT_ERROR_REPORT_INTERVAL 10 - -/* Module configuration structure */ -typedef struct { - int enabled; - const char *socket_path; - apr_array_header_t *headers; - int max_headers; - int max_header_value_len; - int reconnect_interval; - int error_report_interval; -} reqin_log_config_t; - /* Dynamic string buffer */ typedef struct { char *data; @@ -90,6 +74,7 @@ typedef struct { static void dynbuf_append(dynbuf_t *db, const char *str, apr_size_t len); static void append_json_string(dynbuf_t *db, const char *str); static void format_iso8601(dynbuf_t *db, apr_time_t t); +static int parse_int_strict(const char *arg, int *out); /* Forward declarations for server config */ static void *reqin_log_create_server_conf(apr_pool_t *pool, server_rec *s); @@ -106,6 +91,7 @@ static const char *cmd_set_error_report_interval(cmd_parms *cmd, void *dummy, co /* Forward declarations for hooks */ static int reqin_log_post_read_request(request_rec *r); static void reqin_log_child_init(apr_pool_t *p, server_rec *s); +static int reqin_log_post_config(apr_pool_t *pconf, apr_pool_t *plog, apr_pool_t *ptemp, server_rec *s); static void reqin_log_register_hooks(apr_pool_t *p); /* Command table */ @@ -141,8 +127,7 @@ module AP_MODULE_DECLARE_DATA reqin_log_module = { /* Get module configuration */ static reqin_log_server_conf_t *get_server_conf(server_rec *s) { - reqin_log_server_conf_t *srv_conf = (reqin_log_server_conf_t *)ap_get_module_config(s->module_config, &reqin_log_module); - return srv_conf; + return (reqin_log_server_conf_t *)ap_get_module_config(s->module_config, &reqin_log_module); } /* Create server configuration */ @@ -164,12 +149,6 @@ static void *reqin_log_create_server_conf(apr_pool_t *pool, server_rec *s) srv_conf->child_state.last_error_report = 0; srv_conf->child_state.connect_failed = 0; - /* Create mutex for thread-safe socket FD access in worker/event MPMs */ - if (apr_thread_mutex_create(&srv_conf->child_state.fd_mutex, - APR_THREAD_MUTEX_DEFAULT, pool) != APR_SUCCESS) { - srv_conf->child_state.fd_mutex = NULL; - } - return srv_conf; } @@ -187,11 +166,11 @@ static void dynbuf_init(dynbuf_t *db, apr_pool_t *pool, apr_size_t initial_capac static void dynbuf_append(dynbuf_t *db, const char *str, apr_size_t len) { if (str == NULL) return; - + if (len == (apr_size_t)-1) { len = strlen(str); } - + if (db->len + len >= db->capacity) { apr_size_t new_capacity = (db->len + len + 1) * 2; char *new_data = apr_palloc(db->pool, new_capacity); @@ -199,7 +178,7 @@ static void dynbuf_append(dynbuf_t *db, const char *str, apr_size_t len) db->data = new_data; db->capacity = new_capacity; } - + memcpy(db->data + db->len, str, len); db->len += len; db->data[db->len] = '\0'; @@ -225,7 +204,7 @@ static void append_json_string(dynbuf_t *db, const char *str) if (str == NULL) { return; } - + for (const char *p = str; *p; p++) { char c = *p; switch (c) { @@ -253,7 +232,7 @@ static void format_iso8601(dynbuf_t *db, apr_time_t t) { apr_time_exp_t tm; apr_time_exp_gmt(&tm, t); - + char time_str[32]; snprintf(time_str, sizeof(time_str), "%04d-%02d-%02dT%02d:%02d:%02dZ", tm.tm_year + 1900, tm.tm_mon + 1, tm.tm_mday, @@ -261,6 +240,18 @@ static void format_iso8601(dynbuf_t *db, apr_time_t t) dynbuf_append(db, time_str, -1); } +static int parse_int_strict(const char *arg, int *out) +{ + char *end = NULL; + long v; + if (arg == NULL || *arg == '\0' || out == NULL) return -1; + errno = 0; + v = strtol(arg, &end, 10); + if (errno != 0 || end == arg || *end != '\0' || v < INT_MIN || v > INT_MAX) return -1; + *out = (int)v; + return 0; +} + /* ============== Configuration Command Handlers ============== */ static const char *cmd_set_enabled(cmd_parms *cmd, void *dummy, int flag) @@ -281,6 +272,12 @@ static const char *cmd_set_socket(cmd_parms *cmd, void *dummy, const char *arg) if (srv_conf == NULL) { return "Internal error: server configuration not available"; } + if (arg == NULL || *arg == '\0') { + return "JsonSockLogSocket must be a non-empty Unix socket path"; + } + if (strlen(arg) >= MAX_SOCKET_PATH_LEN) { + return "JsonSockLogSocket path is too long for Unix domain socket"; + } srv_conf->config->socket_path = apr_pstrdup(cmd->pool, arg); return NULL; } @@ -298,12 +295,15 @@ static const char *cmd_set_headers(cmd_parms *cmd, void *dummy, const char *arg) static const char *cmd_set_max_headers(cmd_parms *cmd, void *dummy, const char *arg) { + int val; (void)dummy; reqin_log_server_conf_t *srv_conf = get_server_conf(cmd->server); if (srv_conf == NULL) { return "Internal error: server configuration not available"; } - int val = atoi(arg); + if (parse_int_strict(arg, &val) != 0) { + return "JsonSockLogMaxHeaders must be a valid integer"; + } if (val < 0) { return "JsonSockLogMaxHeaders must be >= 0"; } @@ -313,12 +313,15 @@ static const char *cmd_set_max_headers(cmd_parms *cmd, void *dummy, const char * static const char *cmd_set_max_header_value_len(cmd_parms *cmd, void *dummy, const char *arg) { + int val; (void)dummy; reqin_log_server_conf_t *srv_conf = get_server_conf(cmd->server); if (srv_conf == NULL) { return "Internal error: server configuration not available"; } - int val = atoi(arg); + if (parse_int_strict(arg, &val) != 0) { + return "JsonSockLogMaxHeaderValueLen must be a valid integer"; + } if (val < 1) { return "JsonSockLogMaxHeaderValueLen must be >= 1"; } @@ -328,12 +331,15 @@ static const char *cmd_set_max_header_value_len(cmd_parms *cmd, void *dummy, con static const char *cmd_set_reconnect_interval(cmd_parms *cmd, void *dummy, const char *arg) { + int val; (void)dummy; reqin_log_server_conf_t *srv_conf = get_server_conf(cmd->server); if (srv_conf == NULL) { return "Internal error: server configuration not available"; } - int val = atoi(arg); + if (parse_int_strict(arg, &val) != 0) { + return "JsonSockLogReconnectInterval must be a valid integer"; + } if (val < 0) { return "JsonSockLogReconnectInterval must be >= 0"; } @@ -343,12 +349,15 @@ static const char *cmd_set_reconnect_interval(cmd_parms *cmd, void *dummy, const static const char *cmd_set_error_report_interval(cmd_parms *cmd, void *dummy, const char *arg) { + int val; (void)dummy; reqin_log_server_conf_t *srv_conf = get_server_conf(cmd->server); if (srv_conf == NULL) { return "Internal error: server configuration not available"; } - int val = atoi(arg); + if (parse_int_strict(arg, &val) != 0) { + return "JsonSockLogErrorReportInterval must be a valid integer"; + } if (val < 0) { return "JsonSockLogErrorReportInterval must be >= 0"; } @@ -367,7 +376,7 @@ static int is_sensitive_header(const char *name) if (name == NULL) { return 0; } - + for (int i = 0; DEFAULT_SENSITIVE_HEADERS[i] != NULL; i++) { if (strcasecmp(name, DEFAULT_SENSITIVE_HEADERS[i]) == 0) { return 1; @@ -391,65 +400,93 @@ static int is_sensitive_header(const char *name) static int try_connect(reqin_log_config_t *cfg, reqin_log_child_state_t *state, server_rec *s) { - apr_time_t now = apr_time_now(); - apr_time_t interval = apr_time_from_sec(cfg->reconnect_interval); + apr_time_t now; + apr_time_t reconnect_interval; + apr_time_t error_interval; + int err = 0; + int should_report = 0; + int fd; + int flags; + struct sockaddr_un addr; + int rc; + + if (cfg == NULL || state == NULL || s == NULL || cfg->socket_path == NULL || cfg->socket_path[0] == '\0') { + return -1; + } + + if (strlen(cfg->socket_path) >= MAX_SOCKET_PATH_LEN) { + ap_log_error(APLOG_MARK, APLOG_ERR, 0, s, + MOD_REQIN_LOG_NAME ": Unix socket path too long, cannot connect"); + return -1; + } + + now = apr_time_now(); + reconnect_interval = apr_time_from_sec(cfg->reconnect_interval); + error_interval = apr_time_from_sec(cfg->error_report_interval); + + FD_MUTEX_LOCK(state); if (state->connect_failed && - (now - state->last_connect_attempt) < interval) { + (now - state->last_connect_attempt) < reconnect_interval) { + FD_MUTEX_UNLOCK(state); return -1; } state->last_connect_attempt = now; - /* Validate socket path length before use */ - if (strlen(cfg->socket_path) >= MAX_SOCKET_PATH_LEN) { - ap_log_error(APLOG_MARK, APLOG_ERR, 0, s, - MOD_REQIN_LOG_NAME ": Configuration error - socket path too long"); - ap_log_error(APLOG_MARK, APLOG_DEBUG, 0, s, - MOD_REQIN_LOG_NAME ": Path length %zu exceeds maximum %zu", - strlen(cfg->socket_path), MAX_SOCKET_PATH_LEN); - return -1; - } - - FD_MUTEX_LOCK(state); if (state->socket_fd < 0) { state->socket_fd = socket(AF_UNIX, SOCK_STREAM, 0); if (state->socket_fd < 0) { - ap_log_error(APLOG_MARK, APLOG_ERR, 0, s, - MOD_REQIN_LOG_NAME ": Failed to create socket"); - ap_log_error(APLOG_MARK, APLOG_DEBUG, errno, s, - MOD_REQIN_LOG_NAME ": Socket creation error detail"); + err = errno; + state->connect_failed = 1; + if ((now - state->last_error_report) >= error_interval) { + state->last_error_report = now; + should_report = 1; + } FD_MUTEX_UNLOCK(state); + + if (should_report) { + ap_log_error(APLOG_MARK, APLOG_ERR, err, s, + MOD_REQIN_LOG_NAME ": Unix socket connect failed: cannot create socket"); + } return -1; } - int flags = fcntl(state->socket_fd, F_GETFL, 0); + flags = fcntl(state->socket_fd, F_GETFL, 0); + if (flags < 0) { + flags = 0; + } fcntl(state->socket_fd, F_SETFL, flags | O_NONBLOCK); } - struct sockaddr_un addr; + fd = state->socket_fd; memset(&addr, 0, sizeof(addr)); addr.sun_family = AF_UNIX; snprintf(addr.sun_path, sizeof(addr.sun_path), "%s", cfg->socket_path); - int rc = connect(state->socket_fd, (struct sockaddr *)&addr, sizeof(addr)); + rc = connect(fd, (struct sockaddr *)&addr, sizeof(addr)); if (rc < 0) { - int err = errno; - if (err != EINPROGRESS && err != EAGAIN && err != EWOULDBLOCK) { - close(state->socket_fd); - state->socket_fd = -1; - state->connect_failed = 1; + err = errno; + if (err == EINPROGRESS || err == EAGAIN || err == EWOULDBLOCK || err == EALREADY || err == EISCONN) { + state->connect_failed = 0; FD_MUTEX_UNLOCK(state); - - if ((now - state->last_error_report) >= apr_time_from_sec(cfg->error_report_interval)) { - ap_log_error(APLOG_MARK, APLOG_ERR, 0, s, - MOD_REQIN_LOG_NAME ": Unix socket connection failed"); - ap_log_error(APLOG_MARK, APLOG_DEBUG, err, s, - MOD_REQIN_LOG_NAME ": Connect failed at %s: %s", cfg->socket_path, strerror(err)); - state->last_error_report = now; - } - return -1; + return 0; } + + close(fd); + state->socket_fd = -1; + state->connect_failed = 1; + if ((now - state->last_error_report) >= error_interval) { + state->last_error_report = now; + should_report = 1; + } + FD_MUTEX_UNLOCK(state); + + if (should_report) { + ap_log_error(APLOG_MARK, APLOG_ERR, err, s, + MOD_REQIN_LOG_NAME ": Unix socket connect failed: %s", cfg->socket_path); + } + return -1; } state->connect_failed = 0; @@ -459,9 +496,16 @@ static int try_connect(reqin_log_config_t *cfg, reqin_log_child_state_t *state, static int ensure_connected(reqin_log_config_t *cfg, reqin_log_child_state_t *state, server_rec *s) { - if (state->socket_fd >= 0 && !state->connect_failed) { + int connected; + + FD_MUTEX_LOCK(state); + connected = (state->socket_fd >= 0 && !state->connect_failed); + FD_MUTEX_UNLOCK(state); + + if (connected) { return 0; } + return try_connect(cfg, state, s); } @@ -469,49 +513,57 @@ static int write_to_socket(const char *data, apr_size_t len, server_rec *s, reqin_log_config_t *cfg, reqin_log_child_state_t *state) { int fd; - int result = -1; + apr_size_t total_written = 0; + apr_time_t error_interval = apr_time_from_sec(cfg->error_report_interval); FD_MUTEX_LOCK(state); + fd = state->socket_fd; if (fd < 0) { FD_MUTEX_UNLOCK(state); return -1; } - apr_size_t total_written = 0; while (total_written < len) { ssize_t n = write(fd, data + total_written, len - total_written); if (n < 0) { int err = errno; - if (err == EAGAIN || err == EWOULDBLOCK) { - FD_MUTEX_UNLOCK(state); - return -1; - } - if (err == EPIPE || err == ECONNRESET) { + apr_time_t now = apr_time_now(); + int should_report = 0; + int conn_lost = (err == EPIPE || err == ECONNRESET || err == ENOTCONN); + + if (conn_lost) { close(fd); state->socket_fd = -1; state->connect_failed = 1; - FD_MUTEX_UNLOCK(state); - - apr_time_t now = apr_time_now(); - if ((now - state->last_error_report) >= apr_time_from_sec(cfg->error_report_interval)) { - ap_log_error(APLOG_MARK, APLOG_ERR, 0, s, - MOD_REQIN_LOG_NAME ": Unix socket write failed, connection lost"); - ap_log_error(APLOG_MARK, APLOG_DEBUG, err, s, - MOD_REQIN_LOG_NAME ": Write error detail: %s", strerror(err)); - state->last_error_report = now; - } - return -1; } + + if (err != EAGAIN && err != EWOULDBLOCK && + (now - state->last_error_report) >= error_interval) { + state->last_error_report = now; + should_report = 1; + } + FD_MUTEX_UNLOCK(state); + + if (should_report) { + if (conn_lost) { + ap_log_error(APLOG_MARK, APLOG_ERR, err, s, + MOD_REQIN_LOG_NAME ": Unix socket write failed: connection lost"); + } else { + ap_log_error(APLOG_MARK, APLOG_ERR, err, s, + MOD_REQIN_LOG_NAME ": Unix socket write failed"); + } + } + return -1; } - total_written += n; + + total_written += (apr_size_t)n; } - result = 0; FD_MUTEX_UNLOCK(state); - return result; + return 0; } /* ============== Request Logging Functions ============== */ @@ -519,11 +571,12 @@ static int write_to_socket(const char *data, apr_size_t len, server_rec *s, static const char *get_header(request_rec *r, const char *name) { const apr_table_t *headers = r->headers_in; - apr_table_entry_t *elts = (apr_table_entry_t *)apr_table_elts(headers)->elts; - int nelts = apr_table_elts(headers)->nelts; + apr_array_header_t *arr = apr_table_elts(headers); + apr_table_entry_t *elts = (apr_table_entry_t *)arr->elts; + int nelts = arr->nelts; for (int i = 0; i < nelts; i++) { - if (strcasecmp(elts[i].key, name) == 0) { + if (elts[i].key != NULL && strcasecmp(elts[i].key, name) == 0) { return elts[i].val; } } @@ -532,15 +585,39 @@ static const char *get_header(request_rec *r, const char *name) static void log_request(request_rec *r, reqin_log_config_t *cfg, reqin_log_child_state_t *state) { - apr_pool_t *pool = r->pool; - server_rec *s = r->server; + apr_pool_t *pool; + server_rec *s; + dynbuf_t buf; char port_buf[16]; + const char *src_ip; + const char *dst_ip; + const char *method; + const char *path; + const char *host; + const char *http_version; + + if (!r || !r->server || !r->pool || !r->connection) { + return; + } + + pool = r->pool; + s = r->server; if (ensure_connected(cfg, state, s) < 0) { return; } - dynbuf_t buf; + src_ip = r->useragent_ip ? r->useragent_ip : + (r->connection->client_ip ? r->connection->client_ip : ""); + dst_ip = r->connection->local_ip ? r->connection->local_ip : ""; + method = r->method ? r->method : "UNKNOWN"; + path = r->parsed_uri.path ? r->parsed_uri.path : "/"; + host = apr_table_get(r->headers_in, "Host"); + if (host == NULL) { + host = ""; + } + http_version = r->protocol ? r->protocol : "UNKNOWN"; + dynbuf_init(&buf, pool, 4096); dynbuf_append(&buf, "{", 1); @@ -550,30 +627,27 @@ static void log_request(request_rec *r, reqin_log_config_t *cfg, reqin_log_child format_iso8601(&buf, r->request_time); dynbuf_append(&buf, "\",", 2); - /* timestamp (nanoseconds since epoch) - * Note: apr_time_now() returns microseconds. Multiplying by 1000 gives nanoseconds. - * LIMITATION: apr_time_t is 64-bit microseconds. Max value ~9.22e18 microseconds. - * In nanoseconds, this overflows around year 2262. However, practical overflow of - * the JSON integer field (uint64) occurs at ~1.84e19 nanoseconds = year 2262. - * Current implementation is safe until ~2262. - */ - apr_time_t now = apr_time_now(); - apr_uint64_t ns = (apr_uint64_t)now * 1000; - char ts_buf[32]; - snprintf(ts_buf, sizeof(ts_buf), "%" APR_UINT64_T_FMT, ns); - dynbuf_append(&buf, "\"timestamp\":", 12); - dynbuf_append(&buf, ts_buf, -1); - dynbuf_append(&buf, ",", 1); + /* timestamp (nanoseconds since epoch) */ + { + apr_time_t now = apr_time_now(); + apr_uint64_t ns = (apr_uint64_t)now * 1000; + char ts_buf[32]; + snprintf(ts_buf, sizeof(ts_buf), "%" APR_UINT64_T_FMT, ns); + dynbuf_append(&buf, "\"timestamp\":", 12); + dynbuf_append(&buf, ts_buf, -1); + dynbuf_append(&buf, ",", 1); + } /* src_ip */ dynbuf_append(&buf, "\"src_ip\":\"", 10); - dynbuf_append(&buf, r->useragent_ip ? r->useragent_ip : r->connection->client_ip, -1); + append_json_string(&buf, src_ip); dynbuf_append(&buf, "\",", 2); /* src_port */ - port_buf[0] = '\0'; if (r->connection->client_addr != NULL) { - snprintf(port_buf, sizeof(port_buf), "%u", r->connection->client_addr->port); + snprintf(port_buf, sizeof(port_buf), "%u", (unsigned int)r->connection->client_addr->port); + } else { + snprintf(port_buf, sizeof(port_buf), "0"); } dynbuf_append(&buf, "\"src_port\":", 11); dynbuf_append(&buf, port_buf, -1); @@ -581,15 +655,14 @@ static void log_request(request_rec *r, reqin_log_config_t *cfg, reqin_log_child /* dst_ip */ dynbuf_append(&buf, "\"dst_ip\":\"", 10); - if (r->connection->local_ip) { - dynbuf_append(&buf, r->connection->local_ip, -1); - } + append_json_string(&buf, dst_ip); dynbuf_append(&buf, "\",", 2); /* dst_port */ - port_buf[0] = '\0'; if (r->connection->local_addr != NULL) { - snprintf(port_buf, sizeof(port_buf), "%u", r->connection->local_addr->port); + snprintf(port_buf, sizeof(port_buf), "%u", (unsigned int)r->connection->local_addr->port); + } else { + snprintf(port_buf, sizeof(port_buf), "0"); } dynbuf_append(&buf, "\"dst_port\":", 11); dynbuf_append(&buf, port_buf, -1); @@ -597,23 +670,22 @@ static void log_request(request_rec *r, reqin_log_config_t *cfg, reqin_log_child /* method */ dynbuf_append(&buf, "\"method\":\"", 10); - append_json_string(&buf, r->method); + append_json_string(&buf, method); dynbuf_append(&buf, "\",", 2); /* path */ dynbuf_append(&buf, "\"path\":\"", 8); - append_json_string(&buf, r->parsed_uri.path ? r->parsed_uri.path : "/"); + append_json_string(&buf, path); dynbuf_append(&buf, "\",", 2); /* host */ - const char *host = apr_table_get(r->headers_in, "Host"); dynbuf_append(&buf, "\"host\":\"", 8); - append_json_string(&buf, host ? host : ""); + append_json_string(&buf, host); dynbuf_append(&buf, "\",", 2); /* http_version */ dynbuf_append(&buf, "\"http_version\":\"", 16); - dynbuf_append(&buf, r->protocol ? r->protocol : "UNKNOWN", -1); + append_json_string(&buf, http_version); dynbuf_append(&buf, "\"", 1); /* Check buffer size before adding headers to prevent memory exhaustion */ @@ -631,36 +703,38 @@ static void log_request(request_rec *r, reqin_log_config_t *cfg, reqin_log_child for (int i = 0; i < cfg->headers->nelts && header_count < max_to_log; i++) { const char *header_name = header_names[i]; - + const char *header_value; + /* Skip sensitive headers to prevent credential leakage */ if (is_sensitive_header(header_name)) { ap_log_error(APLOG_MARK, APLOG_DEBUG, 0, s, MOD_REQIN_LOG_NAME ": Skipping sensitive header: %s", header_name); continue; } - - const char *header_value = get_header(r, header_name); + + header_value = get_header(r, header_name); if (header_value != NULL) { - /* Check if adding this header would exceed size limit */ - apr_size_t header_contrib = 9 + strlen(header_name) + 3 + - strlen(header_value) + 1; + apr_size_t header_contrib = 9 + strlen(header_name) + 3 + strlen(header_value) + 1; + apr_size_t val_len; + char *truncated; + if (buf.len + header_contrib >= MAX_JSON_SIZE) { ap_log_error(APLOG_MARK, APLOG_DEBUG, 0, s, MOD_REQIN_LOG_NAME ": JSON size limit reached, truncating headers"); break; } - + dynbuf_append(&buf, ",\"header_", 9); append_json_string(&buf, header_name); dynbuf_append(&buf, "\":\"", 3); - apr_size_t val_len = strlen(header_value); + val_len = strlen(header_value); if ((int)val_len > cfg->max_header_value_len) { - val_len = cfg->max_header_value_len; + val_len = (apr_size_t)cfg->max_header_value_len; } - char *truncated = apr_pstrmemdup(pool, header_value, val_len); + truncated = apr_pstrmemdup(pool, header_value, val_len); append_json_string(&buf, truncated); dynbuf_append(&buf, "\"", 1); @@ -671,6 +745,25 @@ static void log_request(request_rec *r, reqin_log_config_t *cfg, reqin_log_child dynbuf_append(&buf, "}\n", 2); + if (buf.len > MAX_JSON_SIZE) { + apr_time_t now = apr_time_now(); + apr_time_t error_interval = apr_time_from_sec(cfg->error_report_interval); + int should_report = 0; + + FD_MUTEX_LOCK(state); + if ((now - state->last_error_report) >= error_interval) { + state->last_error_report = now; + should_report = 1; + } + FD_MUTEX_UNLOCK(state); + + if (should_report) { + ap_log_error(APLOG_MARK, APLOG_ERR, 0, s, + MOD_REQIN_LOG_NAME ": JSON log line exceeds maximum size, dropping"); + } + return; + } + write_to_socket(buf.data, buf.len, s, cfg, state); } @@ -680,7 +773,7 @@ static int reqin_log_post_read_request(request_rec *r) { reqin_log_server_conf_t *srv_conf = get_server_conf(r->server); - if (srv_conf == NULL || srv_conf->config == NULL || + if (srv_conf == NULL || srv_conf->config == NULL || !srv_conf->config->enabled || srv_conf->config->socket_path == NULL) { return DECLINED; } @@ -691,20 +784,26 @@ static int reqin_log_post_read_request(request_rec *r) static void reqin_log_child_init(apr_pool_t *p, server_rec *s) { - (void)p; reqin_log_server_conf_t *srv_conf = get_server_conf(s); if (srv_conf == NULL) { return; } - /* Initialize child state for this process */ srv_conf->child_state.socket_fd = -1; srv_conf->child_state.last_connect_attempt = 0; srv_conf->child_state.last_error_report = 0; srv_conf->child_state.connect_failed = 0; - if (srv_conf->config == NULL || !srv_conf->config->enabled || + srv_conf->child_state.fd_mutex = NULL; + if (apr_thread_mutex_create(&srv_conf->child_state.fd_mutex, + APR_THREAD_MUTEX_DEFAULT, p) != APR_SUCCESS) { + srv_conf->child_state.fd_mutex = NULL; + ap_log_error(APLOG_MARK, APLOG_ERR, 0, s, + MOD_REQIN_LOG_NAME ": Failed to create mutex, continuing in degraded mode"); + } + + if (srv_conf->config == NULL || !srv_conf->config->enabled || srv_conf->config->socket_path == NULL) { return; } @@ -712,9 +811,47 @@ static void reqin_log_child_init(apr_pool_t *p, server_rec *s) try_connect(srv_conf->config, &srv_conf->child_state, s); } +static int reqin_log_post_config(apr_pool_t *pconf, apr_pool_t *plog, apr_pool_t *ptemp, server_rec *s) +{ + server_rec *cur; + + (void)pconf; + (void)plog; + (void)ptemp; + + for (cur = s; cur != NULL; cur = cur->next) { + reqin_log_server_conf_t *srv_conf = get_server_conf(cur); + reqin_log_config_t *cfg; + + if (srv_conf == NULL || srv_conf->config == NULL) { + continue; + } + + cfg = srv_conf->config; + if (!cfg->enabled) { + continue; + } + + if (cfg->socket_path == NULL || cfg->socket_path[0] == '\0') { + ap_log_error(APLOG_MARK, APLOG_EMERG, 0, cur, + MOD_REQIN_LOG_NAME ": JsonSockLogEnabled is On but JsonSockLogSocket is missing"); + return HTTP_INTERNAL_SERVER_ERROR; + } + + if (strlen(cfg->socket_path) >= MAX_SOCKET_PATH_LEN) { + ap_log_error(APLOG_MARK, APLOG_EMERG, 0, cur, + MOD_REQIN_LOG_NAME ": JsonSockLogSocket path too long (max %d)", (int)MAX_SOCKET_PATH_LEN - 1); + return HTTP_INTERNAL_SERVER_ERROR; + } + } + + return OK; +} + static void reqin_log_register_hooks(apr_pool_t *p) { (void)p; + ap_hook_post_config(reqin_log_post_config, NULL, NULL, APR_HOOK_MIDDLE); ap_hook_post_read_request(reqin_log_post_read_request, NULL, NULL, APR_HOOK_MIDDLE); ap_hook_child_init(reqin_log_child_init, NULL, NULL, APR_HOOK_MIDDLE); } diff --git a/src/mod_reqin_log.h b/src/mod_reqin_log.h index 0205cd4..366ba7e 100644 --- a/src/mod_reqin_log.h +++ b/src/mod_reqin_log.h @@ -9,6 +9,7 @@ #include "httpd.h" #include "http_config.h" +#include "apr_tables.h" /* Module name */ #define MOD_REQIN_LOG_NAME "mod_reqin_log" diff --git a/tests/integration/test_integration.py b/tests/integration/test_integration.py index d1c2554..7d00ba0 100644 --- a/tests/integration/test_integration.py +++ b/tests/integration/test_integration.py @@ -3,24 +3,21 @@ test_integration.py - Integration tests for mod_reqin_log This script runs integration tests for the mod_reqin_log Apache module. -It tests the 4 required scenarios from architecture.yml: +It tests the required scenarios: 1. basic_logging - Verify JSON logs with expected fields 2. header_limits - Verify header count and value length limits -3. socket_unavailable_on_start - Verify reconnect behavior when socket is unavailable -4. runtime_socket_loss - Verify behavior when socket disappears during traffic +3. sensitive_headers_blacklist - Verify sensitive headers are never logged +4. socket_unavailable_on_start - Verify reconnect behavior when socket is unavailable +5. runtime_socket_loss - Verify behavior when socket disappears during traffic """ import socket import os import sys import json -import signal import time -import subprocess import threading import argparse -from datetime import datetime -from http.server import HTTPServer, BaseHTTPRequestHandler # Default paths # Use /var/run for production (more secure than /tmp) @@ -32,12 +29,6 @@ tests_run = 0 tests_passed = 0 tests_failed = 0 -# Global flags -shutdown_requested = False -log_entries = [] -socket_server = None -socket_thread = None - def log_info(msg): print(f"[INFO] {msg}", file=sys.stderr) @@ -63,7 +54,7 @@ def log_test_start(name): class SocketServer: """Unix socket server that collects JSON log entries.""" - + def __init__(self, socket_path): self.socket_path = socket_path self.server = None @@ -72,31 +63,28 @@ class SocketServer: self.lock = threading.Lock() self.connection = None self.buffer = b"" - + def start(self): """Start the socket server.""" - # Remove existing socket if os.path.exists(self.socket_path): os.remove(self.socket_path) - - # Create socket + self.server = socket.socket(socket.AF_UNIX, socket.SOCK_STREAM) self.server.setsockopt(socket.SOL_SOCKET, socket.SO_REUSEADDR, 1) self.server.bind(self.socket_path) self.server.listen(5) self.server.settimeout(1.0) - os.chmod(self.socket_path, 0o666) + os.chmod(self.socket_path, 0o660) self.running = True - - # Start accept thread + self.thread = threading.Thread(target=self._accept_loop, daemon=True) self.thread.start() - + def _accept_loop(self): """Accept connections and read data.""" while self.running: try: - conn, addr = self.server.accept() + conn, _ = self.server.accept() conn.settimeout(0.5) self.connection = conn while self.running: @@ -105,8 +93,7 @@ class SocketServer: if not chunk: break self.buffer += chunk - - # Process complete lines + while b'\n' in self.buffer: newline_pos = self.buffer.index(b'\n') line = self.buffer[:newline_pos].decode('utf-8', errors='replace') @@ -115,7 +102,7 @@ class SocketServer: self._process_entry(line) except socket.timeout: continue - except Exception as e: + except Exception: break conn.close() self.connection = None @@ -124,7 +111,7 @@ class SocketServer: except Exception as e: if self.running: log_info(f"Socket server error: {e}") - + def _process_entry(self, line): """Process a log entry.""" try: @@ -133,36 +120,36 @@ class SocketServer: self.entries.append(entry) except json.JSONDecodeError: log_info(f"Invalid JSON entry: {line[:100]}") - + def stop(self): """Stop the socket server.""" self.running = False if self.connection: try: self.connection.close() - except: + except Exception: pass if self.server: try: self.server.close() - except: + except Exception: pass if os.path.exists(self.socket_path): try: os.remove(self.socket_path) - except: + except Exception: pass - + def get_entries(self): """Get collected log entries.""" with self.lock: return list(self.entries) - + def clear_entries(self): """Clear collected entries.""" with self.lock: self.entries.clear() - + def wait_for_entries(self, count, timeout=5.0): """Wait for at least 'count' entries to arrive.""" start = time.time() @@ -175,14 +162,14 @@ class SocketServer: def make_request(url, headers=None, method='GET'): - """Make an HTTP request using curl.""" + """Make an HTTP request using urllib.""" import urllib.request - + req = urllib.request.Request(url, method=method) if headers: for key, value in headers.items(): req.add_header(key, value) - + try: with urllib.request.urlopen(req, timeout=5) as response: return response.status, response.read().decode('utf-8', errors='replace') @@ -194,52 +181,42 @@ def make_request(url, headers=None, method='GET'): # Test 1: Basic Logging # ============================================================================ def test_basic_logging(socket_server, apache_url): - """ - Test: basic_logging - Description: With JsonSockLogEnabled On and valid socket, verify that each request - produces a valid JSON line with expected fields. - """ log_test_start("basic_logging") - + socket_server.clear_entries() - - # Make a simple request + status, _ = make_request(f"{apache_url}/") - - # Wait for log entry + if status is None: + log_fail("basic_logging - HTTP request failed") + return False + if not socket_server.wait_for_entries(1, timeout=3.0): log_fail("basic_logging - No log entries received") return False - + entries = socket_server.get_entries() entry = entries[-1] - - # Verify required fields - required_fields = ['time', 'timestamp', 'src_ip', 'src_port', 'dst_ip', + + required_fields = ['time', 'timestamp', 'src_ip', 'src_port', 'dst_ip', 'dst_port', 'method', 'path', 'host', 'http_version'] - - missing_fields = [] - for field in required_fields: - if field not in entry: - missing_fields.append(field) - + + missing_fields = [field for field in required_fields if field not in entry] if missing_fields: log_fail(f"basic_logging - Missing fields: {missing_fields}") return False - - # Verify field types and values + if entry.get('method') != 'GET': log_fail(f"basic_logging - Expected method 'GET', got '{entry.get('method')}'") return False - + if not isinstance(entry.get('timestamp'), int): log_fail(f"basic_logging - timestamp should be integer, got {type(entry.get('timestamp'))}") return False - + if not entry.get('time', '').startswith('20'): log_fail(f"basic_logging - Invalid time format: {entry.get('time')}") return False - + log_pass("basic_logging - All required fields present and valid") return True @@ -248,188 +225,189 @@ def test_basic_logging(socket_server, apache_url): # Test 2: Header Limits # ============================================================================ def test_header_limits(socket_server, apache_url): - """ - Test: header_limits - Description: Configure more headers than JsonSockLogMaxHeaders and verify only - the first N are logged and values are truncated. - """ log_test_start("header_limits") - + socket_server.clear_entries() - - # Make request with multiple headers including a long one + headers = { 'X-Request-Id': 'test-123', 'X-Trace-Id': 'trace-456', 'User-Agent': 'TestAgent/1.0', - 'X-Long-Header': 'A' * 500, # Very long value + 'X-Long-Header': 'A' * 500, } - + status, _ = make_request(f"{apache_url}/test-headers", headers=headers) - - # Wait for log entry + if status is None: + log_fail("header_limits - HTTP request failed") + return False + if not socket_server.wait_for_entries(1, timeout=3.0): log_fail("header_limits - No log entries received") return False - + entries = socket_server.get_entries() entry = entries[-1] - - # Check that header fields are present (implementation logs configured headers) header_fields = [k for k in entry.keys() if k.startswith('header_')] - - # Verify header value truncation (max 256 chars by default) + for key, value in entry.items(): - if key.startswith('header_') and isinstance(value, str): - if len(value) > 256: - log_fail(f"header_limits - Header value not truncated: {key} has {len(value)} chars") - return False - + if key.startswith('header_') and isinstance(value, str) and len(value) > 256: + log_fail(f"header_limits - Header value not truncated: {key} has {len(value)} chars") + return False + log_pass(f"header_limits - Headers logged correctly ({len(header_fields)} header fields)") return True # ============================================================================ -# Test 3: Socket Unavailable on Start +# Test 3: Sensitive Headers Blacklist +# ============================================================================ +def test_sensitive_headers_blacklist(socket_server, apache_url): + log_test_start("sensitive_headers_blacklist") + + socket_server.clear_entries() + + headers = { + 'X-Request-Id': 'blacklist-test', + 'Authorization': 'Bearer secret-token', + 'Cookie': 'sessionid=super-secret', + 'X-Api-Key': 'api-key-secret', + } + + status, _ = make_request(f"{apache_url}/blacklist-check", headers=headers) + if status is None: + log_fail("sensitive_headers_blacklist - HTTP request failed") + return False + + if not socket_server.wait_for_entries(1, timeout=3.0): + log_fail("sensitive_headers_blacklist - No log entries received") + return False + + entry = socket_server.get_entries()[-1] + + forbidden_keys = [ + 'header_Authorization', + 'header_Cookie', + 'header_X-Api-Key', + ] + + for key in forbidden_keys: + if key in entry: + log_fail(f"sensitive_headers_blacklist - Sensitive header leaked: {key}") + return False + + log_pass("sensitive_headers_blacklist - Sensitive headers are not logged") + return True + + +# ============================================================================ +# Test 4: Socket Unavailable on Start # ============================================================================ def test_socket_unavailable_on_start(socket_server, apache_url): - """ - Test: socket_unavailable_on_start - Description: Start with socket not yet created; verify periodic reconnect attempts - and throttled error logging. - """ log_test_start("socket_unavailable_on_start") - - # Stop the socket server to simulate unavailable socket + socket_server.stop() time.sleep(0.5) - - # Make requests while socket is unavailable + for i in range(3): make_request(f"{apache_url}/unavailable-{i}") time.sleep(0.2) - - # Requests should still succeed (logging failures don't affect client) + status, _ = make_request(f"{apache_url}/final-check") if status != 200: log_fail("socket_unavailable_on_start - Request failed when socket unavailable") - # Restart socket server for subsequent tests socket_server.start() return False - - # Restart socket server + socket_server.start() - time.sleep(0.5) - - # Verify module can reconnect + time.sleep(10.5) + socket_server.clear_entries() - status, _ = make_request(f"{apache_url}/after-reconnect") - - if socket_server.wait_for_entries(1, timeout=3.0): + make_request(f"{apache_url}/after-reconnect") + + if socket_server.wait_for_entries(1, timeout=12.0): log_pass("socket_unavailable_on_start - Module reconnected after socket became available") return True - else: - log_fail("socket_unavailable_on_start - Module did not reconnect") - return False + + log_fail("socket_unavailable_on_start - Module did not reconnect") + return False # ============================================================================ -# Test 4: Runtime Socket Loss +# Test 5: Runtime Socket Loss # ============================================================================ def test_runtime_socket_loss(socket_server, apache_url): - """ - Test: runtime_socket_loss - Description: Drop the Unix socket while traffic is ongoing; verify that log lines - are dropped, worker threads are not blocked, and reconnect attempts - resume once the socket reappears. - """ log_test_start("runtime_socket_loss") - + socket_server.clear_entries() - - # Make some initial requests + for i in range(3): make_request(f"{apache_url}/before-loss-{i}") - + if not socket_server.wait_for_entries(3, timeout=3.0): log_fail("runtime_socket_loss - Initial requests not logged") return False - + initial_count = len(socket_server.get_entries()) - - # Simulate socket loss by stopping server + socket_server.stop() time.sleep(0.3) - - # Make requests while socket is gone - start_time = time.time() + for i in range(3): req_start = time.time() - status, _ = make_request(f"{apache_url}/during-loss-{i}") + make_request(f"{apache_url}/during-loss-{i}") req_duration = time.time() - req_start - - # Requests should NOT block (should complete quickly) + if req_duration > 2.0: log_fail(f"runtime_socket_loss - Request blocked for {req_duration:.2f}s") socket_server.start() return False - - # Give time for any pending logs + time.sleep(0.5) - - # Verify no new entries were logged (socket was down) + current_count = len(socket_server.get_entries()) if current_count != initial_count: log_info(f"runtime_socket_loss - Some entries logged during socket loss (expected: {initial_count}, got: {current_count})") - - # Restart socket server + socket_server.start() - time.sleep(0.5) - - # Verify module can reconnect and log again + time.sleep(10.5) + socket_server.clear_entries() - status, _ = make_request(f"{apache_url}/after-loss") - - if socket_server.wait_for_entries(1, timeout=3.0): + make_request(f"{apache_url}/after-loss") + + if socket_server.wait_for_entries(1, timeout=12.0): log_pass("runtime_socket_loss - Module recovered after socket restored") return True - else: - log_fail("runtime_socket_loss - Module did not recover after socket restored") - return False + + log_fail("runtime_socket_loss - Module did not recover after socket restored") + return False # ============================================================================ # Main Test Runner # ============================================================================ def run_all_tests(apache_url, socket_path): - """Run all integration tests.""" global tests_run, tests_passed, tests_failed - + print("=" * 60, file=sys.stderr) print("mod_reqin_log Integration Tests", file=sys.stderr) print("=" * 60, file=sys.stderr) - - # Create socket server + server = SocketServer(socket_path) server.start() log_info(f"Socket server started on {socket_path}") - - # Give Apache time to connect + time.sleep(1.0) - + try: - # Run all tests test_basic_logging(server, apache_url) test_header_limits(server, apache_url) + test_sensitive_headers_blacklist(server, apache_url) test_socket_unavailable_on_start(server, apache_url) test_runtime_socket_loss(server, apache_url) - finally: - # Cleanup server.stop() log_info("Socket server stopped") - - # Print summary + print("\n" + "=" * 60, file=sys.stderr) print("Test Summary", file=sys.stderr) print("=" * 60, file=sys.stderr) @@ -437,7 +415,7 @@ def run_all_tests(apache_url, socket_path): print(f"Tests passed: {tests_passed}", file=sys.stderr) print(f"Tests failed: {tests_failed}", file=sys.stderr) print("=" * 60, file=sys.stderr) - + return tests_failed == 0 @@ -448,7 +426,7 @@ def main(): parser.add_argument('--url', default=DEFAULT_APACHE_URL, help=f'Apache URL (default: {DEFAULT_APACHE_URL})') args = parser.parse_args() - + success = run_all_tests(args.url, args.socket) sys.exit(0 if success else 1) diff --git a/tests/unit/test_config_parsing.c b/tests/unit/test_config_parsing.c index ef1a503..6d29760 100644 --- a/tests/unit/test_config_parsing.c +++ b/tests/unit/test_config_parsing.c @@ -9,12 +9,15 @@ #include #include #include +#include +#include /* Default configuration values */ #define DEFAULT_MAX_HEADERS 10 #define DEFAULT_MAX_HEADER_VALUE_LEN 256 #define DEFAULT_RECONNECT_INTERVAL 10 #define DEFAULT_ERROR_REPORT_INTERVAL 10 +#define MAX_SOCKET_PATH_LEN 108 /* Mock configuration structure */ typedef struct { @@ -40,34 +43,59 @@ static const char *parse_socket_path(const char *value) if (value == NULL || strlen(value) == 0) { return NULL; } + if (strlen(value) >= MAX_SOCKET_PATH_LEN) { + return NULL; + } return value; } +static int parse_int_strict(const char *value, int *result) +{ + char *endptr = NULL; + long val; + + if (value == NULL || *value == '\0' || result == NULL) { + return -1; + } + + errno = 0; + val = strtol(value, &endptr, 10); + if (errno != 0 || endptr == value || *endptr != '\0' || val < INT_MIN || val > INT_MAX) { + return -1; + } + + *result = (int)val; + return 0; +} + static int parse_max_headers(const char *value, int *result) { - char *endptr; - long val = strtol(value, &endptr, 10); - if (*endptr != '\0' || val < 0) { + if (parse_int_strict(value, result) != 0 || *result < 0) { return -1; } - *result = (int)val; return 0; } static int parse_interval(const char *value, int *result) { - char *endptr; - long val = strtol(value, &endptr, 10); - if (*endptr != '\0' || val < 0) { + if (parse_int_strict(value, result) != 0 || *result < 0) { + return -1; + } + return 0; +} + +static int parse_max_header_value_len(const char *value, int *result) +{ + if (parse_int_strict(value, result) != 0 || *result < 1) { return -1; } - *result = (int)val; return 0; } /* Test: Parse enabled On */ static void test_parse_enabled_on(void **state) { + (void)state; assert_int_equal(parse_enabled("On"), 1); assert_int_equal(parse_enabled("on"), 1); assert_int_equal(parse_enabled("ON"), 1); @@ -77,6 +105,7 @@ static void test_parse_enabled_on(void **state) /* Test: Parse enabled Off */ static void test_parse_enabled_off(void **state) { + (void)state; assert_int_equal(parse_enabled("Off"), 0); assert_int_equal(parse_enabled("off"), 0); assert_int_equal(parse_enabled("OFF"), 0); @@ -86,6 +115,7 @@ static void test_parse_enabled_off(void **state) /* Test: Parse socket path valid */ static void test_parse_socket_path_valid(void **state) { + (void)state; const char *result = parse_socket_path("/var/run/mod_reqin_log.sock"); assert_string_equal(result, "/var/run/mod_reqin_log.sock"); } @@ -93,6 +123,7 @@ static void test_parse_socket_path_valid(void **state) /* Test: Parse socket path empty */ static void test_parse_socket_path_empty(void **state) { + (void)state; const char *result = parse_socket_path(""); assert_null(result); } @@ -100,20 +131,45 @@ static void test_parse_socket_path_empty(void **state) /* Test: Parse socket path NULL */ static void test_parse_socket_path_null(void **state) { + (void)state; const char *result = parse_socket_path(NULL); assert_null(result); } +/* Test: Parse socket path max length valid */ +static void test_parse_socket_path_max_len_valid(void **state) +{ + (void)state; + char path[MAX_SOCKET_PATH_LEN]; + memset(path, 'a', MAX_SOCKET_PATH_LEN - 1); + path[MAX_SOCKET_PATH_LEN - 1] = '\0'; + + assert_non_null(parse_socket_path(path)); +} + +/* Test: Parse socket path max length invalid */ +static void test_parse_socket_path_max_len_invalid(void **state) +{ + (void)state; + char path[MAX_SOCKET_PATH_LEN + 1]; + memset(path, 'b', MAX_SOCKET_PATH_LEN); + path[MAX_SOCKET_PATH_LEN] = '\0'; + + assert_null(parse_socket_path(path)); +} + /* Test: Parse max headers valid */ static void test_parse_max_headers_valid(void **state) { int result; + (void)state; + assert_int_equal(parse_max_headers("10", &result), 0); assert_int_equal(result, 10); - + assert_int_equal(parse_max_headers("0", &result), 0); assert_int_equal(result, 0); - + assert_int_equal(parse_max_headers("100", &result), 0); assert_int_equal(result, 100); } @@ -122,6 +178,8 @@ static void test_parse_max_headers_valid(void **state) static void test_parse_max_headers_invalid(void **state) { int result; + (void)state; + assert_int_equal(parse_max_headers("-1", &result), -1); assert_int_equal(parse_max_headers("abc", &result), -1); assert_int_equal(parse_max_headers("10abc", &result), -1); @@ -131,12 +189,14 @@ static void test_parse_max_headers_invalid(void **state) static void test_parse_reconnect_interval_valid(void **state) { int result; + (void)state; + assert_int_equal(parse_interval("10", &result), 0); assert_int_equal(result, 10); - + assert_int_equal(parse_interval("0", &result), 0); assert_int_equal(result, 0); - + assert_int_equal(parse_interval("60", &result), 0); assert_int_equal(result, 60); } @@ -145,13 +205,52 @@ static void test_parse_reconnect_interval_valid(void **state) static void test_parse_reconnect_interval_invalid(void **state) { int result; + (void)state; + assert_int_equal(parse_interval("-5", &result), -1); assert_int_equal(parse_interval("abc", &result), -1); + assert_int_equal(parse_interval("10abc", &result), -1); +} + +/* Test: Parse max header value length valid */ +static void test_parse_max_header_value_len_valid(void **state) +{ + int result; + (void)state; + + assert_int_equal(parse_max_header_value_len("1", &result), 0); + assert_int_equal(result, 1); + + assert_int_equal(parse_max_header_value_len("256", &result), 0); + assert_int_equal(result, 256); +} + +/* Test: Parse max header value length invalid */ +static void test_parse_max_header_value_len_invalid(void **state) +{ + int result; + (void)state; + + assert_int_equal(parse_max_header_value_len("0", &result), -1); + assert_int_equal(parse_max_header_value_len("-1", &result), -1); + assert_int_equal(parse_max_header_value_len("10abc", &result), -1); +} + +/* Test: strict numeric parsing invalid suffix for all int directives */ +static void test_strict_numeric_invalid_suffix_all(void **state) +{ + int result; + (void)state; + + assert_int_equal(parse_max_headers("10abc", &result), -1); + assert_int_equal(parse_interval("10abc", &result), -1); + assert_int_equal(parse_max_header_value_len("10abc", &result), -1); } /* Test: Default configuration values */ static void test_default_config_values(void **state) { + (void)state; assert_int_equal(DEFAULT_MAX_HEADERS, 10); assert_int_equal(DEFAULT_MAX_HEADER_VALUE_LEN, 256); assert_int_equal(DEFAULT_RECONNECT_INTERVAL, 10); @@ -161,34 +260,47 @@ static void test_default_config_values(void **state) /* Test: Configuration validation - enabled requires socket */ static void test_config_validation_enabled_requires_socket(void **state) { - /* Valid: enabled with socket */ int enabled = 1; const char *socket = "/var/run/socket"; + (void)state; + assert_true(enabled == 0 || socket != NULL); - - /* Invalid: enabled without socket */ + socket = NULL; assert_false(enabled == 0 || socket != NULL); } +/* Test: Configuration validation - enabled with empty socket is invalid */ +static void test_config_validation_enabled_with_empty_socket(void **state) +{ + int enabled = 1; + const char *socket = parse_socket_path(""); + (void)state; + + assert_false(enabled == 0 || socket != NULL); +} + /* Test: Header value length validation */ static void test_header_value_len_validation(void **state) { int result; - assert_int_equal(parse_interval("1", &result), 0); + (void)state; + + assert_int_equal(parse_max_header_value_len("1", &result), 0); assert_true(result >= 1); - - assert_int_equal(parse_interval("0", &result), 0); - assert_false(result >= 1); + + assert_int_equal(parse_max_header_value_len("0", &result), -1); } /* Test: Large but valid values */ static void test_large_valid_values(void **state) { int result; + (void)state; + assert_int_equal(parse_max_headers("1000000", &result), 0); assert_int_equal(result, 1000000); - + assert_int_equal(parse_interval("86400", &result), 0); assert_int_equal(result, 86400); } @@ -201,15 +313,21 @@ int main(void) cmocka_unit_test(test_parse_socket_path_valid), cmocka_unit_test(test_parse_socket_path_empty), cmocka_unit_test(test_parse_socket_path_null), + cmocka_unit_test(test_parse_socket_path_max_len_valid), + cmocka_unit_test(test_parse_socket_path_max_len_invalid), cmocka_unit_test(test_parse_max_headers_valid), cmocka_unit_test(test_parse_max_headers_invalid), cmocka_unit_test(test_parse_reconnect_interval_valid), cmocka_unit_test(test_parse_reconnect_interval_invalid), + cmocka_unit_test(test_parse_max_header_value_len_valid), + cmocka_unit_test(test_parse_max_header_value_len_invalid), + cmocka_unit_test(test_strict_numeric_invalid_suffix_all), cmocka_unit_test(test_default_config_values), cmocka_unit_test(test_config_validation_enabled_requires_socket), + cmocka_unit_test(test_config_validation_enabled_with_empty_socket), cmocka_unit_test(test_header_value_len_validation), cmocka_unit_test(test_large_valid_values), }; - + return cmocka_run_group_tests(tests, NULL, NULL); } diff --git a/tests/unit/test_json_serialization.c b/tests/unit/test_json_serialization.c index 5cefebe..864ecd1 100644 --- a/tests/unit/test_json_serialization.c +++ b/tests/unit/test_json_serialization.c @@ -8,34 +8,88 @@ #include #include #include +#include #include #include #include -/* Mock JSON string escaping function for testing */ -static void append_json_string(apr_pool_t *pool, apr_strbuf_t *buf, const char *str) +typedef struct { + char *data; + size_t len; + size_t cap; + apr_pool_t *pool; +} testbuf_t; + +static void testbuf_init(testbuf_t *buf, apr_pool_t *pool, size_t initial_capacity) +{ + buf->pool = pool; + buf->cap = initial_capacity; + buf->len = 0; + buf->data = apr_palloc(pool, initial_capacity); + buf->data[0] = '\0'; +} + +static void testbuf_append(testbuf_t *buf, const char *str, size_t len) { if (str == NULL) { return; } - + + if (len == (size_t)-1) { + len = strlen(str); + } + + if (buf->len + len + 1 > buf->cap) { + size_t new_cap = (buf->len + len + 1) * 2; + char *new_data = apr_palloc(buf->pool, new_cap); + memcpy(new_data, buf->data, buf->len + 1); + buf->data = new_data; + buf->cap = new_cap; + } + + memcpy(buf->data + buf->len, str, len); + buf->len += len; + buf->data[buf->len] = '\0'; +} + +static void testbuf_append_char(testbuf_t *buf, char c) +{ + if (buf->len + 2 > buf->cap) { + size_t new_cap = (buf->cap * 2); + char *new_data = apr_palloc(buf->pool, new_cap); + memcpy(new_data, buf->data, buf->len + 1); + buf->data = new_data; + buf->cap = new_cap; + } + + buf->data[buf->len++] = c; + buf->data[buf->len] = '\0'; +} + +/* Mock JSON string escaping function for testing */ +static void append_json_string(testbuf_t *buf, const char *str) +{ + if (str == NULL) { + return; + } + for (const char *p = str; *p; p++) { char c = *p; switch (c) { - case '"': apr_strbuf_append(buf, "\\\"", 2); break; - case '\\': apr_strbuf_append(buf, "\\\\", 2); break; - case '\b': apr_strbuf_append(buf, "\\b", 2); break; - case '\f': apr_strbuf_append(buf, "\\f", 2); break; - case '\n': apr_strbuf_append(buf, "\\n", 2); break; - case '\r': apr_strbuf_append(buf, "\\r", 2); break; - case '\t': apr_strbuf_append(buf, "\\t", 2); break; + case '"': testbuf_append(buf, "\\\"", 2); break; + case '\\': testbuf_append(buf, "\\\\", 2); break; + case '\b': testbuf_append(buf, "\\b", 2); break; + case '\f': testbuf_append(buf, "\\f", 2); break; + case '\n': testbuf_append(buf, "\\n", 2); break; + case '\r': testbuf_append(buf, "\\r", 2); break; + case '\t': testbuf_append(buf, "\\t", 2); break; default: if ((unsigned char)c < 0x20) { char unicode[8]; apr_snprintf(unicode, sizeof(unicode), "\\u%04x", (unsigned char)c); - apr_strbuf_append(buf, unicode, -1); + testbuf_append(buf, unicode, (size_t)-1); } else { - apr_strbuf_append_char(buf, c); + testbuf_append_char(buf, c); } break; } @@ -46,16 +100,16 @@ static void append_json_string(apr_pool_t *pool, apr_strbuf_t *buf, const char * static void test_json_escape_empty_string(void **state) { apr_pool_t *pool; + testbuf_t buf; + (void)state; + apr_pool_create(&pool, NULL); - - apr_strbuf_t buf; - char *initial = apr_palloc(pool, 256); - apr_strbuf_init(pool, &buf, initial, 256); - - append_json_string(pool, &buf, ""); - - assert_string_equal(buf.buf, ""); - + testbuf_init(&buf, pool, 256); + + append_json_string(&buf, ""); + + assert_string_equal(buf.data, ""); + apr_pool_destroy(pool); } @@ -63,16 +117,16 @@ static void test_json_escape_empty_string(void **state) static void test_json_escape_simple_string(void **state) { apr_pool_t *pool; + testbuf_t buf; + (void)state; + apr_pool_create(&pool, NULL); - - apr_strbuf_t buf; - char *initial = apr_palloc(pool, 256); - apr_strbuf_init(pool, &buf, initial, 256); - - append_json_string(pool, &buf, "hello world"); - - assert_string_equal(buf.buf, "hello world"); - + testbuf_init(&buf, pool, 256); + + append_json_string(&buf, "hello world"); + + assert_string_equal(buf.data, "hello world"); + apr_pool_destroy(pool); } @@ -80,16 +134,16 @@ static void test_json_escape_simple_string(void **state) static void test_json_escape_quotes(void **state) { apr_pool_t *pool; + testbuf_t buf; + (void)state; + apr_pool_create(&pool, NULL); - - apr_strbuf_t buf; - char *initial = apr_palloc(pool, 256); - apr_strbuf_init(pool, &buf, initial, 256); - - append_json_string(pool, &buf, "hello \"world\""); - - assert_string_equal(buf.buf, "hello \\\"world\\\""); - + testbuf_init(&buf, pool, 256); + + append_json_string(&buf, "hello \"world\""); + + assert_string_equal(buf.data, "hello \\\"world\\\""); + apr_pool_destroy(pool); } @@ -97,16 +151,16 @@ static void test_json_escape_quotes(void **state) static void test_json_escape_backslashes(void **state) { apr_pool_t *pool; + testbuf_t buf; + (void)state; + apr_pool_create(&pool, NULL); - - apr_strbuf_t buf; - char *initial = apr_palloc(pool, 256); - apr_strbuf_init(pool, &buf, initial, 256); - - append_json_string(pool, &buf, "path\\to\\file"); - - assert_string_equal(buf.buf, "path\\\\to\\\\file"); - + testbuf_init(&buf, pool, 256); + + append_json_string(&buf, "path\\to\\file"); + + assert_string_equal(buf.data, "path\\\\to\\\\file"); + apr_pool_destroy(pool); } @@ -114,16 +168,16 @@ static void test_json_escape_backslashes(void **state) static void test_json_escape_newlines_tabs(void **state) { apr_pool_t *pool; + testbuf_t buf; + (void)state; + apr_pool_create(&pool, NULL); - - apr_strbuf_t buf; - char *initial = apr_palloc(pool, 256); - apr_strbuf_init(pool, &buf, initial, 256); - - append_json_string(pool, &buf, "line1\nline2\ttab"); - - assert_string_equal(buf.buf, "line1\\nline2\\ttab"); - + testbuf_init(&buf, pool, 256); + + append_json_string(&buf, "line1\nline2\ttab"); + + assert_string_equal(buf.data, "line1\\nline2\\ttab"); + apr_pool_destroy(pool); } @@ -131,18 +185,18 @@ static void test_json_escape_newlines_tabs(void **state) static void test_json_escape_control_chars(void **state) { apr_pool_t *pool; + testbuf_t buf; + (void)state; + apr_pool_create(&pool, NULL); - - apr_strbuf_t buf; - char *initial = apr_palloc(pool, 256); - apr_strbuf_init(pool, &buf, initial, 256); - + testbuf_init(&buf, pool, 256); + /* Test with bell character (0x07) */ - append_json_string(pool, &buf, "test\bell"); - + append_json_string(&buf, "test\bell"); + /* Should contain unicode escape */ - assert_true(strstr(buf.buf, "\\u0007") != NULL); - + assert_true(strstr(buf.data, "\\u0007") != NULL); + apr_pool_destroy(pool); } @@ -150,16 +204,16 @@ static void test_json_escape_control_chars(void **state) static void test_json_escape_null_string(void **state) { apr_pool_t *pool; + testbuf_t buf; + (void)state; + apr_pool_create(&pool, NULL); - - apr_strbuf_t buf; - char *initial = apr_palloc(pool, 256); - apr_strbuf_init(pool, &buf, initial, 256); - - append_json_string(pool, &buf, NULL); - - assert_string_equal(buf.buf, ""); - + testbuf_init(&buf, pool, 256); + + append_json_string(&buf, NULL); + + assert_string_equal(buf.data, ""); + apr_pool_destroy(pool); } @@ -167,17 +221,17 @@ static void test_json_escape_null_string(void **state) static void test_json_escape_user_agent(void **state) { apr_pool_t *pool; - apr_pool_create(&pool, NULL); - - apr_strbuf_t buf; - char *initial = apr_palloc(pool, 512); - apr_strbuf_init(pool, &buf, initial, 512); - + testbuf_t buf; const char *ua = "Mozilla/5.0 (Windows NT 10.0; Win64; x64) \"Test\""; - append_json_string(pool, &buf, ua); - - assert_true(strstr(buf.buf, "\\\"Test\\\"") != NULL); - + (void)state; + + apr_pool_create(&pool, NULL); + testbuf_init(&buf, pool, 512); + + append_json_string(&buf, ua); + + assert_true(strstr(buf.data, "\\\"Test\\\"") != NULL); + apr_pool_destroy(pool); } @@ -193,6 +247,6 @@ int main(void) cmocka_unit_test(test_json_escape_null_string), cmocka_unit_test(test_json_escape_user_agent), }; - + return cmocka_run_group_tests(tests, NULL, NULL); }