2 * ModSecurity for Apache 2.x, http://www.modsecurity.org/
3 * Copyright (c) 2004-2009 Breach Security, Inc. (http://www.breach.com/)
5 * This product is released under the terms of the General Public Licence,
6 * version 2 (GPLv2). Please refer to the file LICENSE (included with this
7 * distribution) which contains the complete text of the licence.
9 * There are special exceptions to the terms and conditions of the GPL
10 * as it is applied to this software. View the full text of the exception in
11 * file MODSECURITY_LICENSING_EXCEPTION in the directory of this software
14 * If any of the files related to licensing are missing or if you have any
15 * other questions related to licensing please contact Breach Security, Inc.
16 * directly using the email address support@breach.com.
21 #include "mod_security2_config.h"
23 #include "msc_logging.h"
25 #include "apr_strings.h"
26 #include "apr_global_mutex.h"
31 * Write the supplied data to the audit log (if the FD is ready), update
32 * the size counters, update the hash context.
34 static int sec_auditlog_write(modsec_rec *msr, const char *data, unsigned int len) {
35 apr_size_t nbytes_written, nbytes = len;
38 /* Do nothing if there's no data. */
39 if (data == NULL) return -1;
41 /* Update size counters and the hash calculation. We always do this,
42 * even in cases where write fails. That will make it easier to detect
43 * problems with partial writes.
45 msr->new_auditlog_size += len;
46 apr_md5_update(&msr->new_auditlog_md5ctx, data, len);
48 /* Do not write if we do not have a file descriptor. */
49 if (msr->new_auditlog_fd == NULL) return -1;
51 /* Write data to file. */
52 rc = apr_file_write_full(msr->new_auditlog_fd, data, nbytes, &nbytes_written);
53 if (rc != APR_SUCCESS) {
54 msr_log(msr, 1, "Audit log: Failed writing (requested %" APR_SIZE_T_FMT
55 " bytes, written %" APR_SIZE_T_FMT ")", nbytes, nbytes_written);
57 /* Set to NULL to prevent more than one error message on
58 * out-of-disk-space events and to prevent further attempts
59 * to write to the same file in this request.
61 * Note that, as we opened the file through the pool mechanism of
62 * the APR, we do not need to close the file here. It will be closed
63 * automatically at the end of the request.
65 msr->new_auditlog_fd = NULL;
74 * Construct a log line in the vcombinedus format (see below).
76 char *construct_log_vcombinedus(modsec_rec *msr) {
77 const char *local_user, *remote_user;
78 const char *referer, *user_agent, *uniqueid;
79 const char *sessionid;
82 if (msr->remote_user == NULL) remote_user = "-";
83 else remote_user = msr->remote_user;
85 /* authenticated user */
86 if (msr->local_user == NULL) local_user = "-";
87 else local_user = msr->local_user;
91 if (uniqueid == NULL) uniqueid = "-";
95 /* Logging Referer is a waste of space.
96 referer = (char *)apr_table_get(msr->request_headers, "Referer");
97 if (referer == NULL) referer = "-";
102 /* Logging User-Agent is a waste of space too.
103 user_agent = (char *)apr_table_get(msr->request_headers, "User-Agent");
104 if (user_agent == NULL) user_agent = "-";
108 sessionid = (msr->sessionid == NULL ? "-" : msr->sessionid);
110 return apr_psprintf(msr->mp, "%s %s %s %s [%s] \"%s\" %u %" APR_OFF_T_FMT " \"%s\" \"%s\" %s \"%s\"",
111 log_escape_nq(msr->mp, msr->hostname), msr->remote_addr, log_escape_nq(msr->mp, remote_user),
112 log_escape_nq(msr->mp, local_user), current_logtime(msr->mp),
113 ((msr->request_line == NULL) ? "" : log_escape(msr->mp, msr->request_line)),
114 msr->response_status, msr->bytes_sent, log_escape(msr->mp, referer),
115 log_escape(msr->mp, user_agent), log_escape(msr->mp, uniqueid), sessionid);
119 * Constructs a log line in vcombined log format trying to truncate
120 * some of the fields to make the log line shorter than _limit bytes.
122 char *construct_log_vcombinedus_limited(modsec_rec *msr, int _limit, int *was_limited) {
124 char *local_user, *remote_user;
125 char *referer, *user_agent, *uniqueid;
126 const char *sessionid;
127 char *the_request, *bytes_sent;
131 hostname = (msr->hostname == NULL ? "-" : log_escape_nq(msr->mp, msr->hostname));
133 /* remote log name */
134 if (msr->remote_user == NULL) remote_user = "-";
135 else remote_user = log_escape_nq(msr->mp, msr->remote_user);
137 /* authenticated user */
138 if (msr->local_user == NULL) local_user = "-";
139 else local_user = log_escape_nq(msr->mp, msr->local_user);
142 if (msr->txid == NULL) uniqueid = "-";
143 else uniqueid = log_escape(msr->mp, msr->txid);
148 referer = (char *)apr_table_get(msr->request_headers, "Referer");
149 if (referer == NULL) referer = "-";
150 else referer = log_escape(msr->mp, referer);
156 user_agent = (char *)apr_table_get(msr->request_headers, "User-Agent");
157 if (user_agent == NULL) user_agent = "-";
158 else user_agent = log_escape(msr->mp, user_agent);
162 sessionid = (msr->sessionid == NULL) ? "-" : log_escape(msr->mp, msr->sessionid);
164 the_request = (msr->request_line == NULL) ? "" : log_escape(msr->mp, msr->request_line);
166 bytes_sent = apr_psprintf(msr->mp, "%" APR_OFF_T_FMT, msr->bytes_sent);
168 /* first take away the size of the
169 * information we must log
171 limit -= 22; /* spaces and double quotes */
172 limit -= strlen(hostname); /* server name or IP */
173 limit -= strlen(msr->remote_addr); /* remote IP */
174 limit -= 28; /* current_logtime */
175 limit -= 3; /* status */
176 limit -= strlen(bytes_sent); /* bytes sent */
177 limit -= strlen(uniqueid); /* unique id */
178 limit -= strlen(sessionid); /* session id */
181 msr_log(msr, 1, "GuardianLog: Atomic pipe write size too small: %d", PIPE_BUF);
185 /* we hope to be able to squeeze everything in */
186 if (limit < (int)(strlen(remote_user) + strlen(local_user) + strlen(referer)
187 + strlen(user_agent) + strlen(the_request)))
189 /* Boo hoo hoo, there's not enough space available. */
192 /* Let's see if we can reduce the size of something. This
193 * is a very crude approach but it seems to work for our
196 if (strlen(remote_user) > 32) {
197 msr_log(msr, 9, "GuardianLog: Reduced remote_user to 32.");
198 remote_user[32] = '\0';
200 limit -= strlen(remote_user);
202 if (strlen(local_user) > 32) {
203 msr_log(msr, 9, "GuardianLog: Reduced local_user to 32.");
204 local_user[32] = '\0';
206 limit -= strlen(local_user);
208 if (strlen(referer) > 64) {
209 msr_log(msr, 9, "GuardianLog: Reduced referer to 64.");
212 limit -= strlen(referer);
214 if (strlen(user_agent) > 64) {
215 msr_log(msr, 9, "GuardianLog: Reduced user_agent to 64.");
216 user_agent[64] = '\0';
218 limit -= strlen(user_agent);
221 msr_log(msr, 1, "GuardianLog: Atomic pipe write size too small: %d.", PIPE_BUF);
225 /* use what's left for the request line */
226 if ((int)strlen(the_request) > limit) {
227 the_request[limit] = '\0';
228 msr_log(msr, 9, "GuardianLog: Reduced the_request to %d bytes.", limit);
231 /* Yay! We have enough space! */
235 return apr_psprintf(msr->mp, "%s %s %s %s [%s] \"%s\" %u %s \"%s\" \"%s\" %s \"%s\"",
236 hostname, msr->remote_addr, remote_user,
237 local_user, current_logtime(msr->mp), the_request,
238 msr->response_status, bytes_sent, referer, user_agent,
244 * Checks if the provided string is a valid audit log parts specification.
246 int is_valid_parts_specification(char *p) {
249 while((c = *(t++)) != '\0') {
250 if ((c != AUDITLOG_PART_ENDMARKER)&&((c < AUDITLOG_PART_FIRST)||(c > AUDITLOG_PART_LAST))) {
259 * Constructs a filename that will be used to store an
262 static char *construct_auditlog_filename(apr_pool_t *mp, const char *uniqueid) {
267 apr_time_exp_lt(&t, apr_time_now());
269 apr_strftime(tstr, &len, 299, "/%Y%m%d/%Y%m%d-%H%M/%Y%m%d-%H%M%S", &t);
270 return apr_psprintf(mp, "%s-%s", tstr, uniqueid);
274 * Creates a random 8-character string that
275 * consists of hexadecimal numbers, to be used
276 * as an audit log boundary.
278 static char *create_auditlog_boundary(request_rec *r) {
279 unsigned long data = rand();
280 /* Do note that I tried using apr_generate_random_bytes but it turned
281 * out to be terribly slow for some reason. Needs further investigation.
283 return bytes2hex(r->pool, (void *)&data, 4);
287 * Sanitises the request line by removing the parameters
288 * that have been marked as sensitive.
290 static void sanitise_request_line(modsec_rec *msr) {
291 const apr_array_header_t *tarr;
292 const apr_table_entry_t *telts;
296 /* Locate the query string. */
297 qspos = strstr(msr->request_line, "?");
298 if (qspos == NULL) return;
301 /* Loop through the list of sensitive parameters. */
302 tarr = apr_table_elts(msr->arguments_to_sanitise);
303 telts = (const apr_table_entry_t*)tarr->elts;
304 for (i = 0; i < tarr->nelts; i++) {
305 msc_arg *arg = (msc_arg *)telts[i].val;
306 /* Only look at the parameters that appeared in the query string. */
307 if (strcmp(arg->origin, "QUERY_STRING") == 0) {
311 /* Go to the beginning of the parameter. */
313 j = arg->value_origin_offset;
314 while((*p != '\0')&&(j--)) p++;
316 msr_log(msr, 1, "Unable to sanitise variable \"%s\" at offset %u of QUERY_STRING"
317 "because the request line is too short.",
318 log_escape_ex(msr->mp, arg->name, arg->name_len),
319 arg->value_origin_offset);
323 /* Write over the value. */
324 j = arg->value_origin_len;
325 while((*p != '\0')&&(j--)) {
329 msr_log(msr, 1, "Unable to sanitise variable \"%s\" at offset %u (size %d) "
330 "of QUERY_STRING because the request line is too short.",
331 log_escape_ex(msr->mp, arg->name, arg->name_len),
332 arg->value_origin_offset, arg->value_origin_len);
340 * Output the Producer header.
342 static void sec_auditlog_write_producer_header(modsec_rec *msr) {
343 char **signatures = NULL;
347 /* Try to write everything in one go. */
348 if (msr->txcfg->component_signatures->nelts == 0) {
349 text = apr_psprintf(msr->mp, "Producer: %s.\n", MODSEC_MODULE_NAME_FULL);
350 sec_auditlog_write(msr, text, strlen(text));
355 /* Start with the ModSecurity signature. */
356 text = apr_psprintf(msr->mp, "Producer: %s", MODSEC_MODULE_NAME_FULL);
357 sec_auditlog_write(msr, text, strlen(text));
360 /* Then loop through the components and output individual signatures. */
361 signatures = (char **)msr->txcfg->component_signatures->elts;
362 for(i = 0; i < msr->txcfg->component_signatures->nelts; i++) {
363 text = apr_psprintf(msr->mp, "; %s", (char *)signatures[i]);
364 sec_auditlog_write(msr, text, strlen(text));
367 sec_auditlog_write(msr, ".\n", 2);
371 * Produce an audit log entry.
373 void sec_audit_logger(modsec_rec *msr) {
374 const apr_array_header_t *arr = NULL;
375 apr_table_entry_t *te = NULL;
376 char *str1 = NULL, *str2 = NULL, *text = NULL;
377 const msre_rule *rule = NULL;
378 apr_size_t nbytes, nbytes_written;
379 unsigned char md5hash[APR_MD5_DIGESTSIZE];
381 int wrote_response_body = 0;
382 char *entry_filename, *entry_basename;
386 /* the boundary is used by both audit log types */
387 msr->new_auditlog_boundary = create_auditlog_boundary(msr->r);
389 /* Return silently if we don't have a request line. This
390 * means we will not be logging request timeouts.
392 if (msr->request_line == NULL) {
393 msr_log(msr, 4, "Audit log: Skipping request whose request_line is null.");
397 /* Also return silently if we don't have a file descriptor. */
398 if (msr->txcfg->auditlog_fd == NULL) {
399 msr_log(msr, 4, "Audit log: Skipping request since there is nowhere to write to.");
403 if (msr->txcfg->auditlog_type != AUDITLOG_CONCURRENT) {
404 /* Serial logging - we already have an open file
405 * descriptor to write to.
407 msr->new_auditlog_fd = msr->txcfg->auditlog_fd;
409 /* Concurrent logging - we need to create a brand
410 * new file for this request.
412 apr_md5_init(&msr->new_auditlog_md5ctx);
414 msr->new_auditlog_filename = construct_auditlog_filename(msr->mp, msr->txid);
415 if (msr->new_auditlog_filename == NULL) return;
417 /* The audit log storage directory should be explicitly
418 * defined. But if it isn't try to write to the same
419 * directory where the index file is placed. Of course,
420 * it is *very* bad practice to allow the Apache user
421 * to write to the same directory where a root user is
422 * writing to but it's not us that's causing the problem
423 * and there isn't anything we can do about that.
425 * ENH Actually there is something we can do! We will make
426 * SecAuditStorageDir mandatory, ask the user to explicitly
427 * define the storage location *and* refuse to work if the
428 * index and the storage location are in the same folder.
430 if (msr->txcfg->auditlog_storage_dir == NULL) {
431 entry_filename = file_dirname(msr->mp, msr->txcfg->auditlog_name);
434 entry_filename = msr->txcfg->auditlog_storage_dir;
436 if (entry_filename == NULL) return;
438 entry_filename = apr_psprintf(msr->mp, "%s%s", entry_filename, msr->new_auditlog_filename);
439 if (entry_filename == NULL) return;
440 entry_basename = file_dirname(msr->mp, entry_filename);
441 if (entry_basename == NULL) return;
443 /* IMP1 Surely it would be more efficient to check the folders for
444 * the audit log repository base path in the configuration phase, to reduce
445 * the work we do on every request. Also, since our path depends on time,
446 * we could cache the time we last checked and don't check if we know
447 * the folder is there.
449 rc = apr_dir_make_recursive(entry_basename, msr->txcfg->auditlog_dirperms, msr->mp);
450 if (rc != APR_SUCCESS) {
451 msr_log(msr, 1, "Audit log: Failed to create subdirectories: %s (%s)",
452 entry_basename, get_apr_error(msr->mp, rc));
456 rc = apr_file_open(&msr->new_auditlog_fd, entry_filename,
457 APR_WRITE | APR_TRUNCATE | APR_CREATE | APR_BINARY | APR_FILE_NOCLEANUP,
458 msr->txcfg->auditlog_fileperms, msr->mp);
459 if (rc != APR_SUCCESS) {
460 msr_log(msr, 1, "Audit log: Failed to create file: %s (%s)",
461 entry_filename, get_apr_error(msr->mp, rc));
466 /* Lock the mutex, but only if we are using serial format. */
467 if (msr->txcfg->auditlog_type != AUDITLOG_CONCURRENT) {
468 rc = apr_global_mutex_lock(msr->modsecurity->auditlog_lock);
469 if (rc != APR_SUCCESS) {
470 msr_log(msr, 1, "Audit log: Failed to lock global mutex: %s",
471 get_apr_error(msr->mp, rc));
475 /* AUDITLOG_PART_HEADER */
477 text = apr_psprintf(msr->mp, "--%s-%c--\n", msr->new_auditlog_boundary, AUDITLOG_PART_HEADER);
478 sec_auditlog_write(msr, text, strlen(text));
480 /* Format: time transaction_id remote_addr remote_port local_addr local_port */
482 text = apr_psprintf(msr->mp, "[%s] %s %s %u %s %u",
483 current_logtime(msr->mp), msr->txid, msr->remote_addr, msr->remote_port,
484 msr->local_addr, msr->local_port);
485 sec_auditlog_write(msr, text, strlen(text));
488 /* AUDITLOG_PART_REQUEST_HEADERS */
490 if (strchr(msr->txcfg->auditlog_parts, AUDITLOG_PART_REQUEST_HEADERS) != NULL) {
491 text = apr_psprintf(msr->mp, "\n--%s-%c--\n", msr->new_auditlog_boundary, AUDITLOG_PART_REQUEST_HEADERS);
492 sec_auditlog_write(msr, text, strlen(text));
494 sanitise_request_line(msr);
496 sec_auditlog_write(msr, msr->request_line, strlen(msr->request_line));
497 sec_auditlog_write(msr, "\n", 1);
499 arr = apr_table_elts(msr->request_headers);
500 te = (apr_table_entry_t *)arr->elts;
501 for (i = 0; i < arr->nelts; i++) {
502 text = apr_psprintf(msr->mp, "%s: %s\n", te[i].key, te[i].val);
503 /* Do we need to sanitise this request header? */
504 if (apr_table_get(msr->request_headers_to_sanitise, te[i].key) != NULL) {
505 /* Yes, sanitise it. */
506 memset(text + strlen(te[i].key) + 2, '*', strlen(te[i].val));
508 sec_auditlog_write(msr, text, strlen(text));
512 /* AUDITLOG_PART_REQUEST_BODY */
514 /* Output this part of it was explicitly requested (C) or if it was the faked
515 * request body that was requested (I) but we have no reason to fake it (it's
516 * already in the correct format).
518 if ( (strchr(msr->txcfg->auditlog_parts, AUDITLOG_PART_REQUEST_BODY) != NULL)
519 || ( (strchr(msr->txcfg->auditlog_parts, AUDITLOG_PART_FAKE_REQUEST_BODY) != NULL)
520 && (msr->mpd == NULL) ) )
522 if (msr->msc_reqbody_read) {
523 const apr_array_header_t *tarr;
524 const apr_table_entry_t *telts;
525 apr_array_header_t *sorted_args;
526 unsigned int offset = 0, last_offset = 0;
527 msc_arg *nextarg = NULL;
528 int sanitise = 0; /* IMP1 Use constants for "sanitise" values. */
529 char *my_error_msg = NULL;
531 sorted_args = apr_array_make(msr->mp, 25, sizeof(const msc_arg *));
533 /* First we need to sort the arguments that need to be
534 * sanitised in descending order (we are using a stack structure
535 * to store then so the order will be ascending when we start
536 * popping them out). This is because we will
537 * be reading the request body sequentially and must
538 * sanitise it as we go.
544 /* Find the next largest offset (excluding
545 * the ones we've used up already).
547 tarr = apr_table_elts(msr->arguments_to_sanitise);
548 telts = (const apr_table_entry_t*)tarr->elts;
549 for(i = 0; i < tarr->nelts; i++) {
550 msc_arg *arg = (msc_arg *)telts[i].val;
551 if (strcmp(arg->origin, "BODY") != 0) continue;
553 if (last_offset == 0) { /* The first time we're here. */
554 if (arg->value_origin_offset > offset) {
555 offset = arg->value_origin_offset;
558 } else { /* Not the first time. */
559 if ((arg->value_origin_offset > offset)
560 &&(arg->value_origin_offset < last_offset))
562 offset = arg->value_origin_offset;
568 /* If we don't have the next argument that means
571 if (nextarg == NULL) break;
573 sanitise = 2; /* Means time to pop the next argument out. */
574 last_offset = offset;
576 { /* IMP1 Fix this ugly bit here. */
577 msc_arg **x = apr_array_push(sorted_args);
582 /* Now start retrieving the body chunk by chunk and
583 * sanitise data in pieces.
586 rc = modsecurity_request_body_retrieve_start(msr, &my_error_msg);
588 msr_log(msr, 1, "Audit log: %s", my_error_msg);
590 msc_data_chunk *chunk = NULL;
591 unsigned int chunk_offset = 0;
592 unsigned int sanitise_offset = 0;
593 unsigned int sanitise_length = 0;
595 text = apr_psprintf(msr->mp, "\n--%s-%c--\n", msr->new_auditlog_boundary, AUDITLOG_PART_REQUEST_BODY);
596 sec_auditlog_write(msr, text, strlen(text));
599 rc = modsecurity_request_body_retrieve(msr, &chunk, -1, &my_error_msg);
601 /* Anything greater than 1 means we have more data to sanitise. */
602 while (sanitise > 1) {
603 msc_arg **arg = NULL;
606 /* Get the next argument from the stack. */
607 arg = (msc_arg **)apr_array_pop(sorted_args);
608 if (arg == NULL) sanitise = 0; /* We're done sanitising. */
610 /* Continue with sanitation to process the
611 * retrieved argument.
614 sanitise_offset = (*arg)->value_origin_offset;
615 sanitise_length = (*arg)->value_origin_len;
620 /* Check if the data we want to sanitise is
621 * stored in the current chunk.
623 if (chunk_offset + chunk->length > sanitise_offset) {
624 unsigned int soff; /* data offset within chunk */
625 unsigned int len; /* amount in this chunk to sanitise */
627 soff = sanitise_offset - chunk_offset;
629 if (soff + sanitise_length <= chunk->length) {
630 /* The entire argument resides in the current chunk. */
631 len = sanitise_length;
632 sanitise = 2; /* Get another parameter to sanitise. */
634 /* Some work to do here but we'll need to seek
637 len = chunk->length - soff;
638 sanitise_offset += len;
639 sanitise_length -= len;
640 sanitise = 1; /* It's OK to go to the next chunk. */
643 /* Yes, we actually write over the original data.
644 * We shouldn't be needing it any more.
646 if (soff + len <= chunk->length) { /* double check */
647 memset((char *)chunk->data + soff, '*', len);
653 /* Write the sanitised chunk to the log
654 * and advance to the next chunk. */
655 sec_auditlog_write(msr, chunk->data, chunk->length);
656 chunk_offset += chunk->length;
665 msr_log(msr, 1, "Audit log: %s", my_error_msg);
668 modsecurity_request_body_retrieve_end(msr);
673 /* AUDITLOG_PART_FAKE_REQUEST_BODY */
675 if (strchr(msr->txcfg->auditlog_parts, AUDITLOG_PART_FAKE_REQUEST_BODY) != NULL) {
676 if ((msr->msc_reqbody_read)&&(msr->mpd != NULL)) {
679 buffer = multipart_reconstruct_urlencoded_body_sanitise(msr);
680 if (buffer == NULL) {
681 msr_log(msr, 1, "Audit log: Failed to reconstruct request body.");
683 text = apr_psprintf(msr->mp, "\n--%s-%c--\n", msr->new_auditlog_boundary, AUDITLOG_PART_FAKE_REQUEST_BODY);
684 sec_auditlog_write(msr, text, strlen(text));
685 sec_auditlog_write(msr, buffer, strlen(buffer));
690 /* AUDITLOG_PART_A_RESPONSE_HEADERS */
692 if (strchr(msr->txcfg->auditlog_parts, AUDITLOG_PART_A_RESPONSE_HEADERS) != NULL) {
693 text = apr_psprintf(msr->mp, "\n--%s-%c--\n", msr->new_auditlog_boundary, AUDITLOG_PART_A_RESPONSE_HEADERS);
694 sec_auditlog_write(msr, text, strlen(text));
696 /* There are no response headers (or the status line) in HTTP 0.9 */
697 if (msr->response_headers_sent) {
698 if (msr->status_line != NULL) {
699 text = apr_psprintf(msr->mp, "%s %s\n", msr->response_protocol,
702 text = apr_psprintf(msr->mp, "%s %u\n", msr->response_protocol,
703 msr->response_status);
705 sec_auditlog_write(msr, text, strlen(text));
709 arr = apr_table_elts(msr->response_headers);
710 te = (apr_table_entry_t *)arr->elts;
711 for (i = 0; i < arr->nelts; i++) {
712 text = apr_psprintf(msr->mp, "%s: %s\n", te[i].key, te[i].val);
713 /* Do we need to sanitise this response header? */
714 if (apr_table_get(msr->response_headers_to_sanitise, te[i].key) != NULL) {
715 /* Yes, sanitise it. */
716 memset(text + strlen(te[i].key) + 2, '*', strlen(te[i].val));
718 sec_auditlog_write(msr, text, strlen(text));
723 /* AUDITLOG_PART_RESPONSE_BODY */
725 if (strchr(msr->txcfg->auditlog_parts, AUDITLOG_PART_RESPONSE_BODY) != NULL) {
726 if (msr->resbody_data != NULL) {
727 text = apr_psprintf(msr->mp, "\n--%s-%c--\n", msr->new_auditlog_boundary, AUDITLOG_PART_RESPONSE_BODY);
728 sec_auditlog_write(msr, text, strlen(text));
729 sec_auditlog_write(msr, msr->resbody_data, msr->resbody_length);
730 wrote_response_body = 1;
734 /* AUDITLOG_PART_TRAILER */
736 if (strchr(msr->txcfg->auditlog_parts, AUDITLOG_PART_TRAILER) != NULL) {
737 apr_time_t now = apr_time_now();
739 text = apr_psprintf(msr->mp, "\n--%s-%c--\n", msr->new_auditlog_boundary, AUDITLOG_PART_TRAILER);
740 sec_auditlog_write(msr, text, strlen(text));
743 for(i = 0; i < msr->alerts->nelts; i++) {
744 text = apr_psprintf(msr->mp, "Message: %s\n", ((char **)msr->alerts->elts)[i]);
745 sec_auditlog_write(msr, text, strlen(text));
748 /* Apache error messages */
749 for(i = 0; i < msr->error_messages->nelts; i++) {
750 error_message *em = (((error_message**)msr->error_messages->elts)[i]);
751 text = apr_psprintf(msr->mp, "Apache-Error: %s\n",
752 format_error_log_message(msr->mp, em));
753 sec_auditlog_write(msr, text, strlen(text));
757 if (msr->was_intercepted) {
758 text = apr_psprintf(msr->mp, "Action: Intercepted (phase %d)\n", msr->intercept_phase);
759 sec_auditlog_write(msr, text, strlen(text));
763 if (msr->r->handler != NULL) {
764 text = apr_psprintf(msr->mp, "Apache-Handler: %s\n", msr->r->handler);
765 sec_auditlog_write(msr, text, strlen(text));
768 /* Processing times */
769 if (msr->time_checkpoint_1 == 0) {
770 text = apr_psprintf(msr->mp, "Stopwatch: %" APR_TIME_T_FMT " %" APR_TIME_T_FMT
771 " (- - -)\n", (msr->request_time), (now - msr->request_time));
773 char sw_str2[101] = "-";
774 char sw_str3[101] = "-";
776 if (msr->time_checkpoint_2 != 0) {
777 apr_snprintf(sw_str2, sizeof(sw_str2), "%" APR_TIME_T_FMT,
778 (msr->time_checkpoint_2 - msr->request_time));
781 if (msr->time_checkpoint_3 != 0) {
782 apr_snprintf(sw_str3, sizeof(sw_str3), "%" APR_TIME_T_FMT,
783 (msr->time_checkpoint_3 - msr->request_time));
786 text = apr_psprintf(msr->mp, "Stopwatch: %" APR_TIME_T_FMT
787 " %" APR_TIME_T_FMT " (%" APR_TIME_T_FMT
789 (msr->request_time), (now - msr->request_time),
790 (msr->time_checkpoint_1 - msr->request_time),
791 ((msr->msc_reqbody_read == 0) ? "" : "*"),
796 sec_auditlog_write(msr, text, strlen(text));
798 /* Our response body does not contain chunks */
799 /* ENH Only write this when the output was chunked. */
800 /* ENH Add info when request body was decompressed, dechunked too. */
801 if (wrote_response_body) {
802 text = apr_psprintf(msr->mp, "Response-Body-Transformed: Dechunked\n");
803 sec_auditlog_write(msr, text, strlen(text));
806 sec_auditlog_write_producer_header(msr);
809 if (msr->server_software != NULL) {
810 text = apr_psprintf(msr->mp, "Server: %s\n", msr->server_software);
811 sec_auditlog_write(msr, text, strlen(text));
814 /* Sanitised arguments */
816 const apr_array_header_t *tarr;
817 const apr_table_entry_t *telts;
819 tarr = apr_table_elts(msr->arguments_to_sanitise);
820 telts = (const apr_table_entry_t*)tarr->elts;
822 if (tarr->nelts > 0) {
823 text = apr_psprintf(msr->mp, "Sanitised-Args: ");
824 sec_auditlog_write(msr, text, strlen(text));
827 for(i = 0; i < tarr->nelts; i++) {
828 msc_arg *arg = (msc_arg *)telts[i].val;
829 text = apr_psprintf(msr->mp, "%s\"%s\"%s", ((i == 0) ? "" : ", "),
830 log_escape(msr->mp, arg->name), ((i == (tarr->nelts - 1)) ? ".\n" : ""));
831 sec_auditlog_write(msr, text, strlen(text));
835 /* Sanitised request headers */
837 const apr_array_header_t *tarr;
838 const apr_table_entry_t *telts;
840 tarr = apr_table_elts(msr->request_headers_to_sanitise);
841 telts = (const apr_table_entry_t*)tarr->elts;
843 if (tarr->nelts > 0) {
844 text = apr_psprintf(msr->mp, "Sanitised-Request-Headers: ");
845 sec_auditlog_write(msr, text, strlen(text));
848 for(i = 0; i < tarr->nelts; i++) {
849 text = apr_psprintf(msr->mp, "%s\"%s\"%s", ((i == 0) ? "" : ", "),
850 log_escape(msr->mp, telts[i].key), ((i == (tarr->nelts - 1)) ? ".\n" : ""));
851 sec_auditlog_write(msr, text, strlen(text));
855 /* Sanitised response headers */
857 const apr_array_header_t *tarr;
858 const apr_table_entry_t *telts;
860 tarr = apr_table_elts(msr->response_headers_to_sanitise);
861 telts = (const apr_table_entry_t*)tarr->elts;
863 if (tarr->nelts > 0) {
864 text = apr_psprintf(msr->mp, "Sanitised-Response-Headers: ");
865 sec_auditlog_write(msr, text, strlen(text));
868 for(i = 0; i < tarr->nelts; i++) {
869 text = apr_psprintf(msr->mp, "%s\"%s\"%s", ((i == 0) ? "" : ", "),
870 log_escape(msr->mp, telts[i].key), ((i == (tarr->nelts - 1)) ? ".\n" : ""));
871 sec_auditlog_write(msr, text, strlen(text));
875 /* Web application info. */
876 if ( ((msr->txcfg->webappid != NULL)&&(strcmp(msr->txcfg->webappid, "default") != 0))
877 || (msr->sessionid != NULL) || (msr->userid != NULL))
879 text = apr_psprintf(msr->mp, "WebApp-Info: \"%s\" \"%s\" \"%s\"\n",
880 msr->txcfg->webappid == NULL ? "-" : log_escape(msr->mp, msr->txcfg->webappid),
881 msr->sessionid == NULL ? "-" : log_escape(msr->mp, msr->sessionid),
882 msr->userid == NULL ? "-" : log_escape(msr->mp, msr->userid));
883 sec_auditlog_write(msr, text, strlen(text));
887 /* AUDITLOG_PART_UPLOADS */
891 /* AUDITLOG_PART_MATCHEDRULES */
893 if (strchr(msr->txcfg->auditlog_parts, AUDITLOG_PART_MATCHEDRULES) != NULL) {
894 text = apr_psprintf(msr->mp, "\n--%s-%c--\n", msr->new_auditlog_boundary, AUDITLOG_PART_MATCHEDRULES);
895 sec_auditlog_write(msr, text, strlen(text));
898 for(i = 0; i < msr->matched_rules->nelts; i++) {
899 rule = ((msre_rule **)msr->matched_rules->elts)[i];
900 text = apr_psprintf(msr->mp, "%s\n", rule->unparsed);
901 sec_auditlog_write(msr, text, strlen(text));
906 /* AUDITLOG_PART_ENDMARKER */
908 text = apr_psprintf(msr->mp, "\n--%s-%c--\n", msr->new_auditlog_boundary, AUDITLOG_PART_ENDMARKER);
909 sec_auditlog_write(msr, text, strlen(text));
911 /* Return here if we were writing to a serial log
912 * as it does not need an index file.
914 if (msr->txcfg->auditlog_type != AUDITLOG_CONCURRENT) {
915 sec_auditlog_write(msr, "\n", 1);
917 /* Unlock the mutex we used to serialise access to the audit log file. */
918 rc = apr_global_mutex_unlock(msr->modsecurity->auditlog_lock);
919 if (rc != APR_SUCCESS) {
920 msr_log(msr, 1, "Audit log: Failed to unlock global mutex: %s",
921 get_apr_error(msr->mp, rc));
927 /* From here on only concurrent-style processing. */
929 apr_file_close(msr->new_auditlog_fd);
931 /* Write an entry to the index file */
933 /* Calculate hash of the entry. */
934 apr_md5_final(md5hash, &msr->new_auditlog_md5ctx);
936 str2 = apr_psprintf(msr->mp, "%s %d %d md5:%s", msr->new_auditlog_filename, 0,
937 msr->new_auditlog_size, bytes2hex(msr->mp, md5hash, 16));
938 if (str2 == NULL) return;
940 /* We do not want the index line to be longer than 3980 bytes. */
944 /* If we are logging to a pipe we need to observe and
945 * obey the pipe atomic write limit - PIPE_BUF. For
946 * more details see the discussion in sec_guardian_logger code.
948 if (msr->txcfg->auditlog_name[0] == '|') {
949 if (PIPE_BUF < limit) {
954 limit = limit - strlen(str2) - 5;
956 msr_log(msr, 1, "Audit Log: Atomic PIPE write buffer too small: %d", PIPE_BUF);
960 str1 = construct_log_vcombinedus_limited(msr, limit, &was_limited);
961 if (str1 == NULL) return;
963 if (was_limited == 0) {
964 text = apr_psprintf(msr->mp, "%s %s \n", str1, str2);
966 text = apr_psprintf(msr->mp, "%s %s L\n", str1, str2);
968 if (text == NULL) return;
970 nbytes = strlen(text);
971 if (msr->txcfg->debuglog_level >= 9) {
972 msr_log(msr, 9, "Audit Log: Writing %" APR_SIZE_T_FMT " bytes to primary concurrent index", nbytes);
974 apr_file_write_full(msr->txcfg->auditlog_fd, text, nbytes, &nbytes_written);
976 /* Write to the secondary audit log if we have one */
977 if (msr->txcfg->auditlog2_fd != NULL) {
978 if (msr->txcfg->debuglog_level >= 9) {
979 msr_log(msr, 9, "Audit Log: Writing %" APR_SIZE_T_FMT " bytes to secondary concurrent index", nbytes);
981 apr_file_write_full(msr->txcfg->auditlog2_fd, text, nbytes, &nbytes_written);