github_mirrors/ModSecurity
3
0
Fork 1
mirror of https://github.com/owasp-modsecurity/ModSecurity.git synced 2025-08-14 13:56:01 +03:00
Code Issues Packages Projects Releases Wiki Activity
ModSecurity/apache2/msc_logging.c
Tomas Korbar bec33810e9 Move log opening to appropriate execution phase 
When piped logs are opened during parsing of configuration
it results in unexpected situations in apache httpd
and can cause hang of process which is trying to log
into auditlog.

Code should work as before, with the exception of
one additional condition evaluation when primary
audit log is not set and secondary audit log
path to piped executable is now not relative
to server root.
2024-10-11 14:50:20 +02:00

2371 lines
89 KiB
C
Raw Blame History

This file contains invisible Unicode characters

This file contains invisible Unicode characters that are indistinguishable to humans but may be processed differently by a computer. If you think that this is intentional, you can safely ignore this warning. Use the Escape button to reveal them.

/*
* ModSecurity for Apache 2.x, http://www.modsecurity.org/
* Copyright (c) 2004-2013 Trustwave Holdings, Inc. (http://www.trustwave.com/)
*
* You may not use this file except in compliance with
* the License.  You may obtain a copy of the License at
*
*     http://www.apache.org/licenses/LICENSE-2.0
*
* If any of the files related to licensing are missing or if you have any
* other questions related to licensing please contact Trustwave Holdings, Inc.
* directly using the email address security@modsecurity.org.
*/
#include "modsecurity.h"
#include <sys/stat.h>
#include "re.h"
#include "msc_logging.h"
#include "httpd.h"
#include "apr_strings.h"
#include "apr_global_mutex.h"
#include "msc_util.h"
#include "apr_version.h"
#include <libxml/xmlversion.h>
#ifdef WITH_YAJL
#include <yajl/yajl_gen.h>
#include "msc_logging_json.h"
#endif
/**
* Write the supplied data to the audit log (if the FD is ready), update
* the size counters, update the hash context.
*/
static int sec_auditlog_write(modsec_rec *msr, const char *data, unsigned int len) {
assert(msr != NULL);
apr_size_t nbytes_written, nbytes = len;
apr_status_t rc;
/* Do nothing if there's no data. */
if (data == NULL) return -1;
/* Update size counters and the hash calculation. We always do this,
* even in cases where write fails. That will make it easier to detect
* problems with partial writes.
*/
msr->new_auditlog_size += len;
apr_md5_update(&msr->new_auditlog_md5ctx, data, len);
/* Do not write if we do not have a file descriptor. */
if (msr->new_auditlog_fd == NULL) return -1;
/* Write data to file. */
rc = apr_file_write_full(msr->new_auditlog_fd, data, nbytes, &nbytes_written);
if (rc != APR_SUCCESS) {
char errstr[1024];
msr_log(msr, 1, "Audit log: Failed writing (requested %" APR_SIZE_T_FMT
" bytes, written %" APR_SIZE_T_FMT "): %s", nbytes, nbytes_written,
apr_strerror(rc, errstr, sizeof(errstr)));
/* Concurrent log format: don't leak file handle. */
if (msr->txcfg->auditlog_type == AUDITLOG_CONCURRENT) {
apr_file_close(msr->new_auditlog_fd);
}
/* Set to NULL to prevent more than one error message on
* out-of-disk-space events and to prevent further attempts
* to write to the same file in this request.
*
* Serial log format: Note that, as we opened the file through the
* pool mechanism of the APR, we do not need to close the file
* here. It will be closed automatically at the end of the request.
*/
msr->new_auditlog_fd = NULL;
return -1;
}
return 1;
}
/**
* Constructs a log line in vcombined log format trying to truncate
* some of the fields to make the log line shorter than _limit bytes.
*/
char *construct_log_vcombinedus_limited(modsec_rec *msr, int _limit, int *was_limited) {
assert(msr != NULL);
assert(was_limited != NULL);
char *hostname;
char *local_user, *remote_user;
char *referer, *user_agent, *uniqueid;
const char *sessionid;
char *the_request, *bytes_sent;
int limit = _limit;
/* hostname */
hostname = (msr->hostname == NULL ? "-" : log_escape_nq(msr->mp, msr->hostname));
/* remote log name */
if (msr->remote_user == NULL) remote_user = "-";
else remote_user = log_escape_nq(msr->mp, msr->remote_user);
/* authenticated user */
if (msr->local_user == NULL) local_user = "-";
else local_user = log_escape_nq(msr->mp, msr->local_user);
/* unique id */
if (msr->txid == NULL) uniqueid = "-";
else uniqueid = log_escape(msr->mp, msr->txid);
/* referer */
referer = "-";
/*
referer = (char *)apr_table_get(msr->request_headers, "Referer");
if (referer == NULL) referer = "-";
else referer = log_escape(msr->mp, referer);
*/
/* user agent */
user_agent = "-";
/*
user_agent = (char *)apr_table_get(msr->request_headers, "User-Agent");
if (user_agent == NULL) user_agent = "-";
else user_agent = log_escape(msr->mp, user_agent);
*/
/* sessionid */
sessionid = (msr->sessionid == NULL) ? "-" : log_escape(msr->mp, msr->sessionid);
the_request = (msr->request_line == NULL) ? "" : log_escape(msr->mp, msr->request_line);
bytes_sent = apr_psprintf(msr->mp, "%" APR_OFF_T_FMT, msr->bytes_sent);
/* first take away the size of the
* information we must log
*/
limit -= 22; /* spaces and double quotes */
limit -= strlen(hostname); /* server name or IP */
limit -= strlen(msr->remote_addr); /* remote IP */
limit -= 28; /* current_logtime */
limit -= 3; /* status */
limit -= strlen(bytes_sent); /* bytes sent */
limit -= strlen(uniqueid); /* unique id */
limit -= strlen(sessionid); /* session id */
if (limit <= 0) {
msr_log(msr, 1, "GuardianLog: Atomic pipe write size too small: %d", PIPE_BUF);
return NULL;
}
/* we hope to be able to squeeze everything in */
if (limit < (int)(strlen(remote_user) + strlen(local_user) + strlen(referer)
+ strlen(user_agent) + strlen(the_request)))
{
/* Boo hoo hoo, there's not enough space available. */
*was_limited = 1;
/* Let's see if we can reduce the size of something. This
* is a very crude approach but it seems to work for our
* needs.
*/
if (strlen(remote_user) > 32) {
msr_log(msr, 9, "GuardianLog: Reduced remote_user to 32.");
remote_user[32] = '\0';
}
limit -= strlen(remote_user);
if (strlen(local_user) > 32) {
msr_log(msr, 9, "GuardianLog: Reduced local_user to 32.");
local_user[32] = '\0';
}
limit -= strlen(local_user);
if (strlen(referer) > 64) {
msr_log(msr, 9, "GuardianLog: Reduced referer to 64.");
referer[64] = '\0';
}
limit -= strlen(referer);
if (strlen(user_agent) > 64) {
msr_log(msr, 9, "GuardianLog: Reduced user_agent to 64.");
user_agent[64] = '\0';
}
limit -= strlen(user_agent);
if (limit <= 0) {
msr_log(msr, 1, "GuardianLog: Atomic pipe write size too small: %d.", PIPE_BUF);
return NULL;
}
/* use what's left for the request line */
if ((int)strlen(the_request) > limit) {
the_request[limit] = '\0';
msr_log(msr, 9, "GuardianLog: Reduced the_request to %d bytes.", limit);
}
} else {
/* Yay! We have enough space! */
*was_limited = 0;
}
return apr_psprintf(msr->mp, "%s %s %s %s [%s] \"%s\" %u %s \"%s\" \"%s\" %s \"%s\"",
hostname, msr->remote_addr, remote_user,
local_user, current_logtime(msr->mp), the_request,
msr->response_status, bytes_sent, referer, user_agent,
uniqueid, sessionid
);
}
/**
* Checks if the provided string is a valid audit log parts specification.
*/
int is_valid_parts_specification(char *p) {
char c, *t = p;
while((c = *(t++)) != '\0') {
if ((c != AUDITLOG_PART_ENDMARKER)&&((c < AUDITLOG_PART_FIRST)||(c > AUDITLOG_PART_LAST))) {
return 0;
}
}
return 1;
}
/**
* Constructs a filename that will be used to store an
* audit log entry.
*/
static char *construct_auditlog_filename(apr_pool_t *mp, const char *uniqueid) {
apr_time_exp_t t;
char tstr[300];
apr_size_t len;
/**
* This is required for mpm-itk & mod_ruid2, though should be harmless for other implementations
* It also changes the return statement.
*/
char *userinfo;
apr_status_t rc;
apr_uid_t uid;
apr_gid_t gid;
apr_uid_current(&uid, &gid, mp);
rc = apr_uid_name_get(&userinfo, uid, mp);
if (rc != APR_SUCCESS) {
userinfo = apr_psprintf(mp, "%u", uid);
}
apr_time_exp_lt(&t, apr_time_now());
apr_strftime(tstr, &len, 299, "/%Y%m%d/%Y%m%d-%H%M/%Y%m%d-%H%M%S", &t);
return apr_psprintf(mp, "/%s%s-%s", userinfo, tstr, uniqueid);
}
/**
* Creates a random 8-character string that
* consists of hexadecimal numbers, to be used
* as an audit log boundary.
*/
static char *create_auditlog_boundary(request_rec *r) {
#ifdef LINUX_S390
int data = swap_int32(rand());
#else
unsigned long data = rand();
#endif
/* Do note that I tried using apr_generate_random_bytes but it turned
* out to be terribly slow for some reason. Needs further investigation.
*/
return bytes2hex(r->pool, (void *)&data, 4);
}
/**
* Sanitises the request line by removing the parameters
* that have been marked as sensitive.
*/
static void sanitize_request_line(modsec_rec *msr) {
const apr_array_header_t *tarr = NULL;
const apr_table_entry_t *telts = NULL;
const apr_array_header_t *tarr_pattern = NULL;
const apr_table_entry_t *telts_pattern = NULL;
msc_parm *mparm = NULL;
int i, k;
char *qspos;
char *buf = NULL;
int sanitized_partial = 0;
int sanitize_matched = 0;
/* Locate the query string. */
qspos = strstr(msr->request_line, "?");
if (qspos == NULL) return;
qspos++;
/* Loop through the list of sensitive parameters. */
tarr = apr_table_elts(msr->arguments_to_sanitize);
telts = (const apr_table_entry_t*)tarr->elts;
for (i = 0; i < tarr->nelts; i++) {
msc_arg *arg = (msc_arg *)telts[i].val;
/* Only look at the parameters that appeared in the query string. */
if (strcmp(arg->origin, "QUERY_STRING") == 0) {
char *pat = NULL;
char *p;
int j, arg_min, arg_max;
/* Go to the beginning of the parameter. */
p = qspos;
j = arg->value_origin_offset;
while((*p != '\0')&&(j--)) p++;
if (*p == '\0') {
msr_log(msr, 1, "Unable to sanitize variable \"%s\" at offset %u of QUERY_STRING"
"because the request line is too short.",
log_escape_ex(msr->mp, arg->name, arg->name_len),
arg->value_origin_offset);
continue;
}
tarr_pattern = apr_table_elts(msr->pattern_to_sanitize);
telts_pattern = (const apr_table_entry_t*)tarr_pattern->elts;
sanitized_partial = 0;
sanitize_matched = 0;
buf = apr_psprintf(msr->mp, "%s",p);
for ( k = 0; k < tarr_pattern->nelts; k++) {
if(strncmp(telts_pattern[k].key,arg->name,strlen(arg->name)) ==0 ) {
mparm = (msc_parm *)telts_pattern[k].val;
pat = strstr(buf,mparm->value);
if(mparm->pad_1 == -1)
sanitize_matched = 1;
if (pat != NULL) {
j = strlen(mparm->value);
arg_min = j;
arg_max = 1;
while((*pat != '\0')&&(j--)) {
if(arg_max > mparm->pad_2) {
int off = (strlen(mparm->value) - arg_max);
int pos = (mparm->pad_1-1);
if(off > pos) {
*pat = '*';
}
}
arg_max++;
arg_min--;
pat++;
}
}
sanitized_partial = 1;
}
}
if(sanitized_partial == 1 && sanitize_matched == 0) {
while(*buf != '\0') {
*p++ = *buf++;
}
continue;
} else {
/* Write over the value. */
j = arg->value_origin_len;
while((*p != '\0')&&(j--)) {
*p++ = '*';
}
if (*p == '\0') {
msr_log(msr, 1, "Unable to sanitize variable \"%s\" at offset %u (size %d) "
"of QUERY_STRING because the request line is too short.",
log_escape_ex(msr->mp, arg->name, arg->name_len),
arg->value_origin_offset, arg->value_origin_len);
continue;
}
}
}
}
}
/**
* Output the Producer header.
*/
static void sec_auditlog_write_producer_header(modsec_rec *msr) {
char **signatures = NULL;
char *text = NULL;
int i;
/* Try to write everything in one go. */
if (msr->txcfg->component_signatures->nelts == 0) {
text = apr_psprintf(msr->mp, "Producer: %s.\n", MODSEC_MODULE_NAME_FULL);
sec_auditlog_write(msr, text, strlen(text));
return;
}
/* Start with the ModSecurity signature. */
text = apr_psprintf(msr->mp, "Producer: %s", MODSEC_MODULE_NAME_FULL);
sec_auditlog_write(msr, text, strlen(text));
/* Then loop through the components and output individual signatures. */
signatures = (char **)msr->txcfg->component_signatures->elts;
for(i = 0; i < msr->txcfg->component_signatures->nelts; i++) {
text = apr_psprintf(msr->mp, "; %s", (char *)signatures[i]);
sec_auditlog_write(msr, text, strlen(text));
}
sec_auditlog_write(msr, ".\n", 2);
}
#ifdef WITH_YAJL
/**
* Ouput the Producer header into a JSON generator
*/
static void sec_auditlog_write_producer_header_json(modsec_rec *msr, yajl_gen g) {
assert(msr != NULL);
char **signatures = NULL;
int i;
// this is written no matter what
yajl_string(g, "producer");
/* Try to write verything in one go. */
if (msr->txcfg->component_signatures->nelts == 0) {
yajl_string(g, MODSEC_MODULE_NAME_FULL);
return;
}
// we'll need an array if there are component signatures
yajl_gen_array_open(g);
/* Start with the ModSecurity signature. */
yajl_string(g, MODSEC_MODULE_NAME_FULL);
/* Then loop through the components and output individual signatures. */
signatures = (char **)msr->txcfg->component_signatures->elts;
for(i = 0; i < msr->txcfg->component_signatures->nelts; i++) {
yajl_string(g, (char *)signatures[i]);
}
yajl_gen_array_close(g); // array for producers is finished
}
#endif
/*
* \brief This function will returns the next chain node
*
* \param current Pointer to current chined rule
* \param msr Pointer to modsec_rec
*
* \retval NULL On failure
* \retval next_rule On Success
*/
static msre_rule *return_chained_rule(const msre_rule *current, modsec_rec *msr) {
apr_array_header_t *arr = NULL;
msre_rule **rules = NULL;
msre_rule *rule = NULL, *next_rule = NULL;
int i;
int phase;
if (current == NULL || current->actionset == NULL || current->ruleset == NULL)
return NULL;
phase = current->actionset->phase;
switch (phase) {
case PHASE_REQUEST_HEADERS :
arr = current->ruleset->phase_request_headers;
break;
case PHASE_REQUEST_BODY :
arr = current->ruleset->phase_request_body;
break;
case PHASE_RESPONSE_HEADERS :
arr = current->ruleset->phase_response_headers;
break;
case PHASE_RESPONSE_BODY :
arr = current->ruleset->phase_response_body;
break;
case PHASE_LOGGING :
arr = current->ruleset->phase_logging;
break;
default :
msr_log(msr, 1, "Logging: Invalid phase %d",phase);
return NULL;
}
rules = (msre_rule **)arr->elts;
for (i = 0; i < arr->nelts; i++) {
rule = rules[i];
if (rule != NULL) {
if (strncmp(current->unparsed,rule->unparsed,strlen(current->unparsed)) == 0) {
if (i < arr->nelts -1) {
next_rule = rules[i+1];
} else {
next_rule = rules[i];
}
if (next_rule == NULL || next_rule->chain_starter == NULL)
return NULL;
if(current->chain_starter == NULL && next_rule->chain_starter != NULL) {
if (strncmp(current->unparsed, next_rule->chain_starter->unparsed, strlen(current->unparsed)) != 0)
return NULL;
}
if(current->chain_starter != NULL && next_rule->chain_starter != NULL) {
if (strncmp(current->chain_starter->unparsed, rule->chain_starter->unparsed, strlen(current->chain_starter->unparsed)) != 0)
return NULL;
}
return next_rule;
}
}
}
return NULL;
}
/*
* \brief This function will check if a chained rule
* appears into matched array.
*
* \param msr Pointer to modsec_rec
* \param next_rule Pointer to chained rule
*
* \retval 0 On failure
* \retval 1 On Success
*/
static int chained_is_matched(modsec_rec *msr, const msre_rule *next_rule) {
assert(msr != NULL);
int i = 0;
const msre_rule *rule = NULL;
for (i = 0; i < msr->matched_rules->nelts; i++) {
rule = ((msre_rule **)msr->matched_rules->elts)[i];
if (rule != NULL && (strncmp(rule->unparsed,next_rule->unparsed,strlen(rule->unparsed)) == 0)) {
return 1;
}
}
return 0;
}
#ifdef WITH_YAJL
/**
* Write detailed information about performance metrics into a JSON generator
*/
static void format_performance_variables_json(modsec_rec *msr, yajl_gen g) {
assert(msr != NULL);
yajl_string(g, "stopwatch");
yajl_gen_map_open(g);
yajl_kv_int(g, "p1", msr->time_phase1);
yajl_kv_int(g, "p2", msr->time_phase2);
yajl_kv_int(g, "p3", msr->time_phase3);
yajl_kv_int(g, "p4", msr->time_phase4);
yajl_kv_int(g, "p5", msr->time_phase5);
yajl_kv_int(g, "sr", msr->time_storage_read);
yajl_kv_int(g, "sw", msr->time_storage_write);
yajl_kv_int(g, "l", msr->time_logging);
yajl_kv_int(g, "gc", msr->time_gc);
yajl_gen_map_close(g);
}
/**
* Write detailed information about a rule and its actionset into a JSON generator
*/
static void write_rule_json(modsec_rec *msr, const msre_rule *rule, yajl_gen g) {
assert(msr != NULL);
assert(rule != NULL);
const apr_array_header_t *tarr;
const apr_table_entry_t *telts;
int been_opened = 0;
int k;
yajl_gen_map_open(g);
yajl_string(g, "actionset");
yajl_gen_map_open(g);
if (rule->actionset->id) {
yajl_kv_string(g, "id", log_escape(msr->mp, rule->actionset->id));
}
if (rule->actionset->rev) {
yajl_kv_string(g, "rev", log_escape(msr->mp, rule->actionset->rev));
}
if (rule->actionset->version) {
yajl_kv_string(g, "version", log_escape(msr->mp, rule->actionset->version));
}
if (rule->actionset->severity != NOT_SET) {
yajl_kv_int(g, "severity", rule->actionset->severity);
}
if (rule->actionset->accuracy != NOT_SET) {
yajl_kv_int(g, "accuracy", rule->actionset->accuracy);
}
if (rule->actionset->maturity != NOT_SET) {
yajl_kv_int(g, "maturity", rule->actionset->maturity);
}
if (rule->actionset->phase != NOT_SET) {
yajl_kv_int(g, "phase", rule->actionset->phase);
}
yajl_kv_bool(g, "is_chained", rule->actionset->is_chained || (rule->chain_starter != NULL));
if (rule->actionset->is_chained && (rule->chain_starter == NULL)) {
yajl_kv_bool(g, "chain_starter", 1);
}
// tags, lazily opened
tarr = apr_table_elts(rule->actionset->actions);
telts = (const apr_table_entry_t*)tarr->elts;
for (k = 0; k < tarr->nelts; k++) {
msre_action *action = (msre_action *)telts[k].val;
if (strcmp(telts[k].key, "tag") == 0) {
msc_string *var = NULL;
if (been_opened == 0) {
yajl_string(g, "tags");
yajl_gen_array_open(g);
been_opened = 1;
}
// expand variables in the tag
var = (msc_string *)apr_pcalloc(msr->mp, sizeof(msc_string));
var->value = (char *)action->param;
var->value_len = strlen(action->param);
expand_macros(msr, var, NULL, msr->mp);
yajl_string(g, log_escape(msr->mp, var->value));
}
}
if (been_opened == 1) {
yajl_gen_array_close(g);
}
yajl_gen_map_close(g);
yajl_string(g, "operator");
yajl_gen_map_open(g);
yajl_kv_string(g, "operator", rule->op_name);
yajl_kv_string(g, "operator_param", rule->op_param);
yajl_kv_string(g, "target", rule->p1);
yajl_kv_bool(g, "negated", rule->op_negated);
yajl_gen_map_close(g);
yajl_string(g, "config");
yajl_gen_map_open(g);
yajl_kv_string(g, "filename", rule->filename);
yajl_kv_int(g, "line_num", rule->line_num);
yajl_gen_map_close(g);
yajl_kv_string(g, "unparsed", rule->unparsed);
yajl_kv_bool(g, "is_matched", chained_is_matched(msr, rule));
yajl_gen_map_close(g);
}
/*
* Produce an audit log entry in JSON format.
*/
void sec_audit_logger_json(modsec_rec *msr) {
assert(msr != NULL);
const apr_array_header_t *arr = NULL;
apr_table_entry_t *te = NULL;
const apr_array_header_t *tarr_pattern = NULL;
const apr_table_entry_t *telts_pattern = NULL;
char *str1 = NULL, *str2 = NULL, *text = NULL;
const msre_rule *rule = NULL, *next_rule = NULL;
apr_size_t nbytes, nbytes_written;
unsigned char md5hash[APR_MD5_DIGESTSIZE];
int was_limited = 0;
int present = 0;
int wrote_response_body = 0;
char *entry_filename, *entry_basename;
apr_status_t rc;
int i, limit, k, sanitized_partial, j;
char *buf = NULL, *pat = NULL;
msc_parm *mparm = NULL;
int arg_min, arg_max, sanitize_matched;
yajl_gen g;
int been_opened = 0; // helper flag for conditionally opening maps
const unsigned char *final_buf;
size_t len;
/* Return silently if we don't have a request line. This
* means we will not be logging request timeouts.
*/
if (msr->request_line == NULL) {
msr_log(msr, 4, "Audit log: Skipping request whose request_line is null.");
return;
}
/* Also return silently if we don't have a file descriptor. */
if (msr->txcfg->auditlog_fd == NULL) {
msr_log(msr, 4, "Audit log: Skipping request since there is nowhere to write to.");
return;
}
if (msr->txcfg->auditlog_type != AUDITLOG_CONCURRENT) {
/* Serial logging - we already have an open file
* descriptor to write to.
*/
msr->new_auditlog_fd = msr->txcfg->auditlog_fd;
} else {
/* Concurrent logging - we need to create a brand
* new file for this request.
*/
apr_md5_init(&msr->new_auditlog_md5ctx);
msr->new_auditlog_filename = construct_auditlog_filename(msr->mp, msr->txid);
if (msr->new_auditlog_filename == NULL) return;
/* The audit log storage directory should be explicitly
* defined. But if it isn't try to write to the same
* directory where the index file is placed. Of course,
* it is *very* bad practice to allow the Apache user
* to write to the same directory where a root user is
* writing to but it's not us that's causing the problem
* and there isn't anything we can do about that.
*
* ENH Actually there is something we can do! We will make
* SecAuditStorageDir mandatory, ask the user to explicitly
* define the storage location *and* refuse to work if the
* index and the storage location are in the same folder.
*/
if (msr->txcfg->auditlog_storage_dir == NULL) {
entry_filename = file_dirname(msr->mp, msr->txcfg->auditlog_name);
}
else {
entry_filename = msr->txcfg->auditlog_storage_dir;
}
if (entry_filename == NULL) return;
entry_filename = apr_psprintf(msr->mp, "%s%s", entry_filename, msr->new_auditlog_filename);
if (entry_filename == NULL) return;
entry_basename = file_dirname(msr->mp, entry_filename);
if (entry_basename == NULL) return;
/* IMP1 Surely it would be more efficient to check the folders for
* the audit log repository base path in the configuration phase, to reduce
* the work we do on every request. Also, since our path depends on time,
* we could cache the time we last checked and don't check if we know
* the folder is there.
*/
rc = apr_dir_make_recursive(entry_basename, msr->txcfg->auditlog_dirperms, msr->mp);
if ((rc != APR_SUCCESS) && (rc != APR_EEXIST)) {
msr_log(msr, 1, "Audit log: Failed to create subdirectories: %s (%s)",
entry_basename, get_apr_error(msr->mp, rc));
return;
}
rc = apr_file_open(&msr->new_auditlog_fd, entry_filename,
APR_WRITE | APR_TRUNCATE | APR_CREATE | APR_BINARY | APR_FILE_NOCLEANUP,
msr->txcfg->auditlog_fileperms, msr->mp);
if (rc != APR_SUCCESS) {
msr_log(msr, 1, "Audit log: Failed to create file: %s (%s)",
entry_filename, get_apr_error(msr->mp, rc));
return;
}
}
/* Lock the mutex, but only if we are using serial format. */
if (msr->txcfg->auditlog_type != AUDITLOG_CONCURRENT) {
msr_global_mutex_lock(msr, msr->modsecurity->auditlog_lock, "Audit log");
}
/**
* allocate the buffer for the JSON generator
* passing null will force yajl to use malloc/realloc/free
* need to perf test using APR routines
*/
g = yajl_gen_alloc(NULL);
/**
* don't pretty print JSON
* this is harder to eyeball but much easier to parse programmatically
*/
yajl_gen_config(g, yajl_gen_beautify, 0);
yajl_gen_map_open(g); // IT BEGINS
/* AUDITLOG_PART_HEADER */
yajl_string(g, "transaction");
yajl_gen_map_open(g); // transaction top-level key
yajl_kv_string(g, "time", current_logtime(msr->mp));
yajl_kv_string(g, "transaction_id", msr->txid);
yajl_kv_string(g, "remote_address", msr->remote_addr);
yajl_kv_int(g, "remote_port", (int)msr->remote_port); // msr->remote_port is unsigned, yajl wants signed
yajl_kv_string(g, "local_address", msr->local_addr);
yajl_kv_int(g, "local_port", (int)msr->local_port);
yajl_gen_map_close(g); // transaction top-level key is finished
yajl_string(g, "request");
yajl_gen_map_open(g); // request top-level key
/* AUDITLOG_PART_REQUEST_HEADERS */
if (strchr(msr->txcfg->auditlog_parts, AUDITLOG_PART_REQUEST_HEADERS) != NULL) {
sanitize_request_line(msr);
yajl_kv_string(g, "request_line", msr->request_line);
yajl_string(g, "headers");
yajl_gen_map_open(g); // separate map for request headers
arr = apr_table_elts(msr->request_headers);
te = (apr_table_entry_t *)arr->elts;
tarr_pattern = apr_table_elts(msr->pattern_to_sanitize);
telts_pattern = (const apr_table_entry_t*)tarr_pattern->elts;
for (i = 0; i < arr->nelts; i++) {
sanitized_partial = 0;
sanitize_matched = 0;
text = apr_psprintf(msr->mp, "%s: %s\n", te[i].key, te[i].val);
// write the key no matter what
// since sanitization only occurs on the value
yajl_string(g, te[i].key);
if (apr_table_get(msr->request_headers_to_sanitize, te[i].key) != NULL) {
buf = apr_psprintf(msr->mp, "%s",text+strlen(te[i].key)+2);
for ( k = 0; k < tarr_pattern->nelts; k++) {
if(strncmp(telts_pattern[k].key,te[i].key,strlen(te[i].key)) ==0 ) {
mparm = (msc_parm *)telts_pattern[k].val;
if(mparm->pad_1 == -1)
sanitize_matched = 1;
pat = strstr(buf,mparm->value);
if (pat != NULL) {
j = strlen(mparm->value);
arg_min = j;
arg_max = 1;
while((*pat != '\0')&&(j--)) {
if(arg_max > mparm->pad_2) {
int off = strlen(mparm->value) - arg_max;
int pos = mparm->pad_1-1;
if(off > pos) {
*pat = '*';
}
}
arg_max++;
arg_min--;
pat++;
}
sanitized_partial = 1;
}
}
}
if(sanitized_partial == 1 && sanitize_matched == 0) {
yajl_string(g, buf);
} else {
memset(buf, '*', strlen(buf)); // strlen also includes the appended newline on the header
yajl_string(g, buf);
}
} else {
// we diverge from the original logic a bit because we always print the key
// at this no point sanitization had occured, so we just print the value
yajl_string(g, te[i].val);
}
}
yajl_gen_map_close(g); // request headers map is finished
}
/* AUDITLOG_PART_REQUEST_BODY */
/* Output this part of it was explicitly requested (C) or if it was the faked
* request body that was requested (I) but we have no reason to fake it (it's
* already in the correct format).
*/
if ( (strchr(msr->txcfg->auditlog_parts, AUDITLOG_PART_REQUEST_BODY) != NULL)
|| ( (strchr(msr->txcfg->auditlog_parts, AUDITLOG_PART_FAKE_REQUEST_BODY) != NULL)
&& (msr->mpd == NULL) ) )
{
if (msr->msc_reqbody_read) {
const apr_array_header_t *tarr;
const apr_table_entry_t *telts;
apr_array_header_t *sorted_args;
unsigned int offset = 0, last_offset = 0;
msc_arg *nextarg = NULL;
int sanitize = 0; /* IMP1 Use constants for "sanitize" values. */
char *my_error_msg = NULL;
sorted_args = apr_array_make(msr->mp, 25, sizeof(const msc_arg *));
/* First we need to sort the arguments that need to be
* sanitized in descending order (we are using a stack structure
* to store then so the order will be ascending when we start
* popping them out). This is because we will
* be reading the request body sequentially and must
* sanitize it as we go.
*/
for(;;) {
nextarg = NULL;
/* Find the next largest offset (excluding
* the ones we've used up already).
*/
tarr = apr_table_elts(msr->arguments_to_sanitize);
telts = (const apr_table_entry_t*)tarr->elts;
for(i = 0; i < tarr->nelts; i++) {
msc_arg *arg = (msc_arg *)telts[i].val;
if (arg->origin != NULL &&
( strcmp(arg->origin, "BODY") != 0 && strcmp(arg->origin, "JSON") !=0) )
continue;
if (last_offset == 0) { /* The first time we're here. */
if (arg->value_origin_offset > offset) {
offset = arg->value_origin_offset;
nextarg = arg;
}
} else { /* Not the first time. */
if ((arg->value_origin_offset > offset)
&&(arg->value_origin_offset < last_offset))
{
offset = arg->value_origin_offset;
nextarg = arg;
}
}
}
/* If we don't have the next argument that means
* we're done here.
*/
if (nextarg == NULL) break;
sanitize = 2; /* Means time to pop the next argument out. */
last_offset = offset;
offset = 0;
{ /* IMP1 Fix this ugly bit here. */
msc_arg **x = apr_array_push(sorted_args);
*x = nextarg;
}
}
/* Now start retrieving the body chunk by chunk and
* sanitize data in pieces.
*/
rc = modsecurity_request_body_retrieve_start(msr, &my_error_msg);
if (rc < 0) {
msr_log(msr, 1, "Audit log: %s", my_error_msg);
} else {
msc_data_chunk *chunk = NULL;
unsigned int chunk_offset = 0;
unsigned int sanitize_offset = 0;
unsigned int sanitize_length = 0;
yajl_string(g, "body");
yajl_gen_array_open(g); // use an array here because we're writing in chunks
for(;;) {
rc = modsecurity_request_body_retrieve(msr, &chunk, -1, &my_error_msg);
if (chunk != NULL) {
/* Anything greater than 1 means we have more data to sanitize. */
while (sanitize > 1) {
msc_arg **arg = NULL;
if (sanitize == 2) {
/* Get the next argument from the stack. */
arg = (msc_arg **)apr_array_pop(sorted_args);
if (arg == NULL) sanitize = 0; /* We're done sanitising. */
else {
/* Continue with sanitation to process the
* retrieved argument.
*/
sanitize = 1;
sanitize_offset = (*arg)->value_origin_offset;
sanitize_length = (*arg)->value_origin_len;
}
}
if (sanitize) {
/* Check if the data we want to sanitize is
* stored in the current chunk.
*/
if (chunk_offset + chunk->length > sanitize_offset) {
unsigned int soff; /* data offset within chunk */
unsigned int len; /* amount in this chunk to sanitize */
soff = sanitize_offset - chunk_offset;
if (soff + sanitize_length <= chunk->length) {
/* The entire argument resides in the current chunk. */
len = sanitize_length;
sanitize = 2; /* Get another parameter to sanitize. */
} else {
/* Some work to do here but we'll need to seek
* another chunk.
*/
len = chunk->length - soff;
sanitize_offset += len;
sanitize_length -= len;
sanitize = 1; /* It's OK to go to the next chunk. */
}
/* Yes, we actually write over the original data.
* We shouldn't be needing it any more.
*/
if (soff + len <= chunk->length) { /* double check */
memset((char *)chunk->data + soff, '*', len);
}
}
}
}
/* Write the sanitized chunk to the log
* and advance to the next chunk. */
chunk->data[chunk->length] = 0;
yajl_string(g, chunk->data);
chunk_offset += chunk->length;
}
if (rc <= 0) {
break;
}
}
yajl_gen_array_close(g); // request body chunks array is finished
if (rc < 0) {
msr_log(msr, 1, "Audit log: %s", my_error_msg);
}
modsecurity_request_body_retrieve_end(msr);
}
}
}
/* AUDITLOG_PART_FAKE_REQUEST_BODY */
if (strchr(msr->txcfg->auditlog_parts, AUDITLOG_PART_FAKE_REQUEST_BODY) != NULL) {
if ((msr->msc_reqbody_read)&&(msr->mpd != NULL)) {
char *buffer = NULL;
buffer = multipart_reconstruct_urlencoded_body_sanitize(msr);
if (buffer == NULL) {
msr_log(msr, 1, "Audit log: Failed to reconstruct request body.");
} else {
yajl_kv_string(g, "fake_body", buffer);
}
}
}
yajl_gen_map_close(g); // request top-level key is finished
yajl_string(g, "response");
yajl_gen_map_open(g); // response top-level key
/* AUDITLOG_PART_A_RESPONSE_HEADERS */
if (strchr(msr->txcfg->auditlog_parts, AUDITLOG_PART_A_RESPONSE_HEADERS) != NULL) {
/* There are no response headers (or the status line) in HTTP 0.9 */
if (msr->response_headers_sent) {
yajl_kv_string(g, "protocol", msr->response_protocol);
// as an integer, response status is easier to parse than status_line
yajl_kv_int(g, "status", (int)msr->response_status);
yajl_string(g, "headers");
yajl_gen_map_open(g); // separate map for response headers
/* Output headers */
arr = apr_table_elts(msr->response_headers);
te = (apr_table_entry_t *)arr->elts;
tarr_pattern = apr_table_elts(msr->pattern_to_sanitize);
telts_pattern = (const apr_table_entry_t*)tarr_pattern->elts;
for (i = 0; i < arr->nelts; i++) {
sanitized_partial = 0;
sanitize_matched = 0;
text = apr_psprintf(msr->mp, "%s: %s\n", te[i].key, te[i].val);
// write the key no matter what
// since sanitization only occurs on the value
yajl_string(g, te[i].key);
if (apr_table_get(msr->response_headers_to_sanitize, te[i].key) != NULL) {
buf = apr_psprintf(msr->mp, "%s",text+strlen(te[i].key)+2);
for ( k = 0; k < tarr_pattern->nelts; k++) {
if(strncmp(telts_pattern[k].key,te[i].key,strlen(te[i].key)) ==0 ) {
mparm = (msc_parm *)telts_pattern[k].val;
if(mparm->pad_1 == -1)
sanitize_matched = 1;
pat = strstr(buf,mparm->value);
if (pat != NULL) {
j = strlen(mparm->value);
arg_min = j;
arg_max = 1;
while((*pat != '\0')&&(j--)) {
if(arg_max > mparm->pad_2) {
int off = strlen(mparm->value) - arg_max;
int pos = mparm->pad_1-1;
if(off > pos) {
*pat = '*';
}
}
arg_max++;
arg_min--;
pat++;
}
sanitized_partial = 1;
}
}
}
if(sanitized_partial == 1 && sanitize_matched == 0) {
yajl_string(g, buf);
} else {
memset(buf, '*', strlen(buf));
yajl_string(g, buf);
}
} else {
// we diverge from the original logic a bit because we always print the key
// at this point no sanitization had occured, so we just print the value
yajl_string(g, te[i].val);
}
}
yajl_gen_map_close(g); // response headers map is finised
}
}
apr_table_clear(msr->pattern_to_sanitize);
/* AUDITLOG_PART_RESPONSE_BODY */
if (strchr(msr->txcfg->auditlog_parts, AUDITLOG_PART_RESPONSE_BODY) != NULL) {
if (msr->resbody_data != NULL) {
yajl_kv_string(g, "body", msr->resbody_data);
wrote_response_body = 1;
}
}
yajl_gen_map_close(g); // response top-level key is finished
yajl_string(g, "audit_data");
yajl_gen_map_open(g); // audit_data top-level key
/* AUDITLOG_PART_TRAILER */
if (strchr(msr->txcfg->auditlog_parts, AUDITLOG_PART_TRAILER) != NULL) {
apr_time_t now = apr_time_now();
/* Messages */
been_opened = 0;
if (msr->alerts->nelts > 0) {
yajl_string(g, "messages");
yajl_gen_array_open(g);
been_opened = 1;
}
for(i = 0; i < msr->alerts->nelts; i++) {
yajl_string(g, ((char **)msr->alerts->elts)[i]);
}
if (been_opened == 1) {
yajl_gen_array_close(g);
}
/* Apache error messages */
been_opened = 0;
if (msr->error_messages->nelts > 0) {
yajl_string(g, "error_messages");
yajl_gen_array_open(g);
been_opened = 1;
}
for(i = 0; i < msr->error_messages->nelts; i++) {
error_message_t *em = (((error_message_t **)msr->error_messages->elts)[i]);
yajl_string(g, format_error_log_message(msr->mp, em));
}
if (been_opened == 1) {
yajl_gen_array_close(g);
}
/* Action */
if (msr->was_intercepted) {
yajl_string(g, "action");
yajl_gen_map_open(g);
yajl_kv_bool(g, "intercepted", 1);
yajl_kv_int(g, "phase", msr->intercept_phase);
yajl_kv_string(g, "message", msr->intercept_message);
yajl_gen_map_close(g);
}
/* Apache-Handler */
#ifdef LOG_NO_HANDLER
if (msr->txcfg->debuglog_level >= 9)
#endif
if (msr->r->handler != NULL) {
yajl_kv_string(g, "handler", msr->r->handler);
}
/* Stopwatch2 */
#ifdef LOG_NO_STOPWATCH
if (msr->txcfg->debuglog_level >= 9)
#endif
format_performance_variables_json(msr, g);
/* Our response body does not contain chunks */
/* ENH Only write this when the output was chunked. */
/* ENH Add info when request body was decompressed, dechunked too. */
#ifdef LOG_NO_DECHUNK
if (msr->txcfg->debuglog_level >= 9)
#endif
if (wrote_response_body) {
yajl_kv_bool(g, "response_body_dechunked", 1);
}
#ifdef LOG_NO_SERVER_CONTEXT
if (msr->txcfg->debuglog_level >= 9) {
#endif
sec_auditlog_write_producer_header_json(msr, g);
/* Server */
if (msr->server_software != NULL) {
yajl_kv_string(g, "server", msr->server_software);
}
been_opened = 0;
/* Sanitised arguments */
{
const apr_array_header_t *tarr;
const apr_table_entry_t *telts;
tarr = apr_table_elts(msr->arguments_to_sanitize);
telts = (const apr_table_entry_t*)tarr->elts;
if (tarr->nelts > 0) {
if (been_opened == 0) {
yajl_string(g, "sanitized");
yajl_gen_map_open(g);
been_opened = 1;
}
yajl_string(g, "args");
yajl_gen_array_open(g);
}
for(i = 0; i < tarr->nelts; i++) {
msc_arg *arg = (msc_arg *)telts[i].val;
// yay arrays actually make it easier here
yajl_string(g, log_escape(msr->mp, arg->name));
}
if (tarr->nelts > 0) {
yajl_gen_array_close(g);
}
}
/* Sanitised request headers */
{
const apr_array_header_t *tarr;
const apr_table_entry_t *telts;
tarr = apr_table_elts(msr->request_headers_to_sanitize);
telts = (const apr_table_entry_t*)tarr->elts;
if (tarr->nelts > 0) {
if (been_opened == 0) {
yajl_string(g, "sanitized");
yajl_gen_map_open(g);
been_opened = 1;
}
yajl_string(g, "request_headers");
yajl_gen_array_open(g);
}
for(i = 0; i < tarr->nelts; i++) {
yajl_string(g, log_escape(msr->mp, telts[i].key));
}
if (tarr->nelts > 0) {
yajl_gen_array_close(g);
}
}
/* Sanitised response headers */
{
const apr_array_header_t *tarr;
const apr_table_entry_t *telts;
tarr = apr_table_elts(msr->response_headers_to_sanitize);
telts = (const apr_table_entry_t*)tarr->elts;
if (tarr->nelts > 0) {
if (been_opened == 0) {
yajl_string(g, "sanitized");
yajl_gen_map_open(g);
been_opened = 1;
}
yajl_string(g, "response_headers");
yajl_gen_array_open(g);
}
for(i = 0; i < tarr->nelts; i++) {
yajl_string(g, log_escape(msr->mp, telts[i].key));
}
if (tarr->nelts > 0) {
yajl_gen_array_close(g);
}
}
if (been_opened == 1) {
yajl_gen_map_close(g); // sanitized args map is finished
}
#ifdef LOG_NO_SERVER_CONTEXT
}
#endif
/* Web application info. */
if ( ((msr->txcfg->webappid != NULL)&&(strcmp(msr->txcfg->webappid, "default") != 0))
|| (msr->sessionid != NULL) || (msr->userid != NULL))
{
yajl_string(g, "webapp_info");
yajl_gen_map_open(g);
if (msr->txcfg->webappid != NULL) {
yajl_kv_string(g, "id", log_escape(msr->mp, msr->txcfg->webappid));
}
if (msr->sessionid != NULL) {
yajl_kv_string(g, "session", log_escape(msr->mp, msr->sessionid));
}
if (msr->userid != NULL) {
yajl_kv_string(g, "user_id", log_escape(msr->mp, msr->userid));
}
yajl_gen_map_close(g);
}
if ( ((msr->txcfg->sensor_id != NULL)&&(strcmp(msr->txcfg->sensor_id, "default") != 0)))
{
if(msr->txcfg->sensor_id != NULL) {
yajl_kv_string(g, "sensor_id", log_escape(msr->mp, msr->txcfg->sensor_id));
}
}
if (msr->txcfg->is_enabled > 0) {
yajl_kv_string(g, "engine_mode", (msr->txcfg->is_enabled == 1 ? "DETECTION_ONLY" : "ENABLED"));
}
/* Rule performance time */
if(msr->txcfg->max_rule_time > 0) {
const apr_array_header_t *tarr;
const apr_table_entry_t *telts;
tarr = apr_table_elts(msr->perf_rules);
telts = (const apr_table_entry_t*)tarr->elts;
if (tarr->nelts > 0) {
yajl_string(g, "rules_performance_info");
yajl_gen_map_open(g); // separate map for rule perf info
}
for(i = 0; i < tarr->nelts; i++) {
yajl_kv_string(g, log_escape(msr->mp, telts[i].key), log_escape(msr->mp, telts[i].val));
}
if (tarr->nelts > 0) {
yajl_gen_map_close(g); // map for rule perf info is finished
}
}
}
yajl_gen_map_close(g); // audit_data top-level key is finished
/* AUDITLOG_PART_UPLOADS */
if ((strchr(msr->txcfg->auditlog_parts, AUDITLOG_PART_UPLOADS) != NULL) && (msr->mpd != NULL)) {
multipart_part **parts = NULL;
unsigned int total_size = 0;
int cfiles = 0;
yajl_string(g, "uploads");
yajl_gen_map_open(g);
parts = (multipart_part **)msr->mpd->parts->elts;
yajl_string(g, "info");
yajl_gen_array_open(g); // separate array for upload info
for(cfiles = 0; cfiles < msr->mpd->parts->nelts; cfiles++) {
if (parts[cfiles]->type == MULTIPART_FILE) {
if(parts[cfiles]->filename != NULL) {
yajl_gen_map_open(g);
yajl_kv_int(g, "file_size", parts[cfiles]->tmp_file_size);
yajl_kv_string(g, "file_name", log_escape(msr->mp, parts[cfiles]->filename));
yajl_kv_string(g, "content_type", parts[cfiles]->content_type ? parts[cfiles]->content_type : "<Unknown Content-Type>");
total_size += parts[cfiles]->tmp_file_size;
yajl_gen_map_close(g);
}
}
}
yajl_gen_array_close(g); // array for upload info is finished
yajl_kv_int(g, "total", total_size);
yajl_gen_map_close(g); // uploads top-level key is finished
}
/* AUDITLOG_PART_MATCHEDRULES */
if (strchr(msr->txcfg->auditlog_parts, AUDITLOG_PART_MATCHEDRULES) != NULL) {
yajl_string(g, "matched_rules");
yajl_gen_array_open(g); // matched_rules top-level key
/* Matched Rules */
for(i = 0; i < msr->matched_rules->nelts; i++) {
rule = ((msre_rule **)msr->matched_rules->elts)[i];
if ((rule != NULL) && (rule->actionset != NULL) && rule->actionset->is_chained && (rule->chain_starter == NULL)) {
/*
* create a separate map for each rule chain
* this makes it a lot easier to search for partial chains
*/
yajl_gen_map_open(g); // map for this chain
yajl_kv_bool(g, "chain", 1);
yajl_string(g, "rules");
yajl_gen_array_open(g); // array for the rules
write_rule_json(msr, rule, g);
do {
if (rule->ruleset != NULL) {
next_rule = return_chained_rule(rule,msr);
if (next_rule != NULL) {
present = chained_is_matched(msr,next_rule);
if (present == 1) {
i++;
}
write_rule_json(msr, next_rule, g);
}
}
rule = next_rule;
} while (rule != NULL && rule->actionset != NULL && rule->actionset->is_chained);
yajl_gen_array_close(g);
yajl_kv_bool(g, "full_chain_match", present); // if one of the rules didnt match, present is set to 0
yajl_gen_map_close(g); // close the map for this chain
} else {
yajl_gen_map_open(g);
yajl_kv_bool(g, "chain", 0);
yajl_string(g, "rules"); // this really should be 'rule', but we're keeping in line with other chain maps
yajl_gen_array_open(g);
if ((rule != NULL) && (rule->actionset != NULL) && !rule->actionset->is_chained && (rule->chain_starter == NULL)) {
write_rule_json(msr, rule, g);
}
yajl_gen_array_close(g);
yajl_gen_map_close(g);
}
}
yajl_gen_array_close(g); // matched_rules top-level key is finished
}
/* AUDITLOG_PART_ENDMARKER */
/* finished building JSON */
yajl_gen_map_close(g); // box it up!
yajl_gen_get_buf(g, &final_buf, &len);
sec_auditlog_write(msr, final_buf, len);
yajl_gen_clear(g);
yajl_gen_free(g);
sec_auditlog_write(msr, "\n", 1);
/* Return here if we were writing to a serial log
* as it does not need an index file.
*/
if (msr->txcfg->auditlog_type != AUDITLOG_CONCURRENT) {
/* Unlock the mutex we used to serialise access to the audit log file. */
msr_global_mutex_unlock(msr, msr->modsecurity->auditlog_lock, "Audit log");
return;
}
/* From here on only concurrent-style processing. */
/* File handle might already be closed after write failure. */
if (msr->new_auditlog_fd) {
apr_file_close(msr->new_auditlog_fd);
}
/* Write an entry to the index file */
/* Calculate hash of the entry. */
apr_md5_final(md5hash, &msr->new_auditlog_md5ctx);
str2 = apr_psprintf(msr->mp, "%s %d %d md5:%s", msr->new_auditlog_filename, 0,
msr->new_auditlog_size, bytes2hex(msr->mp, md5hash, 16));
if (str2 == NULL) return;
/* We do not want the index line to be longer than 3980 bytes. */
limit = 3980;
was_limited = 0;
/* If we are logging to a pipe we need to observe and
* obey the pipe atomic write limit - PIPE_BUF. For
* more details see the discussion in sec_guardian_logger code.
*/
if (msr->txcfg->auditlog_name[0] == '|') {
if (PIPE_BUF < limit) {
limit = PIPE_BUF;
}
}
limit = limit - strlen(str2) - 5;
if (limit <= 0) {
msr_log(msr, 1, "Audit Log: Atomic PIPE write buffer too small: %d", PIPE_BUF);
return;
}
str1 = construct_log_vcombinedus_limited(msr, limit, &was_limited);
if (str1 == NULL) return;
if (was_limited == 0) {
text = apr_psprintf(msr->mp, "%s %s \n", str1, str2);
} else {
text = apr_psprintf(msr->mp, "%s %s L\n", str1, str2);
}
if (text == NULL) return;
nbytes = strlen(text);
if (msr->txcfg->debuglog_level >= 9) {
msr_log(msr, 9, "Audit Log: Writing %" APR_SIZE_T_FMT " bytes to primary concurrent index", nbytes);
}
apr_file_write_full(msr->txcfg->auditlog_fd, text, nbytes, &nbytes_written);
/* Write to the secondary audit log if we have one */
if (msr->txcfg->auditlog2_fd != NULL) {
if (msr->txcfg->debuglog_level >= 9) {
msr_log(msr, 9, "Audit Log: Writing %" APR_SIZE_T_FMT " bytes to secondary concurrent index", nbytes);
}
apr_file_write_full(msr->txcfg->auditlog2_fd, text, nbytes, &nbytes_written);
}
}
#endif
/*
* Produce an audit log entry in native format.
*/
void sec_audit_logger_native(modsec_rec *msr) {
assert(msr != NULL);
const apr_array_header_t *arr = NULL;
apr_table_entry_t *te = NULL;
const apr_array_header_t *tarr_pattern = NULL;
const apr_table_entry_t *telts_pattern = NULL;
char *str1 = NULL, *str2 = NULL, *text = NULL;
const msre_rule *rule = NULL, *next_rule = NULL;
apr_size_t nbytes, nbytes_written;
unsigned char md5hash[APR_MD5_DIGESTSIZE];
int was_limited = 0;
int present = 0;
int wrote_response_body = 0;
char *entry_filename, *entry_basename;
apr_status_t rc;
int i, limit, k, sanitized_partial, j;
char *buf = NULL, *pat = NULL;
msc_parm *mparm = NULL;
int arg_min, arg_max, sanitize_matched;
/* the boundary is used by both audit log types */
msr->new_auditlog_boundary = create_auditlog_boundary(msr->r);
/* Return silently if we don't have a request line. This
* means we will not be logging request timeouts.
*/
if (msr->request_line == NULL) {
msr_log(msr, 4, "Audit log: Skipping request whose request_line is null.");
return;
}
/* Also return silently if we don't have a file descriptor. */
if (msr->txcfg->auditlog_fd == NULL) {
msr_log(msr, 4, "Audit log: Skipping request since there is nowhere to write to.");
return;
}
if (msr->txcfg->auditlog_type != AUDITLOG_CONCURRENT) {
/* Serial logging - we already have an open file
* descriptor to write to.
*/
msr->new_auditlog_fd = msr->txcfg->auditlog_fd;
} else {
/* Concurrent logging - we need to create a brand
* new file for this request.
*/
apr_md5_init(&msr->new_auditlog_md5ctx);
msr->new_auditlog_filename = construct_auditlog_filename(msr->mp, msr->txid);
if (msr->new_auditlog_filename == NULL) return;
/* The audit log storage directory should be explicitly
* defined. But if it isn't try to write to the same
* directory where the index file is placed. Of course,
* it is *very* bad practice to allow the Apache user
* to write to the same directory where a root user is
* writing to but it's not us that's causing the problem
* and there isn't anything we can do about that.
*
* ENH Actually there is something we can do! We will make
* SecAuditStorageDir mandatory, ask the user to explicitly
* define the storage location *and* refuse to work if the
* index and the storage location are in the same folder.
*/
if (msr->txcfg->auditlog_storage_dir == NULL) {
entry_filename = file_dirname(msr->mp, msr->txcfg->auditlog_name);
}
else {
entry_filename = msr->txcfg->auditlog_storage_dir;
}
if (entry_filename == NULL) return;
entry_filename = apr_psprintf(msr->mp, "%s%s", entry_filename, msr->new_auditlog_filename);
if (entry_filename == NULL) return;
entry_basename = file_dirname(msr->mp, entry_filename);
if (entry_basename == NULL) return;
/* IMP1 Surely it would be more efficient to check the folders for
* the audit log repository base path in the configuration phase, to reduce
* the work we do on every request. Also, since our path depends on time,
* we could cache the time we last checked and don't check if we know
* the folder is there.
*/
rc = apr_dir_make_recursive(entry_basename, msr->txcfg->auditlog_dirperms, msr->mp);
if ((rc != APR_SUCCESS) && (rc != APR_EEXIST)) {
msr_log(msr, 1, "Audit log: Failed to create subdirectories: %s (%s)",
entry_basename, get_apr_error(msr->mp, rc));
return;
}
rc = apr_file_open(&msr->new_auditlog_fd, entry_filename,
APR_WRITE | APR_TRUNCATE | APR_CREATE | APR_BINARY | APR_FILE_NOCLEANUP,
msr->txcfg->auditlog_fileperms, msr->mp);
if (rc != APR_SUCCESS) {
msr_log(msr, 1, "Audit log: Failed to create file: %s (%s)",
entry_filename, get_apr_error(msr->mp, rc));
return;
}
}
/* Lock the mutex, but only if we are using serial format. */
if (msr->txcfg->auditlog_type != AUDITLOG_CONCURRENT) {
msr_global_mutex_lock(msr, msr->modsecurity->auditlog_lock, "Audit log");
}
/* AUDITLOG_PART_HEADER */
text = apr_psprintf(msr->mp, "--%s-%c--\n", msr->new_auditlog_boundary, AUDITLOG_PART_HEADER);
sec_auditlog_write(msr, text, strlen(text));
/* Format: time transaction_id remote_addr remote_port local_addr local_port */
text = apr_psprintf(msr->mp, "[%s] %s %s %u %s %u",
current_logtime(msr->mp), msr->txid, msr->remote_addr, msr->remote_port,
msr->local_addr, msr->local_port);
sec_auditlog_write(msr, text, strlen(text));
/* AUDITLOG_PART_REQUEST_HEADERS */
if (strchr(msr->txcfg->auditlog_parts, AUDITLOG_PART_REQUEST_HEADERS) != NULL) {
text = apr_psprintf(msr->mp, "\n--%s-%c--\n", msr->new_auditlog_boundary, AUDITLOG_PART_REQUEST_HEADERS);
sec_auditlog_write(msr, text, strlen(text));
sanitize_request_line(msr);
sec_auditlog_write(msr, msr->request_line, strlen(msr->request_line));
sec_auditlog_write(msr, "\n", 1);
arr = apr_table_elts(msr->request_headers);
te = (apr_table_entry_t *)arr->elts;
tarr_pattern = apr_table_elts(msr->pattern_to_sanitize);
telts_pattern = (const apr_table_entry_t*)tarr_pattern->elts;
for (i = 0; i < arr->nelts; i++) {
sanitized_partial = 0;
sanitize_matched = 0;
text = apr_psprintf(msr->mp, "%s: %s\n", te[i].key, te[i].val);
if (apr_table_get(msr->request_headers_to_sanitize, te[i].key) != NULL) {
buf = apr_psprintf(msr->mp, "%s",text+strlen(te[i].key)+2);
for ( k = 0; k < tarr_pattern->nelts; k++) {
if(strncmp(telts_pattern[k].key,te[i].key,strlen(te[i].key)) ==0 ) {
mparm = (msc_parm *)telts_pattern[k].val;
if(mparm->pad_1 == -1)
sanitize_matched = 1;
pat = strstr(buf,mparm->value);
if (pat != NULL) {
j = strlen(mparm->value);
arg_min = j;
arg_max = 1;
while((*pat != '\0')&&(j--)) {
if(arg_max > mparm->pad_2) {
int off = strlen(mparm->value) - arg_max;
int pos = mparm->pad_1-1;
if(off > pos) {
*pat = '*';
}
}
arg_max++;
arg_min--;
pat++;
}
sanitized_partial = 1;
}
}
}
if(sanitized_partial == 1 && sanitize_matched == 0) {
text = apr_psprintf(msr->mp, "%s: %s\n", te[i].key, buf);
} else {
memset(text + strlen(te[i].key) + 2, '*', strlen(te[i].val));
}
}
sec_auditlog_write(msr, text, strlen(text));
}
}
/* AUDITLOG_PART_REQUEST_BODY */
/* Output this part of it was explicitly requested (C) or if it was the faked
* request body that was requested (I) but we have no reason to fake it (it's
* already in the correct format).
*/
if ( (strchr(msr->txcfg->auditlog_parts, AUDITLOG_PART_REQUEST_BODY) != NULL)
|| ( (strchr(msr->txcfg->auditlog_parts, AUDITLOG_PART_FAKE_REQUEST_BODY) != NULL)
&& (msr->mpd == NULL) ) )
{
if (msr->msc_reqbody_read) {
const apr_array_header_t *tarr;
const apr_table_entry_t *telts;
apr_array_header_t *sorted_args;
unsigned int offset = 0, last_offset = 0;
msc_arg *nextarg = NULL;
int sanitize = 0; /* IMP1 Use constants for "sanitize" values. */
char *my_error_msg = NULL;
sorted_args = apr_array_make(msr->mp, 25, sizeof(const msc_arg *));
/* First we need to sort the arguments that need to be
* sanitized in descending order (we are using a stack structure
* to store then so the order will be ascending when we start
* popping them out). This is because we will
* be reading the request body sequentially and must
* sanitize it as we go.
*/
for(;;) {
nextarg = NULL;
/* Find the next largest offset (excluding
* the ones we've used up already).
*/
tarr = apr_table_elts(msr->arguments_to_sanitize);
telts = (const apr_table_entry_t*)tarr->elts;
for(i = 0; i < tarr->nelts; i++) {
msc_arg *arg = (msc_arg *)telts[i].val;
if (arg->origin != NULL &&
( strcmp(arg->origin, "BODY") != 0 && strcmp(arg->origin, "JSON") != 0) )
continue;
if (last_offset == 0) { /* The first time we're here. */
if (arg->value_origin_offset > offset) {
offset = arg->value_origin_offset;
nextarg = arg;
}
} else { /* Not the first time. */
if ((arg->value_origin_offset > offset)
&&(arg->value_origin_offset < last_offset))
{
offset = arg->value_origin_offset;
nextarg = arg;
}
}
}
/* If we don't have the next argument that means
* we're done here.
*/
if (nextarg == NULL) break;
sanitize = 2; /* Means time to pop the next argument out. */
last_offset = offset;
offset = 0;
{ /* IMP1 Fix this ugly bit here. */
msc_arg **x = apr_array_push(sorted_args);
*x = nextarg;
}
}
/* Now start retrieving the body chunk by chunk and
* sanitize data in pieces.
*/
rc = modsecurity_request_body_retrieve_start(msr, &my_error_msg);
if (rc < 0) {
msr_log(msr, 1, "Audit log: %s", my_error_msg);
} else {
msc_data_chunk *chunk = NULL;
unsigned int chunk_offset = 0;
unsigned int sanitize_offset = 0;
unsigned int sanitize_length = 0;
text = apr_psprintf(msr->mp, "\n--%s-%c--\n", msr->new_auditlog_boundary, AUDITLOG_PART_REQUEST_BODY);
sec_auditlog_write(msr, text, strlen(text));
for(;;) {
rc = modsecurity_request_body_retrieve(msr, &chunk, -1, &my_error_msg);
if (chunk != NULL) {
/* Anything greater than 1 means we have more data to sanitize. */
while (sanitize > 1) {
msc_arg **arg = NULL;
if (sanitize == 2) {
/* Get the next argument from the stack. */
arg = (msc_arg **)apr_array_pop(sorted_args);
if (arg == NULL) sanitize = 0; /* We're done sanitising. */
else {
/* Continue with sanitation to process the
* retrieved argument.
*/
sanitize = 1;
sanitize_offset = (*arg)->value_origin_offset;
sanitize_length = (*arg)->value_origin_len;
}
}
if (sanitize) {
/* Check if the data we want to sanitize is
* stored in the current chunk.
*/
if (chunk_offset + chunk->length > sanitize_offset) {
unsigned int soff; /* data offset within chunk */
unsigned int len; /* amount in this chunk to sanitize */
soff = sanitize_offset - chunk_offset;
if (soff + sanitize_length <= chunk->length) {
/* The entire argument resides in the current chunk. */
len = sanitize_length;
sanitize = 2; /* Get another parameter to sanitize. */
} else {
/* Some work to do here but we'll need to seek
* another chunk.
*/
len = chunk->length - soff;
sanitize_offset += len;
sanitize_length -= len;
sanitize = 1; /* It's OK to go to the next chunk. */
}
/* Yes, we actually write over the original data.
* We shouldn't be needing it any more.
*/
if (soff + len <= chunk->length) { /* double check */
memset((char *)chunk->data + soff, '*', len);
}
}
}
}
/* Write the sanitized chunk to the log
* and advance to the next chunk. */
sec_auditlog_write(msr, chunk->data, chunk->length);
chunk_offset += chunk->length;
}
if (rc <= 0) {
break;
}
}
if (rc < 0) {
msr_log(msr, 1, "Audit log: %s", my_error_msg);
}
modsecurity_request_body_retrieve_end(msr);
}
}
}
/* AUDITLOG_PART_FAKE_REQUEST_BODY */
if (strchr(msr->txcfg->auditlog_parts, AUDITLOG_PART_FAKE_REQUEST_BODY) != NULL) {
if ((msr->msc_reqbody_read)&&(msr->mpd != NULL)) {
char *buffer = NULL;
buffer = multipart_reconstruct_urlencoded_body_sanitize(msr);
if (buffer == NULL) {
msr_log(msr, 1, "Audit log: Failed to reconstruct request body.");
} else {
text = apr_psprintf(msr->mp, "\n--%s-%c--\n", msr->new_auditlog_boundary, AUDITLOG_PART_FAKE_REQUEST_BODY);
sec_auditlog_write(msr, text, strlen(text));
sec_auditlog_write(msr, buffer, strlen(buffer));
}
}
}
/* AUDITLOG_PART_A_RESPONSE_HEADERS */
if (strchr(msr->txcfg->auditlog_parts, AUDITLOG_PART_A_RESPONSE_HEADERS) != NULL) {
text = apr_psprintf(msr->mp, "\n--%s-%c--\n", msr->new_auditlog_boundary, AUDITLOG_PART_A_RESPONSE_HEADERS);
sec_auditlog_write(msr, text, strlen(text));
/* There are no response headers (or the status line) in HTTP 0.9 */
if (msr->response_headers_sent) {
if (msr->status_line != NULL && msr->status_line[0] != '\0') {
text = apr_psprintf(msr->mp, "%s %s\n", msr->response_protocol,
msr->status_line);
} else {
text = apr_psprintf(msr->mp, "%s %u\n", msr->response_protocol,
msr->response_status);
}
sec_auditlog_write(msr, text, strlen(text));
/* Output headers */
arr = apr_table_elts(msr->response_headers);
te = (apr_table_entry_t *)arr->elts;
tarr_pattern = apr_table_elts(msr->pattern_to_sanitize);
telts_pattern = (const apr_table_entry_t*)tarr_pattern->elts;
for (i = 0; i < arr->nelts; i++) {
sanitized_partial = 0;
sanitize_matched = 0;
text = apr_psprintf(msr->mp, "%s: %s\n", te[i].key, te[i].val);
if (apr_table_get(msr->response_headers_to_sanitize, te[i].key) != NULL) {
buf = apr_psprintf(msr->mp, "%s",text+strlen(te[i].key)+2);
for ( k = 0; k < tarr_pattern->nelts; k++) {
if(strncmp(telts_pattern[k].key,te[i].key,strlen(te[i].key)) ==0 ) {
mparm = (msc_parm *)telts_pattern[k].val;
if(mparm->pad_1 == -1)
sanitize_matched = 1;
pat = strstr(buf,mparm->value);
if (pat != NULL) {
j = strlen(mparm->value);
arg_min = j;
arg_max = 1;
while((*pat != '\0')&&(j--)) {
if(arg_max > mparm->pad_2) {
int off = strlen(mparm->value) - arg_max;
int pos = mparm->pad_1-1;
if(off > pos) {
*pat = '*';
}
}
arg_max++;
arg_min--;
pat++;
}
sanitized_partial = 1;
}
}
}
if(sanitized_partial == 1 && sanitize_matched == 0) {
text = apr_psprintf(msr->mp, "%s: %s\n", te[i].key, buf);
} else {
memset(text + strlen(te[i].key) + 2, '*', strlen(te[i].val));
}
}
sec_auditlog_write(msr, text, strlen(text));
}
}
}
apr_table_clear(msr->pattern_to_sanitize);
/* AUDITLOG_PART_RESPONSE_BODY */
if (strchr(msr->txcfg->auditlog_parts, AUDITLOG_PART_RESPONSE_BODY) != NULL) {
if (msr->resbody_data != NULL) {
text = apr_psprintf(msr->mp, "\n--%s-%c--\n", msr->new_auditlog_boundary, AUDITLOG_PART_RESPONSE_BODY);
sec_auditlog_write(msr, text, strlen(text));
sec_auditlog_write(msr, msr->resbody_data, msr->resbody_length);
wrote_response_body = 1;
}
}
/* AUDITLOG_PART_TRAILER */
if (strchr(msr->txcfg->auditlog_parts, AUDITLOG_PART_TRAILER) != NULL) {
apr_time_t now = apr_time_now();
text = apr_psprintf(msr->mp, "\n--%s-%c--\n", msr->new_auditlog_boundary, AUDITLOG_PART_TRAILER);
sec_auditlog_write(msr, text, strlen(text));
/* Messages */
for(i = 0; i < msr->alerts->nelts; i++) {
text = apr_psprintf(msr->mp, "Message: %s\n", ((char **)msr->alerts->elts)[i]);
sec_auditlog_write(msr, text, strlen(text));
}
/* Apache error messages */
for(i = 0; i < msr->error_messages->nelts; i++) {
error_message_t *em = (((error_message_t **)msr->error_messages->elts)[i]);
text = apr_psprintf(msr->mp, "Apache-Error: %s\n",
format_error_log_message(msr->mp, em));
sec_auditlog_write(msr, text, strlen(text));
}
/* Action */
if (msr->was_intercepted) {
text = apr_psprintf(msr->mp, "Action: Intercepted (phase %d)\n", msr->intercept_phase);
sec_auditlog_write(msr, text, strlen(text));
}
/* Apache-Handler */
#ifdef LOG_NO_HANDLER
if (msr->txcfg->debuglog_level >= 9)
#endif
if (msr->r->handler != NULL) {
text = apr_psprintf(msr->mp, "Apache-Handler: %s\n", msr->r->handler);
sec_auditlog_write(msr, text, strlen(text));
}
/* Stopwatch; left in for compatibility reasons */
#ifdef LOG_NO_STOPWATCH
if (msr->txcfg->debuglog_level >= 9) {
#endif
text = apr_psprintf(msr->mp, "Stopwatch: %" APR_TIME_T_FMT " %" APR_TIME_T_FMT " (- - -)\n",
msr->request_time, (now - msr->request_time));
sec_auditlog_write(msr, text, strlen(text));
/* Stopwatch2 */
{
char *perf_all = format_all_performance_variables(msr, msr->mp);
text = apr_psprintf(msr->mp, "Stopwatch2: %" APR_TIME_T_FMT " %" APR_TIME_T_FMT
"; %s\n", msr->request_time, (now - msr->request_time), perf_all);
sec_auditlog_write(msr, text, strlen(text));
}
#ifdef LOG_NO_STOPWATCH
}
#endif
/* Our response body does not contain chunks */
/* ENH Only write this when the output was chunked. */
/* ENH Add info when request body was decompressed, dechunked too. */
#ifdef LOG_NO_DECHUNK
if (msr->txcfg->debuglog_level >= 9)
#endif
if (wrote_response_body) {
text = apr_psprintf(msr->mp, "Response-Body-Transformed: Dechunked\n");
sec_auditlog_write(msr, text, strlen(text));
}
#ifdef LOG_NO_SERVER_CONTEXT
if (msr->txcfg->debuglog_level >= 9) {
#endif
sec_auditlog_write_producer_header(msr);
/* Server */
if (msr->server_software != NULL) {
text = apr_psprintf(msr->mp, "Server: %s\n", msr->server_software);
sec_auditlog_write(msr, text, strlen(text));
}
/* Sanitised arguments */
{
const apr_array_header_t *tarr;
const apr_table_entry_t *telts;
tarr = apr_table_elts(msr->arguments_to_sanitize);
telts = (const apr_table_entry_t*)tarr->elts;
if (tarr->nelts > 0) {
text = apr_psprintf(msr->mp, "Sanitised-Args: ");
sec_auditlog_write(msr, text, strlen(text));
}
for(i = 0; i < tarr->nelts; i++) {
msc_arg *arg = (msc_arg *)telts[i].val;
text = apr_psprintf(msr->mp, "%s\"%s\"%s", ((i == 0) ? "" : ", "),
log_escape(msr->mp, arg->name), ((i == (tarr->nelts - 1)) ? ".\n" : ""));
sec_auditlog_write(msr, text, strlen(text));
}
}
/* Sanitised request headers */
{
const apr_array_header_t *tarr;
const apr_table_entry_t *telts;
tarr = apr_table_elts(msr->request_headers_to_sanitize);
telts = (const apr_table_entry_t*)tarr->elts;
if (tarr->nelts > 0) {
text = apr_psprintf(msr->mp, "Sanitised-Request-Headers: ");
sec_auditlog_write(msr, text, strlen(text));
}
for(i = 0; i < tarr->nelts; i++) {
text = apr_psprintf(msr->mp, "%s\"%s\"%s", ((i == 0) ? "" : ", "),
log_escape(msr->mp, telts[i].key), ((i == (tarr->nelts - 1)) ? ".\n" : ""));
sec_auditlog_write(msr, text, strlen(text));
}
}
/* Sanitised response headers */
{
const apr_array_header_t *tarr;
const apr_table_entry_t *telts;
tarr = apr_table_elts(msr->response_headers_to_sanitize);
telts = (const apr_table_entry_t*)tarr->elts;
if (tarr->nelts > 0) {
text = apr_psprintf(msr->mp, "Sanitised-Response-Headers: ");
sec_auditlog_write(msr, text, strlen(text));
}
for(i = 0; i < tarr->nelts; i++) {
text = apr_psprintf(msr->mp, "%s\"%s\"%s", ((i == 0) ? "" : ", "),
log_escape(msr->mp, telts[i].key), ((i == (tarr->nelts - 1)) ? ".\n" : ""));
sec_auditlog_write(msr, text, strlen(text));
}
}
#ifdef LOG_NO_SERVER_CONTEXT
}
#endif
/* Web application info. */
if ( ((msr->txcfg->webappid != NULL)&&(strcmp(msr->txcfg->webappid, "default") != 0))
|| (msr->sessionid != NULL) || (msr->userid != NULL))
{
text = apr_psprintf(msr->mp, "WebApp-Info: \"%s\" \"%s\" \"%s\"\n",
msr->txcfg->webappid == NULL ? "-" : log_escape(msr->mp, msr->txcfg->webappid),
msr->sessionid == NULL ? "-" : log_escape(msr->mp, msr->sessionid),
msr->userid == NULL ? "-" : log_escape(msr->mp, msr->userid));
sec_auditlog_write(msr, text, strlen(text));
}
if ( ((msr->txcfg->sensor_id != NULL)&&(strcmp(msr->txcfg->sensor_id, "default") != 0)))
{
text = apr_psprintf(msr->mp, "Sensor-Id: \"%s\"\n",
msr->txcfg->sensor_id == NULL ? "-" : log_escape(msr->mp, msr->txcfg->sensor_id)),
sec_auditlog_write(msr, text, strlen(text));
}
if (msr->txcfg->is_enabled > 0) {
text = apr_psprintf(msr->mp, "Engine-Mode: \"%s\"\n",
msr->txcfg->is_enabled == 1 ? "DETECTION_ONLY" : "ENABLED"),
sec_auditlog_write(msr, text, strlen(text));
}
/* Rule performance time */
if(msr->txcfg->max_rule_time > 0) {
const apr_array_header_t *tarr;
const apr_table_entry_t *telts;
tarr = apr_table_elts(msr->perf_rules);
telts = (const apr_table_entry_t*)tarr->elts;
if (tarr->nelts > 0) {
text = apr_psprintf(msr->mp, "Rules-Performance-Info: ");
sec_auditlog_write(msr, text, strlen(text));
}
for(i = 0; i < tarr->nelts; i++) {
text = apr_psprintf(msr->mp, "%s\"%s=%s\"%s", ((i == 0) ? "" : ", "),
log_escape(msr->mp, telts[i].key), log_escape(msr->mp, telts[i].val), ((i == (tarr->nelts - 1)) ? ".\n" : ""));
sec_auditlog_write(msr, text, strlen(text));
}
}
}
/* AUDITLOG_PART_UPLOADS */
if ((strchr(msr->txcfg->auditlog_parts, AUDITLOG_PART_UPLOADS) != NULL) && (msr->mpd != NULL)) {
multipart_part **parts = NULL;
unsigned int total_size = 0;
int cfiles = 0;
text = apr_psprintf(msr->mp, "\n--%s-%c--\n", msr->new_auditlog_boundary, AUDITLOG_PART_UPLOADS);
sec_auditlog_write(msr, text, strlen(text));
parts = (multipart_part **)msr->mpd->parts->elts;
for(cfiles = 0; cfiles < msr->mpd->parts->nelts; cfiles++) {
if (parts[cfiles]->type == MULTIPART_FILE) {
if(parts[cfiles]->filename != NULL) {
text = apr_psprintf(msr->mp, "%d,%u,\"%s\",\"%s\"\n", cfiles+1, parts[cfiles]->tmp_file_size, log_escape(msr->mp, parts[cfiles]->filename), log_escape(msr->mp, parts[cfiles]->content_type ? parts[cfiles]->content_type : "<Unknown ContentType>"));
sec_auditlog_write(msr, text, strlen(text));
total_size += parts[cfiles]->tmp_file_size;
}
}
}
text = apr_psprintf(msr->mp, "Total,%u\n", total_size);
sec_auditlog_write(msr, text, strlen(text));
}
/* AUDITLOG_PART_MATCHEDRULES */
if (strchr(msr->txcfg->auditlog_parts, AUDITLOG_PART_MATCHEDRULES) != NULL) {
text = apr_psprintf(msr->mp, "\n--%s-%c--\n", msr->new_auditlog_boundary, AUDITLOG_PART_MATCHEDRULES);
sec_auditlog_write(msr, text, strlen(text));
/* Matched Rules */
for(i = 0; i < msr->matched_rules->nelts; i++) {
rule = ((msre_rule **)msr->matched_rules->elts)[i];
if ((rule != NULL) && (rule->actionset != NULL) && rule->actionset->is_chained && (rule->chain_starter == NULL)) {
text = apr_psprintf(msr->mp, "%s\n", rule->unparsed);
sec_auditlog_write(msr, text, strlen(text));
do {
if (rule->ruleset != NULL) {
next_rule = return_chained_rule(rule,msr);
if (next_rule != NULL) {
present = chained_is_matched(msr,next_rule);
if (present == 0) {
text = apr_psprintf(msr->mp, "#%s\n",next_rule->unparsed);
} else {
text = apr_psprintf(msr->mp, "%s\n",next_rule->unparsed);
i++;
}
sec_auditlog_write(msr, text, strlen(text));
}
}
rule = next_rule;
} while (rule != NULL && rule->actionset != NULL && rule->actionset->is_chained);
text = apr_psprintf(msr->mp, "\n");
sec_auditlog_write(msr, text, strlen(text));
} else {
if ((rule != NULL) && (rule->actionset != NULL) && !rule->actionset->is_chained && (rule->chain_starter == NULL)) {
text = apr_psprintf(msr->mp, "%s\n", rule->unparsed);
sec_auditlog_write(msr, text, strlen(text));
}
}
}
}
/* AUDITLOG_PART_ENDMARKER */
text = apr_psprintf(msr->mp, "\n--%s-%c--\n", msr->new_auditlog_boundary, AUDITLOG_PART_ENDMARKER);
sec_auditlog_write(msr, text, strlen(text));
/* Return here if we were writing to a serial log
* as it does not need an index file.
*/
if (msr->txcfg->auditlog_type != AUDITLOG_CONCURRENT) {
sec_auditlog_write(msr, "\n", 1);
/* Unlock the mutex we used to serialise access to the audit log file. */
msr_global_mutex_unlock(msr, msr->modsecurity->auditlog_lock, "Audit log");
return;
}
/* From here on only concurrent-style processing. */
/* File handle might already be closed after write failure. */
if (msr->new_auditlog_fd) {
apr_file_close(msr->new_auditlog_fd);
}
/* Write an entry to the index file */
/* Calculate hash of the entry. */
apr_md5_final(md5hash, &msr->new_auditlog_md5ctx);
str2 = apr_psprintf(msr->mp, "%s %d %d md5:%s", msr->new_auditlog_filename, 0,
msr->new_auditlog_size, bytes2hex(msr->mp, md5hash, 16));
if (str2 == NULL) return;
/* We do not want the index line to be longer than 3980 bytes. */
limit = 3980;
was_limited = 0;
/* If we are logging to a pipe we need to observe and
* obey the pipe atomic write limit - PIPE_BUF. For
* more details see the discussion in sec_guardian_logger code.
*/
if (msr->txcfg->auditlog_name[0] == '|') {
if (PIPE_BUF < limit) {
limit = PIPE_BUF;
}
}
limit = limit - strlen(str2) - 5;
if (limit <= 0) {
msr_log(msr, 1, "Audit Log: Atomic PIPE write buffer too small: %d", PIPE_BUF);
return;
}
str1 = construct_log_vcombinedus_limited(msr, limit, &was_limited);
if (str1 == NULL) return;
if (was_limited == 0) {
text = apr_psprintf(msr->mp, "%s %s \n", str1, str2);
} else {
text = apr_psprintf(msr->mp, "%s %s L\n", str1, str2);
}
if (text == NULL) return;
nbytes = strlen(text);
if (msr->txcfg->debuglog_level >= 9) {
msr_log(msr, 9, "Audit Log: Writing %" APR_SIZE_T_FMT " bytes to primary concurrent index", nbytes);
}
apr_file_write_full(msr->txcfg->auditlog_fd, text, nbytes, &nbytes_written);
/* Write to the secondary audit log if we have one */
if (msr->txcfg->auditlog2_fd != NULL) {
if (msr->txcfg->debuglog_level >= 9) {
msr_log(msr, 9, "Audit Log: Writing %" APR_SIZE_T_FMT " bytes to secondary concurrent index", nbytes);
}
apr_file_write_full(msr->txcfg->auditlog2_fd, text, nbytes, &nbytes_written);
}
}
/*
* Handler for audit log writers.
*/
void sec_audit_logger(modsec_rec *msr) {
#ifdef WITH_YAJL
assert(msr != NULL);
if (msr->txcfg->auditlog_format == AUDITLOGFORMAT_JSON) {
sec_audit_logger_json(msr);
} else {
#endif
sec_audit_logger_native(msr);
#ifdef WITH_YAJL
}
#endif
}
static int open_audit_log(char *auditlog_name, unsigned char primary, apr_file_t **auditlog_fd,
apr_fileperms_t *auditlog_fileperms, apr_pool_t *p) {
if (auditlog_name == NOT_SET_P) {
return OK;
}
if (auditlog_name[0] == '|') {
const char *pipe_name = auditlog_name + 1;
piped_log *pipe_log;
pipe_log = ap_open_piped_log(p, pipe_name);
if (pipe_log == NULL) {
ap_log_error(APLOG_MARK, APLOG_ERR, 0, NULL,
"ModSecurity: Failed to open the %saudit log pipe: %s",
primary ? "" : "secondary ", pipe_name);
return primary ? DONE : OK;
}
*auditlog_fd = ap_piped_log_write_fd(pipe_log);
}
else {
const char *file_name = ap_server_root_relative(p, auditlog_name);
apr_status_t rc;
if (*auditlog_fileperms == NOT_SET) {
*auditlog_fileperms = CREATEMODE;
}
rc = apr_file_open(auditlog_fd, file_name,
APR_WRITE | APR_APPEND | APR_CREATE | APR_BINARY,
*auditlog_fileperms, p);
if (rc != APR_SUCCESS) {
ap_log_error(APLOG_MARK, APLOG_ERR, 0, NULL,
"ModSecurity: Failed to open the %saudit log file: %s",
primary ? "" : "secondary ", file_name);
return primary ? DONE : OK;
}
}
return OK;
}
int modsec_open_logs(apr_pool_t *pconf, apr_pool_t *p, apr_pool_t *ptemp, server_rec *s_main) {
directory_config *dcfg = ap_get_module_config(s_main->lookup_defaults, &security2_module);
int primary_log_rc = open_audit_log(dcfg->auditlog_name, 1,
&dcfg->auditlog_fd, &dcfg->auditlog_fileperms, p);
if (primary_log_rc != OK) {
return primary_log_rc;
}
return open_audit_log(dcfg->auditlog2_name, 0,
&dcfg->auditlog2_fd, &dcfg->auditlog_fileperms, p);
}
Reference in New Issue View Git Blame Copy Permalink