- REFACTOR: All JSON fields now follow same pattern (field ends with comma) - FIX: Duplicate comma between query and host fields - FIX: Buffer corruption in dynbuf_append (copy null terminator) - CLEANUP: Remove unnecessary comments, simplify code structure Co-authored-by: Qwen-Coder <qwen-coder@alibabacloud.com>
1007 lines
32 KiB
C
1007 lines
32 KiB
C
/*
|
|
* mod_reqin_log.c - Apache HTTPD module for logging HTTP requests as JSON to Unix socket
|
|
*
|
|
* Copyright (c) 2026. All rights reserved.
|
|
*/
|
|
|
|
#include "httpd.h"
|
|
#include "http_config.h"
|
|
#include "http_core.h"
|
|
#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"
|
|
#include "ap_config.h"
|
|
#include "ap_mpm.h"
|
|
|
|
#include <sys/socket.h>
|
|
#include <sys/un.h>
|
|
#include <netinet/in.h>
|
|
#include <arpa/inet.h>
|
|
#include <unistd.h>
|
|
#include <errno.h>
|
|
#include <fcntl.h>
|
|
#include <time.h>
|
|
#include <string.h>
|
|
#include <stdlib.h>
|
|
#include <limits.h>
|
|
|
|
#ifndef MSG_NOSIGNAL
|
|
#define MSG_NOSIGNAL 0
|
|
#endif
|
|
|
|
/* 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)
|
|
|
|
/* Helper macro for throttled error logging - prevents error_log flooding */
|
|
#define LOG_THROTTLED(state, cfg, s, level, err, msg, ...) do { \
|
|
apr_time_t lt_now = apr_time_now(); \
|
|
int lt_should_report = 0; \
|
|
FD_MUTEX_LOCK(state); \
|
|
if ((lt_now - state->last_error_report) >= apr_time_from_sec(cfg->error_report_interval)) { \
|
|
state->last_error_report = lt_now; \
|
|
lt_should_report = 1; \
|
|
} \
|
|
FD_MUTEX_UNLOCK(state); \
|
|
if (lt_should_report) { \
|
|
ap_log_error(APLOG_MARK, level, err, s, MOD_REQIN_LOG_NAME ": " msg, ##__VA_ARGS__); \
|
|
} \
|
|
} while(0)
|
|
|
|
/* Helper macro to check if a log level should be emitted */
|
|
#define SHOULD_LOG(srv_conf, level) ((srv_conf) && (srv_conf)->log_level <= (level))
|
|
|
|
/* Default sensitive headers blacklist - prevents accidental logging of credentials */
|
|
static const char *const DEFAULT_SENSITIVE_HEADERS[] = {
|
|
"Authorization",
|
|
"Cookie",
|
|
"Set-Cookie",
|
|
"X-Api-Key",
|
|
"X-Auth-Token",
|
|
"Proxy-Authorization",
|
|
"WWW-Authenticate",
|
|
NULL
|
|
};
|
|
|
|
/* Dynamic string buffer */
|
|
typedef struct {
|
|
char *data;
|
|
apr_size_t len;
|
|
apr_size_t capacity;
|
|
apr_pool_t *pool;
|
|
} dynbuf_t;
|
|
|
|
/* Per-child process state - stored in server config
|
|
* Includes mutex for thread safety in worker/event MPMs */
|
|
typedef struct {
|
|
int socket_fd;
|
|
apr_thread_mutex_t *fd_mutex; /* Protects socket_fd from concurrent access */
|
|
apr_time_t last_connect_attempt;
|
|
apr_time_t last_error_report;
|
|
int connect_failed;
|
|
} reqin_log_child_state_t;
|
|
|
|
/* Log levels */
|
|
typedef enum {
|
|
REQIN_LOG_LEVEL_DEBUG = 0,
|
|
REQIN_LOG_LEVEL_INFO = 1,
|
|
REQIN_LOG_LEVEL_WARNING = 2,
|
|
REQIN_LOG_LEVEL_ERROR = 3,
|
|
REQIN_LOG_LEVEL_EMERG = 4
|
|
} reqin_log_level_t;
|
|
|
|
/* Module server configuration structure */
|
|
typedef struct {
|
|
reqin_log_config_t *config;
|
|
reqin_log_child_state_t child_state;
|
|
reqin_log_level_t log_level;
|
|
} reqin_log_server_conf_t;
|
|
|
|
/* Forward declarations for helper functions */
|
|
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);
|
|
|
|
/* Forward declarations for commands */
|
|
static const char *cmd_set_enabled(cmd_parms *cmd, void *dummy, int flag);
|
|
static const char *cmd_set_socket(cmd_parms *cmd, void *dummy, const char *arg);
|
|
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);
|
|
static const char *cmd_set_max_header_value_len(cmd_parms *cmd, void *dummy, const char *arg);
|
|
static const char *cmd_set_reconnect_interval(cmd_parms *cmd, void *dummy, const char *arg);
|
|
static const char *cmd_set_error_report_interval(cmd_parms *cmd, void *dummy, const char *arg);
|
|
static const char *cmd_set_log_level(cmd_parms *cmd, void *dummy, const char *arg);
|
|
|
|
/* 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 */
|
|
static const command_rec reqin_log_cmds[] = {
|
|
AP_INIT_FLAG("JsonSockLogEnabled", cmd_set_enabled, NULL, RSRC_CONF,
|
|
"Enable or disable mod_reqin_log (On|Off)"),
|
|
AP_INIT_TAKE1("JsonSockLogSocket", cmd_set_socket, NULL, RSRC_CONF,
|
|
"Unix domain socket path for JSON logging"),
|
|
AP_INIT_ITERATE("JsonSockLogHeaders", cmd_set_headers, NULL, RSRC_CONF,
|
|
"List of HTTP header names to log"),
|
|
AP_INIT_TAKE1("JsonSockLogMaxHeaders", cmd_set_max_headers, NULL, RSRC_CONF,
|
|
"Maximum number of headers to log (default: 10)"),
|
|
AP_INIT_TAKE1("JsonSockLogMaxHeaderValueLen", cmd_set_max_header_value_len, NULL, RSRC_CONF,
|
|
"Maximum length of header value to log (default: 256)"),
|
|
AP_INIT_TAKE1("JsonSockLogReconnectInterval", cmd_set_reconnect_interval, NULL, RSRC_CONF,
|
|
"Reconnect interval in seconds (default: 10)"),
|
|
AP_INIT_TAKE1("JsonSockLogErrorReportInterval", cmd_set_error_report_interval, NULL, RSRC_CONF,
|
|
"Error report interval in seconds (default: 10)"),
|
|
AP_INIT_TAKE1("JsonSockLogLevel", cmd_set_log_level, NULL, RSRC_CONF,
|
|
"Log level: DEBUG, INFO, WARNING, ERROR, EMERG (default: WARNING)"),
|
|
{ NULL }
|
|
};
|
|
|
|
/* Module definition */
|
|
module AP_MODULE_DECLARE_DATA reqin_log_module = {
|
|
STANDARD20_MODULE_STUFF,
|
|
NULL, /* per-directory config creator */
|
|
NULL, /* dir config merger */
|
|
reqin_log_create_server_conf, /* server config creator */
|
|
NULL, /* server config merger */
|
|
reqin_log_cmds, /* command table */
|
|
reqin_log_register_hooks, /* register hooks */
|
|
0 /* flags */
|
|
};
|
|
|
|
/* Get module configuration */
|
|
static reqin_log_server_conf_t *get_server_conf(server_rec *s)
|
|
{
|
|
return (reqin_log_server_conf_t *)ap_get_module_config(s->module_config, &reqin_log_module);
|
|
}
|
|
|
|
/* Create server configuration */
|
|
static void *reqin_log_create_server_conf(apr_pool_t *pool, server_rec *s)
|
|
{
|
|
(void)s;
|
|
reqin_log_server_conf_t *srv_conf = apr_pcalloc(pool, sizeof(reqin_log_server_conf_t));
|
|
|
|
srv_conf->config = apr_pcalloc(pool, sizeof(reqin_log_config_t));
|
|
srv_conf->config->headers = apr_array_make(pool, 5, sizeof(const char *));
|
|
srv_conf->config->max_headers = DEFAULT_MAX_HEADERS;
|
|
srv_conf->config->max_header_value_len = DEFAULT_MAX_HEADER_VALUE_LEN;
|
|
srv_conf->config->reconnect_interval = DEFAULT_RECONNECT_INTERVAL;
|
|
srv_conf->config->error_report_interval = DEFAULT_ERROR_REPORT_INTERVAL;
|
|
|
|
srv_conf->child_state.socket_fd = -1;
|
|
srv_conf->child_state.fd_mutex = NULL;
|
|
srv_conf->child_state.last_connect_attempt = 0;
|
|
srv_conf->child_state.last_error_report = 0;
|
|
srv_conf->child_state.connect_failed = 0;
|
|
|
|
srv_conf->log_level = REQIN_LOG_LEVEL_WARNING;
|
|
|
|
return srv_conf;
|
|
}
|
|
|
|
/* ============== Dynamic Buffer Functions ============== */
|
|
|
|
static void dynbuf_init(dynbuf_t *db, apr_pool_t *pool, apr_size_t initial_capacity)
|
|
{
|
|
db->pool = pool;
|
|
db->capacity = initial_capacity;
|
|
db->len = 0;
|
|
db->data = apr_palloc(pool, initial_capacity);
|
|
db->data[0] = '\0';
|
|
}
|
|
|
|
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);
|
|
memcpy(new_data, db->data, db->len + 1); /* Copy including null terminator */
|
|
db->data = new_data;
|
|
db->capacity = new_capacity;
|
|
}
|
|
|
|
memcpy(db->data + db->len, str, len);
|
|
db->len += len;
|
|
db->data[db->len] = '\0';
|
|
}
|
|
|
|
static void dynbuf_append_char(dynbuf_t *db, char c)
|
|
{
|
|
if (db->len + 1 >= db->capacity) {
|
|
apr_size_t new_capacity = db->capacity * 2;
|
|
char *new_data = apr_palloc(db->pool, new_capacity);
|
|
memcpy(new_data, db->data, db->len);
|
|
db->data = new_data;
|
|
db->capacity = new_capacity;
|
|
}
|
|
db->data[db->len++] = c;
|
|
db->data[db->len] = '\0';
|
|
}
|
|
|
|
/* ============== JSON Helper Functions ============== */
|
|
|
|
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) {
|
|
case '"': dynbuf_append(db, "\\\"", 2); break;
|
|
case '\\': dynbuf_append(db, "\\\\", 2); break;
|
|
case '\b': dynbuf_append(db, "\\b", 2); break;
|
|
case '\f': dynbuf_append(db, "\\f", 2); break;
|
|
case '\n': dynbuf_append(db, "\\n", 2); break;
|
|
case '\r': dynbuf_append(db, "\\r", 2); break;
|
|
case '\t': dynbuf_append(db, "\\t", 2); break;
|
|
default:
|
|
if ((unsigned char)c < 0x20) {
|
|
char unicode[8];
|
|
snprintf(unicode, sizeof(unicode), "\\u%04x", (unsigned char)c);
|
|
dynbuf_append(db, unicode, -1);
|
|
} else {
|
|
dynbuf_append_char(db, c);
|
|
}
|
|
break;
|
|
}
|
|
}
|
|
}
|
|
|
|
static void format_iso8601(dynbuf_t *db, apr_time_t t)
|
|
{
|
|
apr_time_exp_t tm;
|
|
apr_time_exp_gmt(&tm, t);
|
|
|
|
/* Validate time components to prevent buffer overflow and invalid output.
|
|
* apr_time_exp_gmt should always produce valid values, but we validate
|
|
* defensively to catch any APR bugs or memory corruption. */
|
|
int year = tm.tm_year + 1900;
|
|
int mon = tm.tm_mon + 1;
|
|
int day = tm.tm_mday;
|
|
int hour = tm.tm_hour;
|
|
int min = tm.tm_min;
|
|
int sec = tm.tm_sec;
|
|
|
|
/* Clamp values to valid ranges to ensure fixed-width output (20 chars + null) */
|
|
if (year < 0) year = 0;
|
|
if (year > 9999) year = 9999;
|
|
if (mon < 1) mon = 1;
|
|
if (mon > 12) mon = 12;
|
|
if (day < 1) day = 1;
|
|
if (day > 31) day = 31;
|
|
if (hour < 0) hour = 0;
|
|
if (hour > 23) hour = 23;
|
|
if (min < 0) min = 0;
|
|
if (min > 59) min = 59;
|
|
if (sec < 0) sec = 0;
|
|
if (sec > 61) sec = 61;
|
|
|
|
char time_str[32];
|
|
snprintf(time_str, sizeof(time_str), "%04d-%02d-%02dT%02d:%02d:%02dZ",
|
|
year, mon, day, hour, min, sec);
|
|
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;
|
|
|
|
/* Reject leading whitespace (strtol skips it by default) */
|
|
if (apr_isspace(*arg)) 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)
|
|
{
|
|
(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";
|
|
}
|
|
srv_conf->config->enabled = flag ? 1 : 0;
|
|
return NULL;
|
|
}
|
|
|
|
static const char *cmd_set_socket(cmd_parms *cmd, void *dummy, const char *arg)
|
|
{
|
|
(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";
|
|
}
|
|
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;
|
|
}
|
|
|
|
static const char *cmd_set_headers(cmd_parms *cmd, void *dummy, const char *arg)
|
|
{
|
|
(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";
|
|
}
|
|
*(const char **)apr_array_push(srv_conf->config->headers) = apr_pstrdup(cmd->pool, arg);
|
|
return NULL;
|
|
}
|
|
|
|
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";
|
|
}
|
|
if (parse_int_strict(arg, &val) != 0) {
|
|
return "JsonSockLogMaxHeaders must be a valid integer";
|
|
}
|
|
if (val < 0) {
|
|
return "JsonSockLogMaxHeaders must be >= 0";
|
|
}
|
|
srv_conf->config->max_headers = val;
|
|
return NULL;
|
|
}
|
|
|
|
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";
|
|
}
|
|
if (parse_int_strict(arg, &val) != 0) {
|
|
return "JsonSockLogMaxHeaderValueLen must be a valid integer";
|
|
}
|
|
if (val < 1) {
|
|
return "JsonSockLogMaxHeaderValueLen must be >= 1";
|
|
}
|
|
srv_conf->config->max_header_value_len = val;
|
|
return NULL;
|
|
}
|
|
|
|
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";
|
|
}
|
|
if (parse_int_strict(arg, &val) != 0) {
|
|
return "JsonSockLogReconnectInterval must be a valid integer";
|
|
}
|
|
if (val < 0) {
|
|
return "JsonSockLogReconnectInterval must be >= 0";
|
|
}
|
|
srv_conf->config->reconnect_interval = val;
|
|
return NULL;
|
|
}
|
|
|
|
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";
|
|
}
|
|
if (parse_int_strict(arg, &val) != 0) {
|
|
return "JsonSockLogErrorReportInterval must be a valid integer";
|
|
}
|
|
if (val < 0) {
|
|
return "JsonSockLogErrorReportInterval must be >= 0";
|
|
}
|
|
srv_conf->config->error_report_interval = val;
|
|
return NULL;
|
|
}
|
|
|
|
static const char *cmd_set_log_level(cmd_parms *cmd, void *dummy, const char *arg)
|
|
{
|
|
(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";
|
|
}
|
|
if (arg == NULL || arg[0] == '\0') {
|
|
return "JsonSockLogLevel must be a non-empty string";
|
|
}
|
|
if (strcasecmp(arg, "DEBUG") == 0) {
|
|
srv_conf->log_level = REQIN_LOG_LEVEL_DEBUG;
|
|
} else if (strcasecmp(arg, "INFO") == 0) {
|
|
srv_conf->log_level = REQIN_LOG_LEVEL_INFO;
|
|
} else if (strcasecmp(arg, "WARNING") == 0) {
|
|
srv_conf->log_level = REQIN_LOG_LEVEL_WARNING;
|
|
} else if (strcasecmp(arg, "ERROR") == 0) {
|
|
srv_conf->log_level = REQIN_LOG_LEVEL_ERROR;
|
|
} else if (strcasecmp(arg, "EMERG") == 0) {
|
|
srv_conf->log_level = REQIN_LOG_LEVEL_EMERG;
|
|
} else {
|
|
return "JsonSockLogLevel must be one of: DEBUG, INFO, WARNING, ERROR, EMERG";
|
|
}
|
|
return NULL;
|
|
}
|
|
|
|
/* ============== Socket Functions ============== */
|
|
|
|
/**
|
|
* Check if a header name is in the sensitive headers blacklist.
|
|
* Returns 1 if header should be excluded, 0 otherwise.
|
|
*/
|
|
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;
|
|
}
|
|
}
|
|
return 0;
|
|
}
|
|
|
|
/* Mutex helper macros for thread-safe socket FD access */
|
|
#define FD_MUTEX_LOCK(state) do { \
|
|
if ((state)->fd_mutex) { \
|
|
apr_thread_mutex_lock((state)->fd_mutex); \
|
|
} \
|
|
} while(0)
|
|
|
|
#define FD_MUTEX_UNLOCK(state) do { \
|
|
if ((state)->fd_mutex) { \
|
|
apr_thread_mutex_unlock((state)->fd_mutex); \
|
|
} \
|
|
} while(0)
|
|
|
|
static int try_connect(reqin_log_config_t *cfg, reqin_log_child_state_t *state, server_rec *s)
|
|
{
|
|
apr_time_t now;
|
|
apr_time_t reconnect_interval;
|
|
int err = 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);
|
|
|
|
FD_MUTEX_LOCK(state);
|
|
|
|
if (state->connect_failed &&
|
|
(now - state->last_connect_attempt) < reconnect_interval) {
|
|
FD_MUTEX_UNLOCK(state);
|
|
return -1;
|
|
}
|
|
|
|
state->last_connect_attempt = now;
|
|
|
|
if (state->socket_fd < 0) {
|
|
state->socket_fd = socket(AF_UNIX, SOCK_DGRAM, 0);
|
|
if (state->socket_fd < 0) {
|
|
err = errno;
|
|
state->connect_failed = 1;
|
|
FD_MUTEX_UNLOCK(state);
|
|
LOG_THROTTLED(state, cfg, s, APLOG_ERR, err,
|
|
"Unix socket connect failed: cannot create socket");
|
|
return -1;
|
|
}
|
|
|
|
flags = fcntl(state->socket_fd, F_GETFL, 0);
|
|
if (flags < 0) {
|
|
flags = 0;
|
|
}
|
|
fcntl(state->socket_fd, F_SETFL, flags | O_NONBLOCK);
|
|
}
|
|
|
|
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);
|
|
|
|
rc = connect(fd, (struct sockaddr *)&addr, sizeof(addr));
|
|
if (rc < 0) {
|
|
err = errno;
|
|
if (err == EINPROGRESS || err == EAGAIN || err == EWOULDBLOCK || err == EALREADY || err == EISCONN) {
|
|
state->connect_failed = 0;
|
|
FD_MUTEX_UNLOCK(state);
|
|
return 0;
|
|
}
|
|
|
|
close(fd);
|
|
state->socket_fd = -1;
|
|
state->connect_failed = 1;
|
|
FD_MUTEX_UNLOCK(state);
|
|
LOG_THROTTLED(state, cfg, s, APLOG_ERR, err,
|
|
"Unix socket connect failed: %s", cfg->socket_path);
|
|
return -1;
|
|
}
|
|
|
|
state->connect_failed = 0;
|
|
FD_MUTEX_UNLOCK(state);
|
|
return 0;
|
|
}
|
|
|
|
static int ensure_connected(reqin_log_config_t *cfg, reqin_log_child_state_t *state, server_rec *s)
|
|
{
|
|
int connected;
|
|
|
|
/* Double-check pattern: validate config and state under lock to avoid
|
|
* unnecessary reconnect attempts under high concurrency */
|
|
FD_MUTEX_LOCK(state);
|
|
connected = (state->socket_fd >= 0 && !state->connect_failed &&
|
|
cfg != NULL && cfg->socket_path != NULL && cfg->socket_path[0] != '\0');
|
|
FD_MUTEX_UNLOCK(state);
|
|
|
|
if (connected) {
|
|
return 0;
|
|
}
|
|
|
|
return try_connect(cfg, state, s);
|
|
}
|
|
|
|
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;
|
|
ssize_t n;
|
|
|
|
if (!cfg || !state || !s || !data || len == 0) {
|
|
return -1;
|
|
}
|
|
|
|
FD_MUTEX_LOCK(state);
|
|
|
|
fd = state->socket_fd;
|
|
if (fd < 0) {
|
|
FD_MUTEX_UNLOCK(state);
|
|
return -1;
|
|
}
|
|
|
|
n = send(fd, data, len, MSG_DONTWAIT | MSG_NOSIGNAL);
|
|
if (n < 0) {
|
|
int err = errno;
|
|
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);
|
|
if (conn_lost) {
|
|
LOG_THROTTLED(state, cfg, s, APLOG_ERR, err,
|
|
"Unix socket write failed: connection lost");
|
|
} else {
|
|
LOG_THROTTLED(state, cfg, s, APLOG_ERR, err,
|
|
"Unix socket write failed");
|
|
}
|
|
return -1;
|
|
}
|
|
|
|
if ((apr_size_t)n < len) {
|
|
close(fd);
|
|
state->socket_fd = -1;
|
|
state->connect_failed = 1;
|
|
FD_MUTEX_UNLOCK(state);
|
|
return -1;
|
|
}
|
|
|
|
FD_MUTEX_UNLOCK(state);
|
|
return 0;
|
|
}
|
|
|
|
/* ============== Request Logging Functions ============== */
|
|
|
|
static const char *get_header(request_rec *r, const char *name)
|
|
{
|
|
const apr_table_t *headers = r->headers_in;
|
|
const apr_array_header_t *arr = apr_table_elts(headers);
|
|
const apr_table_entry_t *elts = (const apr_table_entry_t *)arr->elts;
|
|
int nelts = arr->nelts;
|
|
|
|
for (int i = 0; i < nelts; i++) {
|
|
if (elts[i].key != NULL && strcasecmp(elts[i].key, name) == 0) {
|
|
return elts[i].val;
|
|
}
|
|
}
|
|
return NULL;
|
|
}
|
|
|
|
static void log_request(request_rec *r, reqin_log_config_t *cfg, reqin_log_child_state_t *state, reqin_log_server_conf_t *srv_conf)
|
|
{
|
|
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;
|
|
const char *scheme;
|
|
const char *query;
|
|
|
|
if (!r || !r->server || !r->pool || !r->connection) {
|
|
return;
|
|
}
|
|
|
|
pool = r->pool;
|
|
s = r->server;
|
|
|
|
if (ensure_connected(cfg, state, s) < 0) {
|
|
return;
|
|
}
|
|
|
|
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 : "/";
|
|
/* Sanitize method and path to prevent log injection via oversized values */
|
|
if (strlen(method) > 32) {
|
|
method = apr_pstrmemdup(pool, method, 32);
|
|
}
|
|
if (strlen(path) > 2048) {
|
|
path = apr_pstrmemdup(pool, path, 2048);
|
|
}
|
|
host = apr_table_get(r->headers_in, "Host");
|
|
if (host == NULL) {
|
|
host = "";
|
|
} else {
|
|
/* Sanitize Host header to prevent log injection via oversized values */
|
|
if (strlen(host) > 256) {
|
|
host = apr_pstrmemdup(pool, host, 256);
|
|
}
|
|
}
|
|
http_version = r->protocol ? r->protocol : "UNKNOWN";
|
|
/* Sanitize HTTP version string */
|
|
if (strlen(http_version) > 16) {
|
|
http_version = apr_pstrmemdup(pool, http_version, 16);
|
|
}
|
|
|
|
/* scheme (https or http) */
|
|
scheme = ap_http_scheme(r);
|
|
if (scheme == NULL) {
|
|
scheme = "http";
|
|
}
|
|
|
|
/* query (query string from parsed URI, e.g., ?foo=bar) */
|
|
query = r->parsed_uri.query ? r->parsed_uri.query : "";
|
|
/* Sanitize query to prevent oversized values */
|
|
if (strlen(query) > 2048) {
|
|
query = apr_pstrmemdup(pool, query, 2048);
|
|
}
|
|
|
|
dynbuf_init(&buf, pool, 4096);
|
|
|
|
dynbuf_append(&buf, "{", 1);
|
|
|
|
/* time */
|
|
dynbuf_append(&buf, "\"time\":\"", 8);
|
|
format_iso8601(&buf, r->request_time);
|
|
dynbuf_append(&buf, "\",", 2);
|
|
|
|
/* timestamp (nanoseconds since epoch) */
|
|
{
|
|
apr_time_t now = apr_time_now();
|
|
apr_uint64_t ns = ((apr_uint64_t)now) * APR_UINT64_C(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);
|
|
}
|
|
|
|
/* scheme */
|
|
dynbuf_append(&buf, "\"scheme\":\"", 10);
|
|
append_json_string(&buf, scheme);
|
|
dynbuf_append(&buf, "\",", 2);
|
|
|
|
/* src_ip */
|
|
dynbuf_append(&buf, "\"src_ip\":\"", 10);
|
|
append_json_string(&buf, src_ip);
|
|
dynbuf_append(&buf, "\",", 2);
|
|
|
|
/* src_port */
|
|
if (r->connection->client_addr != NULL) {
|
|
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);
|
|
dynbuf_append(&buf, ",", 1);
|
|
|
|
/* dst_ip */
|
|
dynbuf_append(&buf, "\"dst_ip\":\"", 10);
|
|
append_json_string(&buf, dst_ip);
|
|
dynbuf_append(&buf, "\",", 2);
|
|
|
|
/* dst_port */
|
|
if (r->connection->local_addr != NULL) {
|
|
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);
|
|
dynbuf_append(&buf, ",", 1);
|
|
|
|
/* method */
|
|
dynbuf_append(&buf, "\"method\":\"", 10);
|
|
append_json_string(&buf, method);
|
|
dynbuf_append(&buf, "\",", 2);
|
|
|
|
/* path */
|
|
dynbuf_append(&buf, "\"path\":\"", 8);
|
|
append_json_string(&buf, path);
|
|
dynbuf_append(&buf, "\",", 2);
|
|
|
|
/* query */
|
|
dynbuf_append(&buf, "\"query\":\"", 9);
|
|
append_json_string(&buf, query);
|
|
dynbuf_append(&buf, "\",", 2);
|
|
|
|
/* host */
|
|
dynbuf_append(&buf, "\"host\":\"", 8);
|
|
append_json_string(&buf, host);
|
|
dynbuf_append(&buf, "\",", 2);
|
|
|
|
/* http_version */
|
|
dynbuf_append(&buf, "\"http_version\":\"", 16);
|
|
append_json_string(&buf, http_version);
|
|
dynbuf_append(&buf, "\",", 2);
|
|
|
|
/* keepalives */
|
|
dynbuf_append(&buf, "\"keepalives\":", 13);
|
|
{
|
|
char ka_buf[16];
|
|
snprintf(ka_buf, sizeof(ka_buf), "%d", r->connection->keepalives);
|
|
dynbuf_append(&buf, ka_buf, -1);
|
|
}
|
|
|
|
/* Check buffer size before adding headers to prevent memory exhaustion */
|
|
if (buf.len >= MAX_JSON_SIZE) {
|
|
if (SHOULD_LOG(srv_conf, REQIN_LOG_LEVEL_DEBUG)) {
|
|
ap_log_error(APLOG_MARK, APLOG_DEBUG, 0, s,
|
|
MOD_REQIN_LOG_NAME ": JSON buffer size limit reached before headers");
|
|
}
|
|
return;
|
|
}
|
|
|
|
/* headers - flat structure at same level as other fields */
|
|
if (cfg->headers && cfg->headers->nelts > 0) {
|
|
int header_count = 0;
|
|
int max_to_log = cfg->max_headers;
|
|
const char **header_names = (const char **)cfg->headers->elts;
|
|
|
|
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)) {
|
|
if (SHOULD_LOG(srv_conf, REQIN_LOG_LEVEL_DEBUG)) {
|
|
ap_log_error(APLOG_MARK, APLOG_DEBUG, 0, s,
|
|
MOD_REQIN_LOG_NAME ": Skipping sensitive header: %s", header_name);
|
|
}
|
|
continue;
|
|
}
|
|
|
|
header_value = get_header(r, header_name);
|
|
|
|
if (header_value != NULL) {
|
|
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) {
|
|
if (SHOULD_LOG(srv_conf, REQIN_LOG_LEVEL_DEBUG)) {
|
|
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);
|
|
|
|
val_len = strlen(header_value);
|
|
if ((int)val_len > cfg->max_header_value_len) {
|
|
val_len = (apr_size_t)cfg->max_header_value_len;
|
|
}
|
|
|
|
truncated = apr_pstrmemdup(pool, header_value, val_len);
|
|
append_json_string(&buf, truncated);
|
|
dynbuf_append(&buf, "\"", 1);
|
|
|
|
header_count++;
|
|
}
|
|
}
|
|
}
|
|
|
|
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);
|
|
}
|
|
|
|
/* ============== Apache Hooks ============== */
|
|
|
|
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 ||
|
|
!srv_conf->config->enabled || srv_conf->config->socket_path == NULL) {
|
|
return DECLINED;
|
|
}
|
|
|
|
log_request(r, srv_conf->config, &srv_conf->child_state, srv_conf);
|
|
return DECLINED;
|
|
}
|
|
|
|
static void reqin_log_child_init(apr_pool_t *p, server_rec *s)
|
|
{
|
|
reqin_log_server_conf_t *srv_conf = get_server_conf(s);
|
|
int threaded_mpm = 0;
|
|
int mpm_threads;
|
|
|
|
if (srv_conf == NULL) {
|
|
return;
|
|
}
|
|
|
|
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;
|
|
|
|
/* Detect if we're running in a threaded MPM (worker/event) */
|
|
if (ap_mpm_query(AP_MPMQ_IS_THREADED, &mpm_threads) == APR_SUCCESS &&
|
|
mpm_threads > 0) {
|
|
threaded_mpm = 1;
|
|
}
|
|
|
|
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;
|
|
|
|
if (threaded_mpm) {
|
|
/* Critical error: cannot ensure thread safety in worker/event MPM */
|
|
ap_log_error(APLOG_MARK, APLOG_EMERG, 0, s,
|
|
MOD_REQIN_LOG_NAME ": Failed to create mutex for thread safety. "
|
|
"Module cannot operate safely in threaded MPM. Disabling.");
|
|
/* Disable module by clearing config */
|
|
srv_conf->config->enabled = 0;
|
|
return;
|
|
} else {
|
|
/* Prefork MPM: single thread per process, mutex not strictly needed */
|
|
ap_log_error(APLOG_MARK, APLOG_WARNING, 0, s,
|
|
MOD_REQIN_LOG_NAME ": Failed to create mutex, continuing in "
|
|
"degraded mode (prefork MPM detected)");
|
|
}
|
|
}
|
|
|
|
if (srv_conf->config == NULL || !srv_conf->config->enabled ||
|
|
srv_conf->config->socket_path == NULL) {
|
|
return;
|
|
}
|
|
|
|
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);
|
|
}
|