apr_status_t modsecurity_tx_init(modsec_rec *msr)
{
const char *s = NULL;
/* Register TX cleanup */
apr_pool_cleanup_register(msr->mp, msr, modsecurity_tx_cleanup, apr_pool_cleanup_null);
/* Initialise C-L */
msr->request_content_length = -1;
s = apr_table_get(msr->request_headers, "Content-Length");
if (s != NULL) {
msr->request_content_length = strtol(s, NULL, 10);
}
/* Figure out whether this request has a body */
msr->reqbody_chunked = 0;
msr->reqbody_should_exist = 0;
if (msr->request_content_length == -1) {
/* There's no C-L, but is chunked encoding used? */
char *transfer_encoding = (char *)apr_table_get(msr->request_headers, "Transfer-Encoding");
if ((transfer_encoding != NULL) && (strstr(transfer_encoding, "chunked") != NULL)) {
msr->reqbody_should_exist = 1;
msr->reqbody_chunked = 1;
}
} else {
/* C-L found */
msr->reqbody_should_exist = 1;
}
/* Initialise C-T */
msr->request_content_type = NULL;
s = apr_table_get(msr->request_headers, "Content-Type");
if (s != NULL) {
msr->request_content_type = s;
}
/* Decide what to do with the request body. */
if ((msr->request_content_type != NULL)
&& (strncasecmp(msr->request_content_type, "application/x-www-form-urlencoded", 33) == 0)) {
/* Always place POST requests with "application/x-www-form-urlencoded" payloads in memory. */
msr->msc_reqbody_storage = MSC_REQBODY_MEMORY;
msr->msc_reqbody_spilltodisk = 1;
msr->msc_reqbody_processor = "URLENCODED";
ap_log_error(APLOG_MARK, APLOG_DEBUG, 0, NULL, "msc reqbody processor change to URLENCODED");
} else {
/* In all other cases, try using the memory first but switch over to disk for larger bodies. */
msr->msc_reqbody_storage = MSC_REQBODY_MEMORY;
msr->msc_reqbody_spilltodisk = 1;
/* If the C-L is known and there's more data than our limit go to disk straight away. */
if ((msr->request_content_length != -1)
&& (msr->request_content_length > msr->txcfg->reqbody_inmemory_limit)) {
msr->msc_reqbody_storage = MSC_REQBODY_DISK;
}
if (msr->request_content_type != NULL) {
if (strncasecmp(msr->request_content_type, "multipart/form-data", 19) == 0) {
msr->msc_reqbody_processor = "MULTIPART";
ap_log_error(APLOG_MARK, APLOG_DEBUG, 0, NULL, "msc reqbody processor change to MULTIPART");
} else if (strncasecmp(msr->request_content_type, "text/xml", 8) == 0) {
msr->msc_reqbody_processor = "XML";
ap_log_error(APLOG_MARK, APLOG_DEBUG, 0, NULL, "msc reqbody processor change to XML");
}
}
}
/* Check if we are forcing buffering, then use memory only. */
if (msr->txcfg->reqbody_buffering != REQUEST_BODY_FORCEBUF_OFF) {
msr->msc_reqbody_storage = MSC_REQBODY_MEMORY;
msr->msc_reqbody_spilltodisk = 0;
}
/* Initialise arguments */
msr->arguments = apr_table_make(msr->mp, 32);
if (msr->arguments == NULL) {
return -1;
}
if (msr->query_string != NULL) {
int invalid_count = 0;
/* 查询串参数解析 */
if (parse_arguments(msr, msr->query_string, strlen(msr->query_string),
msr->txcfg->argument_separator, "QUERY_STRING", msr->arguments, &invalid_count) < 0) {
msr_log(msr, 1, "Initialisation: Error occurred while parsing QUERY_STRING arguments.");
return -1;
}
if (invalid_count) {
msr->urlencoded_error = 1;
}
}
if (msr->request_uri != NULL) {
/* request_uri解析 */
msr->request_uri = (const char *)parse_uri(msr->mp, msr->request_uri);
if (msr->request_uri == NULL) {
msr_log(msr, 1, "Initialisation: Error occurred while parsing REQUEST_URI arguments.");
return -1;
}
}
if (msr->request_line != NULL) {
/* request_line解析 */
msr->request_line = (const char *)parse_request_line(msr->mp, msr->request_line);
if (msr->request_line == NULL) {
msr_log(msr, 1, "Initialisation: Error occurred while parsing REQUEST_LINE arguments.");
return -1;
}
}
msr->arguments_to_sanitize = apr_table_make(msr->mp, 16);
if (msr->arguments_to_sanitize == NULL) {
return -1;
}
msr->request_headers_to_sanitize = apr_table_make(msr->mp, 16);
if (msr->request_headers_to_sanitize == NULL) {
return -1;
}
msr->response_headers_to_sanitize = apr_table_make(msr->mp, 16);
if (msr->response_headers_to_sanitize == NULL) {
return -1;
}
msr->pattern_to_sanitize = apr_table_make(msr->mp, 32);
if (msr->pattern_to_sanitize == NULL) {
return -1;
}
/* Initialise cookies */
msr->request_cookies = apr_table_make(msr->mp, 5);
if (msr->request_cookies == NULL) {
return -1;
}
/* Initialize matched vars */
msr->matched_vars = apr_table_make(msr->mp, 8);
if (msr->matched_vars == NULL) {
return -1;
}
apr_table_clear(msr->matched_vars);
/* Locate the cookie headers and parse them */
/* 解析请求cookie */
if (parse_request_cookie(msr) == -1) {
return -1;
}
/* Collections. */
msr->tx_vars = apr_table_make(msr->mp, 32);
if (msr->tx_vars == NULL) {
return -1;
}
msr->geo_vars = apr_table_make(msr->mp, 8);
if (msr->geo_vars == NULL) {
return -1;
}
msr->collections_original = apr_table_make(msr->mp, 8);
if (msr->collections_original == NULL) {
return -1;
}
msr->collections = apr_table_make(msr->mp, 8);
if (msr->collections == NULL) {
return -1;
}
msr->collections_dirty = apr_table_make(msr->mp, 8);
if (msr->collections_dirty == NULL) {
return -1;
}
/* Other */
msr->tcache = NULL;
msr->tcache_items = 0;
/* 初始化变量缓存内存池 */
#ifdef VAR_FETCH_CACHE
if (apr_pool_create(&msr->var_fetch_cache_mptmp, msr->mp) != APR_SUCCESS) {
return -1;
}
apr_pool_tag(msr->var_fetch_cache_mptmp, "varfetchcache");
#endif
msr->matched_rules = apr_array_make(msr->mp, 16, sizeof(void *));
if (msr->matched_rules == NULL) {
return -1;
}
msr->matched_var = (msc_string *)apr_pcalloc(msr->mp, sizeof(msc_string));
if (msr->matched_var == NULL) {
return -1;
}
msr->highest_severity = 255; /* high, invalid value */
msr->removed_rules = apr_array_make(msr->mp, 16, sizeof(char *));
if (msr->removed_rules == NULL) {
return -1;
}
msr->removed_rules_tag = apr_array_make(msr->mp, 16, sizeof(char *));
if (msr->removed_rules_tag == NULL) {
return -1;
}
return 1;
}
static apr_status_t modsecurity_process_phase_logging(modsec_rec *msr)
{
apr_time_t time_before, time_after;
if (msr->txcfg->debuglog_level >= 4) {
msr_log(msr, 4, "Starting phase LOGGING.");
}
time_before = apr_time_now();
if (msr->txcfg->ruleset != NULL) {
msre_ruleset_process_phase(msr->txcfg->ruleset, msr);
}
modsecurity_persist_data(msr);
time_after = apr_time_now();
msr->time_phase5 = time_after - time_before;
/* Is this request relevant for logging purposes? */
#if 0
if (msr->is_relevant == 0) {
/* Check the status */
msr->is_relevant += is_response_status_relevant(msr, msr->r->status);
/* If we processed two requests and statuses are different then check the other status too. */
if (msr->r_early->status != msr->r->status) {
msr->is_relevant += is_response_status_relevant(msr, msr->r_early->status);
}
}
#endif
/* Figure out if we want to keep the files (if there are any, of course). */
if ((msr->txcfg->upload_keep_files == KEEP_FILES_ON) ||
((msr->txcfg->upload_keep_files == KEEP_FILES_RELEVANT_ONLY) && (msr->is_relevant))) {
msr->upload_remove_files = 0;
} else {
msr->upload_remove_files = 1;
}
/* Are we configured for audit logging? */
switch(msr->txcfg->attacklog_flag) {
case AUDITLOG_OFF :
if (msr->txcfg->debuglog_level >= 4) {
msr_log(msr, 4, "Audit log: Not configured to run for this request.");
}
return DECLINED;
break;
/* 裁减 */
#if 0
case AUDITLOG_RELEVANT :
if (msr->is_relevant == 0) {
if (msr->txcfg->debuglog_level >= 4) {
msr_log(msr, 4, "Audit log: Ignoring a non-relevant request.");
}
return DECLINED;
}
break;
#endif
case AUDITLOG_ON :
/* All right, do nothing */
break;
default :
msr_log(msr, 1, "Internal error: Could not determine if auditing is needed, so forcing auditing.");
break;
}
/* Invoke the Audit logger */
if (msr->txcfg->debuglog_level >= 4) {
msr_log(msr, 4, "Audit log: Logging this transaction.");
}
/* sec_attack_logger(msr); 该函数移至外面 */
msr->time_logging = apr_time_now() - time_after;
return 0;
}
/**
* Processes one transaction phase. The phase number does not
* need to be explicitly provided since it's already available
* in the modsec_rec structure.
*/
apr_status_t modsecurity_process_phase(modsec_rec *msr, unsigned int phase)
{
/* Check if we should run. */
if ((msr->was_intercepted) && (phase != PHASE_LOGGING)) {
if (msr->txcfg->debuglog_level >= 4) {
msr_log(msr, 4, "Skipping phase %d as request was already intercepted.", phase);
}
return 0;
}
/* Do not process the same phase twice. */
if (msr->phase >= phase) {
if (msr->txcfg->debuglog_level >= 4) {
msr_log(msr, 4, "Skipping phase %d because it was previously run (at %d now).",
phase, msr->phase);
}
return 0;
}
msr->phase = phase;
/* Clear out the transformation cache at the start of each phase */
if (msr->txcfg->cache_trans == MODSEC_CACHE_ENABLED) {
if (msr->tcache) {
apr_hash_index_t *hi;
void *dummy;
apr_table_t *tab;
const void *key;
apr_ssize_t klen;
#ifdef CACHE_DEBUG
apr_pool_t *mp = msr->msc_rule_mptmp;
const apr_array_header_t *ctarr;
const apr_table_entry_t *ctelts;
msre_cache_rec *rec;
int cn = 0;
int ri;
#else
apr_pool_t *mp = msr->mp;
#endif
for (hi = apr_hash_first(mp, msr->tcache); hi; hi = apr_hash_next(hi)) {
apr_hash_this(hi, &key, &klen, &dummy);
tab = (apr_table_t *)dummy;
if (tab == NULL) {
continue;
}
#ifdef CACHE_DEBUG
/* Dump the cache out as we clear */
ctarr = apr_table_elts(tab);
ctelts = (const apr_table_entry_t*)ctarr->elts;
for (ri = 0; ri < ctarr->nelts; ri++) {
cn++;
rec = (msre_cache_rec *)ctelts[ri].val;
if (rec->changed) {
if (msr->txcfg->debuglog_level >= 9) {
msr_log(msr, 9, "CACHE: %5d) hits=%d key=%pp %x;%s=\"%s\" (%pp - %pp)",
cn, rec->hits, key, rec->num, rec->path,
log_escape_nq_ex(mp, rec->val, rec->val_len), rec->val,
rec->val + rec->val_len);
}
} else {
if (msr->txcfg->debuglog_level >= 9) {
msr_log(msr, 9, "CACHE: %5d) hits=%d key=%pp %x;%s=<no change>",
cn, rec->hits, key, rec->num, rec->path);
}
}
}
#endif
apr_table_clear(tab);
apr_hash_set(msr->tcache, key, klen, NULL);
}
if (msr->txcfg->debuglog_level >= 9) {
msr_log(msr, 9, "Cleared transformation cache for phase %d", msr->phase);
}
}
msr->tcache_items = 0;
msr->tcache = apr_hash_make(msr->mp);
if (msr->tcache == NULL) {
return -1;
}
}
/* 清除变量缓存 */
#ifdef VAR_FETCH_CACHE
apr_pool_clear(msr->var_fetch_cache_mptmp);
msr->var_fetch_cache = apr_hash_make(msr->var_fetch_cache_mptmp);
if (msr->var_fetch_cache == NULL) {
return -1;
}
#endif
switch(phase) {
case 1 :
return modsecurity_process_phase_request_headers(msr);
case 2 :
return modsecurity_process_phase_request_body(msr);
case 3 :
return modsecurity_process_phase_response_headers(msr);
case 4 :
return modsecurity_process_phase_response_body(msr);
case 5 :
return modsecurity_process_phase_logging(msr);
default :
msr_log(msr, 1, "Invalid processing phase: %d", msr->phase);
break;
}
return -1;
}
/**
* Stops receiving the request body.
*/
apr_status_t modsecurity_request_body_end(modsec_rec *msr, char **error_msg)
{
*error_msg = NULL;
/* Close open file descriptors, if any. */
if (msr->msc_reqbody_storage == MSC_REQBODY_DISK) {
if (msr->msc_reqbody_fd > 0) {
close(msr->msc_reqbody_fd);
msr->msc_reqbody_fd = -1;
}
}
/* Note that we've read the body. */
msr->msc_reqbody_read = 1;
/* Finalise body processing. */
if ((msr->msc_reqbody_processor != NULL) && (msr->msc_reqbody_error == 0)) {
char *my_error_msg = NULL;
msre_reqbody_processor_metadata *metadata =
(msre_reqbody_processor_metadata *)apr_table_get(msr->modsecurity->msre->reqbody_processors, msr->msc_reqbody_processor);
if (metadata != NULL) {
if ((metadata->complete != NULL) && (metadata->complete(msr, &my_error_msg) < 0)) {
*error_msg = apr_psprintf(msr->mp, "%s parsing error (complete): %s",
msr->msc_reqbody_processor, my_error_msg);
msr->msc_reqbody_error = 1;
msr->msc_reqbody_error_msg = my_error_msg;
msr_log(msr, 2, "%s", *error_msg);
}
}
// TODO: All these below need to be registered in the same way as above
else if (strcmp(msr->msc_reqbody_processor, "MULTIPART") == 0) {
if (multipart_complete(msr, &my_error_msg) < 0) {
*error_msg = apr_psprintf(msr->mp, "Multipart parsing error: %s", my_error_msg);
msr->msc_reqbody_error = 1;
msr->msc_reqbody_error_msg = *error_msg;
if (msr->txcfg->debuglog_level >= 4) {
msr_log(msr, 4, "%s", *error_msg);
}
return -1;
}
if (multipart_get_arguments(msr, "BODY", msr->arguments) < 0) {
*error_msg = "Multipart parsing error: Failed to retrieve arguments.";
msr->msc_reqbody_error = 1;
msr->msc_reqbody_error_msg = *error_msg;
msr_log(msr, 2, "%s", *error_msg);
return -1;
}
} else if (strcmp(msr->msc_reqbody_processor, "URLENCODED") == 0) {
return modsecurity_request_body_end_urlencoded(msr, error_msg); /* 会解析参数 */
} else if (strcmp(msr->msc_reqbody_processor, "XML") == 0) {
if (xml_complete(msr, &my_error_msg) < 0) {
*error_msg = apr_psprintf(msr->mp, "XML parser error: %s", my_error_msg);
msr->msc_reqbody_error = 1;
msr->msc_reqbody_error_msg = *error_msg;
msr_log(msr, 2, "%s", *error_msg);
return -1;
}
}
} else if (msr->msc_reqbody_length > 0) {
/* if (msr->txcfg->reqbody_buffering != REQUEST_BODY_FORCEBUF_OFF) { */
/* 除了muitipart和xml类型外其余情况内存部分的数据都进行打包 */
/* Convert to a single continous buffer, but don't do anything else. */
return modsecurity_request_body_end_raw(msr, error_msg);
}
/* Note the request body no files length. */
msr_log(msr, 4, "Request body no files length: %" APR_SIZE_T_FMT, msr->msc_reqbody_no_files_length);
return 1;
}
apr_status_t modsecurity_request_body_clear(modsec_rec *msr, char **error_msg)
{
*error_msg = NULL;
/* Release memory we used to store request body data. */
if (msr->msc_reqbody_chunks != NULL) {
msc_data_chunk **chunks = (msc_data_chunk **)msr->msc_reqbody_chunks->elts;
int i;
for(i = 0; i < msr->msc_reqbody_chunks->nelts; i++) {
if (chunks[i]->data != NULL) {
free(chunks[i]->data);
chunks[i]->data = NULL;
}
}
}
if (msr->msc_reqbody_storage == MSC_REQBODY_DISK) {
int keep_body = 0;
/* Should we keep the body? This normally happens when a PUT method was used, which
* means the body is actually a file. */
if ((msr->upload_remove_files == 0) && (strcasecmp(msr->request_method, "PUT") == 0)) {
if (msr->txcfg->upload_dir != NULL) {
keep_body = 1;
} else {
*error_msg = apr_psprintf(msr->mp, "Input filter: SecUploadDir is undefined, "
"unable to store PUT file.");
}
}
/* Deal with a request body stored in a file. */
if (msr->msc_reqbody_filename != NULL) {
if (keep_body) {
/* Move request body (which is a file) to the storage area. */
const char *put_filename = NULL;
const char *put_basename = NULL;
/* Construct the new filename. */
put_basename = file_basename(msr->msc_reqbody_mp, msr->msc_reqbody_filename);
if (put_basename == NULL) {
*error_msg = apr_psprintf(msr->mp, "Input filter: Failed to generate basename "
"to PUT file \"%s\"", log_escape(msr->msc_reqbody_mp,
msr->msc_reqbody_filename));
return -1;
}
put_filename = apr_psprintf(msr->msc_reqbody_mp, "%s/%s", msr->txcfg->upload_dir,
put_basename);
if (put_filename == NULL) {
*error_msg = apr_psprintf(msr->mp, "Input filter: Failed to generate filename "
"to PUT file \"%s\"", log_escape(msr->msc_reqbody_mp,
msr->msc_reqbody_filename));
return -1;
}
if (apr_file_rename(msr->msc_reqbody_filename, put_filename, msr->msc_reqbody_mp) != APR_SUCCESS) {
*error_msg = apr_psprintf(msr->mp, "Input filter: Failed to rename file from "
"\"%s\" to \"%s\".",
log_escape(msr->msc_reqbody_mp, msr->msc_reqbody_filename),
log_escape(msr->msc_reqbody_mp, put_filename));
return -1;
} else {
msr_log(msr, 4, "Input filter: Moved file from \"%s\" to \"%s\".",
log_escape(msr->msc_reqbody_mp, msr->msc_reqbody_filename),
log_escape(msr->msc_reqbody_mp, put_filename));
}
} else {
/* make sure it is closed first */
if (msr->msc_reqbody_fd > 0) {
close(msr->msc_reqbody_fd);
msr->msc_reqbody_fd = -1;
}
/* We do not want to keep the request body. */
if (apr_file_remove(msr->msc_reqbody_filename, msr->msc_reqbody_mp) != APR_SUCCESS) {
*error_msg = apr_psprintf(msr->mp, "Input filter: Failed to delete temporary file: %s",
log_escape(msr->mp, msr->msc_reqbody_filename));
return -1;
}
msr_log(msr, 4, "Input filter: Removed temporary file: %s", msr->msc_reqbody_filename);
}
msr->msc_reqbody_filename = NULL;
}
}
if (msr->msc_reqbody_mp != NULL) {
apr_pool_destroy(msr->msc_reqbody_mp);
msr->msc_reqbody_mp = NULL;
}
return 1;
}
/**
* Stores one chunk of request body data in memory.
*/
static apr_status_t modsecurity_request_body_store_memory(modsec_rec *msr, const char *data,
apr_size_t length, char **error_msg)
{
*error_msg = NULL;
/* Would storing this chunk mean going over the limit? */
if ((msr->msc_reqbody_spilltodisk)
&& (msr->msc_reqbody_length + length > (apr_size_t)msr->txcfg->reqbody_inmemory_limit)) {
msc_data_chunk **chunks;
unsigned int disklen = 0;
int i;
msr_log(msr, 4, "Input filter: Request too large to store in memory, switching to disk.");
/* NOTE Must use modsecurity_request_body_store_disk() here
* to prevent data to be sent to the streaming
* processors again.
*/
/* Initialise disk storage */
msr->msc_reqbody_storage = MSC_REQBODY_DISK;
if (modsecurity_request_body_start_init(msr, error_msg) < 0) {
return -1;
}
/* Write the data we keep in memory */
chunks = (msc_data_chunk **)msr->msc_reqbody_chunks->elts;
for(i = 0; i < msr->msc_reqbody_chunks->nelts; i++) {
disklen += chunks[i]->length;
if (modsecurity_request_body_store_disk(msr, chunks[i]->data, chunks[i]->length, error_msg) < 0) {
return -1;
}
/* 对于 text/xml类型和multipart/form-data类型不保存内存数据*/
if (msr->request_content_type != NULL
&& ((strncasecmp(msr->request_content_type, "text/xml", 8) == 0)
|| (strncasecmp(msr->request_content_type, "multipart/form-data", 19) == 0))) {
free(chunks[i]->data);
chunks[i]->data = NULL;
msr->msc_reqbody_length = 0;
}
}
/* Clear the memory pool as we no longer need the bits. */
/* IMP1 But since we only used apr_pool_clear memory might
* not be released back to the OS straight away?
*/
msr_log(msr, 4, "Input filter: Wrote %u bytes from memory to disk.", disklen);
/* Continue with disk storage from now on */
return modsecurity_request_body_store_disk(msr, data, length, error_msg);
}
/* If we're here that means we are not over the request body in-memory limit yet. */
{
unsigned long int bucket_offset, bucket_left;
bucket_offset = 0;
bucket_left = length;
/* Although we store the request body in chunks we don't
* want to use the same chunk sizes as the incoming memory
* buffers. They are often of very small sizes and that
* would make us waste a lot of memory. That's why we
* use our own chunks of CHUNK_CAPACITY sizes.
*/
/* Loop until we empty this bucket into our chunks. */
while(bucket_left > 0) {
/* Allocate a new chunk if we have to. */
if (msr->msc_reqbody_chunk_current == NULL) {
msr->msc_reqbody_chunk_current = (msc_data_chunk *)apr_pcalloc(msr->msc_reqbody_mp,
sizeof(msc_data_chunk));
if (msr->msc_reqbody_chunk_current == NULL) {
*error_msg = apr_psprintf(msr->mp, "Input filter: Failed to allocate %lu bytes "
"for request body chunk.", (unsigned long)sizeof(msc_data_chunk));
return -1;
}
msr->msc_reqbody_chunk_current->data = malloc(CHUNK_CAPACITY);
if (msr->msc_reqbody_chunk_current->data == NULL) {
*error_msg = apr_psprintf(msr->mp, "Input filter: Failed to allocate %d bytes "
"for request body chunk data.", CHUNK_CAPACITY);
return -1;
}
msr->msc_reqbody_chunk_current->length = 0;
msr->msc_reqbody_chunk_current->is_permanent = 1;
*(const msc_data_chunk **)apr_array_push(msr->msc_reqbody_chunks) = msr->msc_reqbody_chunk_current;
}
if (bucket_left < (CHUNK_CAPACITY - msr->msc_reqbody_chunk_current->length)) {
/* There's enough space in the current chunk. */
memcpy(msr->msc_reqbody_chunk_current->data + msr->msc_reqbody_chunk_current->length,
data + bucket_offset, bucket_left);
msr->msc_reqbody_chunk_current->length += bucket_left;
bucket_left = 0;
} else {
/* Fill the existing chunk. */
unsigned long int copy_length = CHUNK_CAPACITY - msr->msc_reqbody_chunk_current->length;
memcpy(msr->msc_reqbody_chunk_current->data + msr->msc_reqbody_chunk_current->length,
data + bucket_offset, copy_length);
bucket_offset += copy_length;
bucket_left -= copy_length;
msr->msc_reqbody_chunk_current->length += copy_length;
/* We're done with this chunk. Setting the pointer to NULL is going to force a new
* chunk to be allocated on the next go.
*/
msr->msc_reqbody_chunk_current = NULL;
}
}
msr->msc_reqbody_length += length;
}
return 1;
}
/**
* Stores one chunk of request body data. Returns -1 on error.
*/
apr_status_t modsecurity_request_body_store(modsec_rec *msr, const char *data, apr_size_t length,
char **error_msg)
{
*error_msg = NULL;
/* If we have a processor for this request body send data to it first (but only if it did not
* report an error on previous invocations).
*/
if ((msr->msc_reqbody_processor != NULL) && (msr->msc_reqbody_error == 0)) {
char *my_error_msg = NULL;
msre_reqbody_processor_metadata *metadata =
(msre_reqbody_processor_metadata *)apr_table_get(msr->modsecurity->msre->reqbody_processors, msr->msc_reqbody_processor);
if (metadata != NULL) {
if ((metadata->process != NULL) && (metadata->process(msr, data, length, &my_error_msg) < 0)) {
*error_msg = apr_psprintf(msr->mp, "%s parsing error: %s", msr->msc_reqbody_processor, my_error_msg);
msr->msc_reqbody_error = 1;
msr->msc_reqbody_error_msg = my_error_msg;
msr_log(msr, 2, "%s", *error_msg);
}
}
// TODO: All these below need to be registered in the same way as above
else if (strcmp(msr->msc_reqbody_processor, "MULTIPART") == 0) {
/* The per-request data length counter will be updated by the multipart parser. */
/* Process data as multipart/form-data. */
if (multipart_process_chunk(msr, data, length, &my_error_msg) < 0) {
*error_msg = apr_psprintf(msr->mp, "Multipart parsing error: %s", my_error_msg);
msr->msc_reqbody_error = 1;
msr->msc_reqbody_error_msg = *error_msg;
msr_log(msr, 2, "%s", *error_msg);
}
} else if (strcmp(msr->msc_reqbody_processor, "XML") == 0) {
/* Increase per-request data length counter. */
msr->msc_reqbody_no_files_length += length;
/* Process data as XML. */
if (xml_process_chunk(msr, data, length, &my_error_msg) < 0) {
*error_msg = apr_psprintf(msr->mp, "XML parsing error: %s", my_error_msg);
msr->msc_reqbody_error = 1;
msr->msc_reqbody_error_msg = *error_msg;
msr_log(msr, 2, "%s", *error_msg);
}
} else if (strcmp(msr->msc_reqbody_processor, "URLENCODED") == 0) {
/* Increase per-request data length counter. */
msr->msc_reqbody_no_files_length += length;
/* Do nothing else, URLENCODED processor does not support streaming. */
} else {
*error_msg = apr_psprintf(msr->mp, "Unknown request body processor: %s", msr->msc_reqbody_processor);
return -1;
}
} else if (msr->txcfg->reqbody_buffering != REQUEST_BODY_FORCEBUF_OFF) {
/* Increase per-request data length counter if forcing buffering. */
msr->msc_reqbody_no_files_length += length;
}
/* Check that we are not over the request body no files limit. */
if (msr->msc_reqbody_no_files_length >= (unsigned long)msr->txcfg->reqbody_no_files_limit) {
if (msr->txcfg->is_enabled == MODSEC_ENABLED) {
return -5;
} else {
*error_msg = apr_psprintf(msr->mp, "Request body no files data length "
"is larger than the configured limit (%ld).",
msr->txcfg->reqbody_no_files_limit);
}
}
/* Store data. */
if (msr->msc_reqbody_storage == MSC_REQBODY_MEMORY) {
return modsecurity_request_body_store_memory(msr, data, length, error_msg);
} else {
if (msr->msc_reqbody_storage == MSC_REQBODY_DISK) {
return modsecurity_request_body_store_disk(msr, data, length, error_msg);
}
}
/* Should never happen. */
*error_msg = apr_psprintf(msr->mp, "Internal error, unknown value for msc_reqbody_storage: %u",
msr->msc_reqbody_storage);
return -1;
}
/**
* Execute system command. First line of the output will be returned in
* the "output" parameter.
*/
int apache2_exec(modsec_rec *msr, const char *command, const char **argv, char **output) {
apr_procattr_t *procattr = NULL;
apr_proc_t *procnew = NULL;
apr_status_t rc = APR_SUCCESS;
const char *const *env = NULL;
apr_file_t *script_out = NULL;
request_rec *r = msr->r;
if (argv == NULL) {
argv = apr_pcalloc(r->pool, 3 * sizeof(char *));
argv[0] = command;
argv[1] = NULL;
}
ap_add_cgi_vars(r);
ap_add_common_vars(r);
/* PHP hack, getting around its silly security checks. */
apr_table_add(r->subprocess_env, "PATH_TRANSLATED", command);
apr_table_add(r->subprocess_env, "REDIRECT_STATUS", "302");
env = (const char * const *)ap_create_environment(r->pool, r->subprocess_env);
if (env == NULL) {
msr_log(msr, 1, "Exec: Unable to create environment.");
return -1;
}
procnew = apr_pcalloc(r->pool, sizeof(*procnew));
if (procnew == NULL) {
msr_log(msr, 1, "Exec: Unable to allocate %lu bytes.", (unsigned long)sizeof(*procnew));
return -1;
}
apr_procattr_create(&procattr, r->pool);
if (procattr == NULL) {
msr_log(msr, 1, "Exec: Unable to create procattr.");
return -1;
}
apr_procattr_io_set(procattr, APR_NO_PIPE, APR_FULL_BLOCK, APR_NO_PIPE);
apr_procattr_cmdtype_set(procattr, APR_SHELLCMD);
if (msr->txcfg->debuglog_level >= 9) {
msr_log(msr, 9, "Exec: %s", log_escape_nq(r->pool, command));
}
rc = apr_proc_create(procnew, command, argv, env, procattr, r->pool);
if (rc != APR_SUCCESS) {
msr_log(msr, 1, "Exec: Execution failed: %s (%s)", log_escape_nq(r->pool, command),
get_apr_error(r->pool, rc));
return -1;
}
apr_pool_note_subprocess(r->pool, procnew, APR_KILL_AFTER_TIMEOUT);
script_out = procnew->out;
if (!script_out) {
msr_log(msr, 1, "Exec: Failed to get script output pipe.");
return -1;
}
apr_file_pipe_timeout_set(script_out, r->server->timeout);
/* Now read from the pipe. */
{
char buf[260] = "";
char *p = buf;
apr_size_t nbytes = 255;
apr_status_t rc2;
rc2 = apr_file_read(script_out, buf, &nbytes);
if (rc2 == APR_SUCCESS) {
buf[nbytes] = 0;
/* if there is more than one line ignore them */
while(*p != 0) {
if (*p == 0x0a) *p = 0;
p++;
}
if (msr->txcfg->debuglog_level >= 4) {
msr_log(msr, 4, "Exec: First line from script output: \"%s\"",
log_escape(r->pool, buf));
}
if (output != NULL) *output = apr_pstrdup(r->pool, buf);
/* Soak up the remaining data. */
nbytes = 255;
while(apr_file_read(script_out, buf, &nbytes) == APR_SUCCESS) nbytes = 255;
} else {
msr_log(msr, 1, "Exec: Execution failed while reading output: %s (%s)",
log_escape_nq(r->pool, command),
get_apr_error(r->pool, rc2));
return -1;
}
}
apr_proc_wait(procnew, NULL, NULL, APR_WAIT);
return 1;
}
/**
* Perform geographical lookup on target.
*/
int geo_lookup(modsec_rec *msr, geo_rec *georec, const char *target, char **error_msg)
{
apr_sockaddr_t *addr;
long ipnum = 0;
char *targetip = NULL;
geo_db *geo = msr->txcfg->geo;
char errstr[1024];
unsigned char buf[2* GEO_MAX_RECORD_LEN];
const int reclen = 3; /* Algorithm needs changed if this changes */
apr_size_t nbytes;
unsigned int rec_val = 0;
apr_off_t seekto = 0;
apr_status_t ret;
int rc;
int country = 0;
int level;
double dtmp;
int itmp;
*error_msg = NULL;
/* init */
georec->country_code = geo_country_code[0];
georec->country_code3 = geo_country_code3[0];
georec->country_name = geo_country_name[0];
georec->country_continent = geo_country_continent[0];
georec->region = "";
georec->city = "";
georec->postal_code = "";
georec->latitude = 0;
georec->longitude = 0;
georec->dma_code = 0;
georec->area_code = 0;
if (msr->txcfg->debuglog_level >= 9) {
msr_log(msr, 9, "GEO: Looking up \"%s\".", log_escape(msr->mp, target));
}
/* NOTE: This only works with ipv4 */
if ((rc = apr_sockaddr_info_get(&addr, target, APR_INET, 0, 0, msr->mp)) != APR_SUCCESS) {
*error_msg = apr_psprintf(msr->mp, "Geo lookup for \"%s\" failed: %s", log_escape(msr->mp, target), apr_strerror(rc, errstr, 1024));
msr_log(msr, 4, "%s", *error_msg);
return 0;
}
if ((rc = apr_sockaddr_ip_get(&targetip, addr)) != APR_SUCCESS) {
*error_msg = apr_psprintf(msr->mp, "Geo lookup for \"%s\" failed: %s", log_escape(msr->mp, target), apr_strerror(rc, errstr, 1024));
msr_log(msr, 4, "%s", *error_msg);
return 0;
};
/* Why is this in host byte order? */
ipnum = ntohl(addr->sa.sin.sin_addr.s_addr);
if (msr->txcfg->debuglog_level >= 9) {
msr_log(msr, 9, "GEO: Using address \"%s\" (0x%08lx). %lu", targetip, ipnum, ipnum);
}
ret = apr_global_mutex_lock(msr->modsecurity->geo_lock);
if (ret != APR_SUCCESS) {
msr_log(msr, 1, "Geo Lookup: Failed to lock proc mutex: %s",
get_apr_error(msr->mp, ret));
}
for (level = 31; level >= 0; level--) {
/* Read the record */
seekto = 2 * reclen * rec_val;
apr_file_seek(geo->db, APR_SET, &seekto);
/* TODO: check rc */
rc = apr_file_read_full(geo->db, &buf, (2 * reclen), &nbytes);
/* NOTE: This is hard-coded for size 3 records */
/* Left */
if ((ipnum & (1 << level)) == 0) {
rec_val = (buf[3*0 + 0] << (0*8)) +
(buf[3*0 + 1] << (1*8)) +
(buf[3*0 + 2] << (2*8));
}
/* Right */
else {
rec_val = (buf[3*1 + 0] << (0*8)) +
(buf[3*1 + 1] << (1*8)) +
(buf[3*1 + 2] << (2*8));
}
/* If we are past the country offset, then we are done */
if (rec_val >= geo->ctry_offset) {
break;
}
}
if (rec_val == geo->ctry_offset) {
*error_msg = apr_psprintf(msr->mp, "No geo data for \"%s\").", log_escape(msr->mp, target));
msr_log(msr, 4, "%s", *error_msg);
ret = apr_global_mutex_unlock(msr->modsecurity->geo_lock);
if (ret != APR_SUCCESS) {
msr_log(msr, 1, "Geo Lookup: Failed to lock proc mutex: %s",
get_apr_error(msr->mp, ret));
}
return 0;
}
if (geo->dbtype == GEO_COUNTRY_DATABASE) {
country = rec_val;
country -= geo->ctry_offset;
if ((country <= 0) || (country > GEO_COUNTRY_LAST)) {
*error_msg = apr_psprintf(msr->mp, "No geo data for \"%s\" (country %d).", log_escape(msr->mp, target), country);
msr_log(msr, 4, "%s", *error_msg);
ret = apr_global_mutex_unlock(msr->modsecurity->geo_lock);
if (ret != APR_SUCCESS) {
msr_log(msr, 1, "Geo Lookup: Failed to lock proc mutex: %s",
get_apr_error(msr->mp, ret));
}
return 0;
}
/* Country */
georec->country_code = geo_country_code[country];
georec->country_code3 = geo_country_code3[country];
georec->country_name = geo_country_name[country];
georec->country_continent = geo_country_continent[country];
}
else {
int field_len = 0;
int rec_offset = 0;
int remaining = GEO_CITY_RECORD_LEN;
unsigned char cbuf[GEO_CITY_RECORD_LEN];
seekto = rec_val + (2 * reclen - 1) * geo->ctry_offset;
apr_file_seek(geo->db, APR_SET, &seekto);
/* TODO: check rc */
rc = apr_file_read_full(geo->db, &cbuf, sizeof(cbuf), &nbytes);
country = cbuf[0];
if ((country <= 0) || (country > GEO_COUNTRY_LAST)) {
*error_msg = apr_psprintf(msr->mp, "No geo data for \"%s\" (country %d).", log_escape(msr->mp, target), country);
msr_log(msr, 4, "%s", *error_msg);
ret = apr_global_mutex_unlock(msr->modsecurity->geo_lock);
if (ret != APR_SUCCESS) {
msr_log(msr, 1, "Geo Lookup: Failed to lock proc mutex: %s",
get_apr_error(msr->mp, ret));
}
return 0;
}
if (msr->txcfg->debuglog_level >= 9) {
msr_log(msr, 9, "GEO: rec=\"%s\"", log_escape_raw(msr->mp, cbuf, sizeof(cbuf)));
}
/* Country */
if (msr->txcfg->debuglog_level >= 9) {
msr_log(msr, 9, "GEO: country=\"%.*s\"", (1*4), log_escape_raw(msr->mp, cbuf, sizeof(cbuf)));
}
georec->country_code = geo_country_code[country];
georec->country_code3 = geo_country_code3[country];
georec->country_name = geo_country_name[country];
georec->country_continent = geo_country_continent[country];
rec_offset++;
remaining -= rec_offset;
/* Region */
field_len = field_length((const char *)cbuf+rec_offset, remaining);
if (msr->txcfg->debuglog_level >= 9) {
msr_log(msr, 9, "GEO: region=\"%.*s\"", ((field_len+1)*4), log_escape_raw(msr->mp, cbuf, sizeof(cbuf))+(rec_offset*4));
}
georec->region = apr_pstrmemdup(msr->mp, (const char *)cbuf+rec_offset, (remaining));
rec_offset += field_len + 1;
remaining -= field_len + 1;
/* City */
field_len = field_length((const char *)cbuf+rec_offset, remaining);
if (msr->txcfg->debuglog_level >= 9) {
msr_log(msr, 9, "GEO: city=\"%.*s\"", ((field_len+1)*4), log_escape_raw(msr->mp, cbuf, sizeof(cbuf))+(rec_offset*4));
}
georec->city = apr_pstrmemdup(msr->mp, (const char *)cbuf+rec_offset, (remaining));
rec_offset += field_len + 1;
remaining -= field_len + 1;
/* Postal Code */
field_len = field_length((const char *)cbuf+rec_offset, remaining);
if (msr->txcfg->debuglog_level >= 9) {
msr_log(msr, 9, "GEO: postal_code=\"%.*s\"", ((field_len+1)*4), log_escape_raw(msr->mp, cbuf, sizeof(cbuf))+(rec_offset*4));
}
georec->postal_code = apr_pstrmemdup(msr->mp, (const char *)cbuf+rec_offset, (remaining));
rec_offset += field_len + 1;
remaining -= field_len + 1;
/* Latitude */
if (msr->txcfg->debuglog_level >= 9) {
msr_log(msr, 9, "GEO: latitude=\"%.*s\"", (3*4), log_escape_raw(msr->mp, cbuf, sizeof(cbuf))+(rec_offset*4));
}
dtmp = cbuf[rec_offset] +
(cbuf[rec_offset+1] << 8) +
(cbuf[rec_offset+2] << 16);
georec->latitude = dtmp/10000 - 180;
rec_offset += 3;
remaining -= 3;
/* Longitude */
if (msr->txcfg->debuglog_level >= 9) {
msr_log(msr, 9, "GEO: longitude=\"%.*s\"", (3*4), log_escape_raw(msr->mp, cbuf, sizeof(cbuf))+(rec_offset*4));
}
dtmp = cbuf[rec_offset] +
(cbuf[rec_offset+1] << 8) +
(cbuf[rec_offset+2] << 16);
georec->longitude = dtmp/10000 - 180;
rec_offset += 3;
remaining -= 3;
/* dma/area codes are in city rev1 and US only */
if (msr->txcfg->debuglog_level >= 9) {
msr_log(msr, 9, "GEO: dma/area=\"%.*s\"", (3*4), log_escape_raw(msr->mp, cbuf, sizeof(cbuf))+(rec_offset*4));
}
if (geo->dbtype == GEO_CITY_DATABASE_1
&& georec->country_code[0] == 'U'
&& georec->country_code[1] == 'S')
{
/* DMA Code */
itmp = cbuf[rec_offset] +
(cbuf[rec_offset+1] << 8) +
(cbuf[rec_offset+2] << 16);
georec->dma_code = itmp / 1000;
georec->area_code = itmp % 1000;
rec_offset += 6;
remaining -= 6;
}
}
*error_msg = apr_psprintf(msr->mp, "Geo lookup for \"%s\" succeeded.", log_escape(msr->mp, target));
ret = apr_global_mutex_unlock(msr->modsecurity->geo_lock);
if (ret != APR_SUCCESS) {
msr_log(msr, 1, "Geo Lookup: Failed to lock proc mutex: %s",
get_apr_error(msr->mp, ret));
}
return 1;
}
apr_status_t modsecurity_tx_init(modsec_rec *msr) {
const char *s = NULL;
const apr_array_header_t *arr;
char *semicolon = NULL;
char *comma = NULL;
apr_table_entry_t *te;
int i;
/* Register TX cleanup */
apr_pool_cleanup_register(msr->mp, msr, modsecurity_tx_cleanup, apr_pool_cleanup_null);
/* Initialise C-L */
msr->request_content_length = -1;
s = apr_table_get(msr->request_headers, "Content-Length");
if (s != NULL) {
msr->request_content_length = strtol(s, NULL, 10);
}
/* Figure out whether this request has a body */
msr->reqbody_chunked = 0;
msr->reqbody_should_exist = 0;
if (msr->request_content_length == -1) {
/* There's no C-L, but is chunked encoding used? */
char *transfer_encoding = (char *)apr_table_get(msr->request_headers, "Transfer-Encoding");
if ((transfer_encoding != NULL)&&(m_strcasestr(transfer_encoding, "chunked") != NULL)) {
msr->reqbody_should_exist = 1;
msr->reqbody_chunked = 1;
}
} else {
/* C-L found */
msr->reqbody_should_exist = 1;
}
/* Initialise C-T */
msr->request_content_type = NULL;
s = apr_table_get(msr->request_headers, "Content-Type");
if (s != NULL) msr->request_content_type = s;
/* Decide what to do with the request body. */
if ((msr->request_content_type != NULL)
&& (strncasecmp(msr->request_content_type, "application/x-www-form-urlencoded", 33) == 0))
{
/* Always place POST requests with
* "application/x-www-form-urlencoded" payloads in memory.
*/
msr->msc_reqbody_storage = MSC_REQBODY_MEMORY;
msr->msc_reqbody_spilltodisk = 0;
msr->msc_reqbody_processor = "URLENCODED";
} else {
/* If the C-L is known and there's more data than
* our limit go to disk straight away.
*/
if ((msr->request_content_length != -1)
&& (msr->request_content_length > msr->txcfg->reqbody_inmemory_limit))
{
msr->msc_reqbody_storage = MSC_REQBODY_DISK;
}
/* In all other cases, try using the memory first
* but switch over to disk for larger bodies.
*/
msr->msc_reqbody_storage = MSC_REQBODY_MEMORY;
msr->msc_reqbody_spilltodisk = 1;
if (msr->request_content_type != NULL) {
if (strncasecmp(msr->request_content_type, "multipart/form-data", 19) == 0) {
msr->msc_reqbody_processor = "MULTIPART";
}
}
}
/* Check if we are forcing buffering, then use memory only. */
if (msr->txcfg->reqbody_buffering != REQUEST_BODY_FORCEBUF_OFF) {
msr->msc_reqbody_storage = MSC_REQBODY_MEMORY;
msr->msc_reqbody_spilltodisk = 0;
}
/* Initialise arguments */
msr->arguments = apr_table_make(msr->mp, 32);
if (msr->arguments == NULL) return -1;
if (msr->query_string != NULL) {
int invalid_count = 0;
if (parse_arguments(msr, msr->query_string, strlen(msr->query_string),
msr->txcfg->argument_separator, "QUERY_STRING", msr->arguments,
&invalid_count) < 0)
{
msr_log(msr, 1, "Initialisation: Error occurred while parsing QUERY_STRING arguments.");
return -1;
}
if (invalid_count) {
msr->urlencoded_error = 1;
}
}
msr->arguments_to_sanitize = apr_table_make(msr->mp, 16);
if (msr->arguments_to_sanitize == NULL) return -1;
msr->request_headers_to_sanitize = apr_table_make(msr->mp, 16);
if (msr->request_headers_to_sanitize == NULL) return -1;
msr->response_headers_to_sanitize = apr_table_make(msr->mp, 16);
if (msr->response_headers_to_sanitize == NULL) return -1;
msr->pattern_to_sanitize = apr_table_make(msr->mp, 32);
if (msr->pattern_to_sanitize == NULL) return -1;
/* remove targets */
msr->removed_targets = apr_table_make(msr->mp, 16);
if (msr->removed_targets == NULL) return -1;
/* Initialise cookies */
msr->request_cookies = apr_table_make(msr->mp, 16);
if (msr->request_cookies == NULL) return -1;
/* Initialize matched vars */
msr->matched_vars = apr_table_make(msr->mp, 8);
if (msr->matched_vars == NULL) return -1;
apr_table_clear(msr->matched_vars);
msr->perf_rules = apr_table_make(msr->mp, 8);
if (msr->perf_rules == NULL) return -1;
apr_table_clear(msr->perf_rules);
/* Locate the cookie headers and parse them */
arr = apr_table_elts(msr->request_headers);
te = (apr_table_entry_t *)arr->elts;
for (i = 0; i < arr->nelts; i++) {
if (strcasecmp(te[i].key, "Cookie") == 0) {
if (msr->txcfg->cookie_format == COOKIES_V0) {
semicolon = apr_pstrdup(msr->mp, te[i].val);
while((*semicolon != 0)&&(*semicolon != ';')) semicolon++;
if(*semicolon == ';') {
parse_cookies_v0(msr, te[i].val, msr->request_cookies, ";");
} else {
comma = apr_pstrdup(msr->mp, te[i].val);
while((*comma != 0)&&(*comma != ',')) comma++;
if(*comma == ',') {
comma++;
if(*comma == 0x20) {// looks like comma is the separator
if (msr->txcfg->debuglog_level >= 5) {
msr_log(msr, 5, "Cookie v0 parser: Using comma as a separator. Semi-colon was not identified!");
}
parse_cookies_v0(msr, te[i].val, msr->request_cookies, ",");
} else {
parse_cookies_v0(msr, te[i].val, msr->request_cookies, ";");
}
} else {
parse_cookies_v0(msr, te[i].val, msr->request_cookies, ";");
}
}
} else {
parse_cookies_v1(msr, te[i].val, msr->request_cookies);
}
}
}
/* Collections. */
msr->tx_vars = apr_table_make(msr->mp, 32);
if (msr->tx_vars == NULL) return -1;
msr->geo_vars = apr_table_make(msr->mp, 8);
if (msr->geo_vars == NULL) return -1;
msr->collections_original = apr_table_make(msr->mp, 8);
if (msr->collections_original == NULL) return -1;
msr->collections = apr_table_make(msr->mp, 8);
if (msr->collections == NULL) return -1;
msr->collections_dirty = apr_table_make(msr->mp, 8);
if (msr->collections_dirty == NULL) return -1;
/* Other */
msr->tcache = NULL;
msr->tcache_items = 0;
msr->matched_rules = apr_array_make(msr->mp, 16, sizeof(void *));
if (msr->matched_rules == NULL) return -1;
msr->matched_var = (msc_string *)apr_pcalloc(msr->mp, sizeof(msc_string));
if (msr->matched_var == NULL) return -1;
msr->highest_severity = 255; /* high, invalid value */
msr->removed_rules = apr_array_make(msr->mp, 16, sizeof(char *));
if (msr->removed_rules == NULL) return -1;
msr->removed_rules_tag = apr_array_make(msr->mp, 16, sizeof(char *));
if (msr->removed_rules_tag == NULL) return -1;
msr->removed_rules_msg = apr_array_make(msr->mp, 16, sizeof(char *));
if (msr->removed_rules_msg == NULL) return -1;
return 1;
}
static apr_table_t *collection_retrieve_ex(apr_sdbm_t *existing_dbm, modsec_rec *msr, const char *col_name,
const char *col_key, int col_key_len)
{
char *dbm_filename = NULL;
apr_status_t rc;
apr_sdbm_datum_t key;
apr_sdbm_datum_t *value = NULL;
apr_sdbm_t *dbm = NULL;
apr_table_t *col = NULL;
const apr_array_header_t *arr;
apr_table_entry_t *te;
int expired = 0;
int i;
if (msr->txcfg->data_dir == NULL) {
msr_log(msr, 1, "collection_retrieve_ex: Unable to retrieve collection (name \"%s\", key \"%s\"). Use "
"SecDataDir to define data directory first.", log_escape(msr->mp, col_name),
log_escape_ex(msr->mp, col_key, col_key_len));
goto cleanup;
}
dbm_filename = apr_pstrcat(msr->mp, msr->txcfg->data_dir, "/", col_name, NULL);
if (msr->txcfg->debuglog_level >= 9) {
msr_log(msr, 9, "collection_retrieve_ex: collection_retrieve_ex: Retrieving collection (name \"%s\", filename \"%s\")",log_escape(msr->mp, col_name),
log_escape(msr->mp, dbm_filename));
}
key.dptr = (char *)col_key;
key.dsize = col_key_len + 1;
if (existing_dbm == NULL) {
rc = apr_sdbm_open(&dbm, dbm_filename, APR_READ | APR_SHARELOCK,
CREATEMODE, msr->mp);
if (rc != APR_SUCCESS) {
dbm = NULL;
goto cleanup;
}
}
else {
dbm = existing_dbm;
}
value = (apr_sdbm_datum_t *)apr_pcalloc(msr->mp, sizeof(apr_sdbm_datum_t));
rc = apr_sdbm_fetch(dbm, value, key);
if (rc != APR_SUCCESS) {
msr_log(msr, 1, "collection_retrieve_ex: Failed to read from DBM file \"%s\": %s", log_escape(msr->mp,
dbm_filename), get_apr_error(msr->mp, rc));
goto cleanup;
}
if (value->dptr == NULL) { /* Key not found in DBM file. */
goto cleanup;
}
/* ENH Need expiration (and perhaps other metadata) accessible in blob
* form to determine if converting to a table is needed. This will
* save some cycles.
*/
/* Transform raw data into a table. */
col = collection_unpack(msr, (const unsigned char *)value->dptr, value->dsize, 1);
if (col == NULL) {
goto cleanup;
}
/* Close after "value" used from fetch or memory may be overwritten. */
if (existing_dbm == NULL) {
apr_sdbm_close(dbm);
dbm = NULL;
}
/* Remove expired variables. */
do {
arr = apr_table_elts(col);
te = (apr_table_entry_t *)arr->elts;
for (i = 0; i < arr->nelts; i++) {
if (strncmp(te[i].key, "__expire_", 9) == 0) {
msc_string *var = (msc_string *)te[i].val;
int expiry_time = atoi(var->value);
if (expiry_time <= apr_time_sec(msr->request_time)) {
char *key_to_expire = te[i].key;
/* Done early if the col expired */
if (strcmp(key_to_expire, "__expire_KEY") == 0) {
expired = 1;
}
if (msr->txcfg->debuglog_level >= 9) {
msr_log(msr, 9, "collection_retrieve_ex: Removing key \"%s\" from collection.", key_to_expire + 9);
msr_log(msr, 9, "collection_retrieve_ex: Removing key \"%s\" from collection.", key_to_expire);
}
apr_table_unset(col, key_to_expire + 9);
apr_table_unset(col, key_to_expire);
if (msr->txcfg->debuglog_level >= 4) {
msr_log(msr, 4, "collection_retrieve_ex: Removed expired variable \"%s\".", key_to_expire + 9);
}
break;
}
}
}
} while(!expired && (i != arr->nelts));
/* Delete the collection if the variable "KEY" does not exist.
*
* ENH It would probably be more efficient to hold the DBM
* open until determined if it needs deleted than to open a second
* time.
*/
if (apr_table_get(col, "KEY") == NULL) {
if (existing_dbm == NULL) {
rc = apr_sdbm_open(&dbm, dbm_filename, APR_CREATE | APR_WRITE | APR_SHARELOCK,
CREATEMODE, msr->mp);
if (rc != APR_SUCCESS) {
msr_log(msr, 1, "collection_retrieve_ex: Failed to access DBM file \"%s\": %s",
log_escape(msr->mp, dbm_filename), get_apr_error(msr->mp, rc));
dbm = NULL;
goto cleanup;
}
}
else {
dbm = existing_dbm;
}
rc = apr_sdbm_delete(dbm, key);
if (rc != APR_SUCCESS) {
msr_log(msr, 1, "collection_retrieve_ex: Failed deleting collection (name \"%s\", "
"key \"%s\"): %s", log_escape(msr->mp, col_name),
log_escape_ex(msr->mp, col_key, col_key_len), get_apr_error(msr->mp, rc));
goto cleanup;
}
if (existing_dbm == NULL) {
apr_sdbm_close(dbm);
dbm = NULL;
}
if (expired && (msr->txcfg->debuglog_level >= 9)) {
msr_log(msr, 9, "collection_retrieve_ex: Collection expired (name \"%s\", key \"%s\").", col_name,
log_escape_ex(msr->mp, col_key, col_key_len));
}
if (msr->txcfg->debuglog_level >= 4) {
msr_log(msr, 4, "collection_retrieve_ex: Deleted collection (name \"%s\", key \"%s\").",
log_escape(msr->mp, col_name), log_escape_ex(msr->mp, col_key, col_key_len));
}
goto cleanup;
}
/* Update UPDATE_RATE */
{
msc_string *var;
int create_time, counter;
var = (msc_string *)apr_table_get(col, "CREATE_TIME");
if (var == NULL) {
/* Error. */
} else {
create_time = atoi(var->value);
var = (msc_string *)apr_table_get(col, "UPDATE_COUNTER");
if (var == NULL) {
/* Error. */
} else {
apr_time_t td;
counter = atoi(var->value);
/* UPDATE_RATE is removed on store, so add it back here */
var = (msc_string *)apr_pcalloc(msr->mp, sizeof(msc_string));
var->name = "UPDATE_RATE";
var->name_len = strlen(var->name);
apr_table_setn(col, var->name, (void *)var);
/* NOTE: No rate if there has been no time elapsed */
td = (apr_time_sec(apr_time_now()) - create_time);
if (td == 0) {
var->value = apr_psprintf(msr->mp, "%d", 0);
}
else {
var->value = apr_psprintf(msr->mp, "%" APR_TIME_T_FMT,
(apr_time_t)((60 * counter)/td));
}
var->value_len = strlen(var->value);
}
}
}
if (msr->txcfg->debuglog_level >= 4) {
msr_log(msr, 4, "collection_retrieve_ex: Retrieved collection (name \"%s\", key \"%s\").",
log_escape(msr->mp, col_name), log_escape_ex(msr->mp, col_key, col_key_len));
}
if ((existing_dbm == NULL) && dbm) {
/* Should not ever get here */
msr_log(msr, 1, "collection_retrieve_ex: Internal Error: Collection remained open (name \"%s\", key \"%s\").",
log_escape(msr->mp, col_name), log_escape_ex(msr->mp, col_key, col_key_len));
apr_sdbm_close(dbm);
}
return col;
cleanup:
if ((existing_dbm == NULL) && dbm) {
apr_sdbm_close(dbm);
}
return NULL;
}
int collections_remove_stale(modsec_rec *msr, const char *col_name) {
char *dbm_filename = NULL;
apr_sdbm_datum_t key, value;
apr_sdbm_t *dbm = NULL;
apr_status_t rc;
apr_array_header_t *keys_arr;
char **keys;
apr_time_t now = apr_time_sec(msr->request_time);
int i;
if (msr->txcfg->data_dir == NULL) {
/* The user has been warned about this problem enough times already by now.
* msr_log(msr, 1, "Unable to access collection file (name \"%s\"). Use SecDataDir to "
* "define data directory first.", log_escape(msr->mp, col_name));
*/
goto error;
}
if(strstr(col_name,"USER") || strstr(col_name,"SESSION") || strstr(col_name, "RESOURCE"))
dbm_filename = apr_pstrcat(msr->mp, msr->txcfg->data_dir, "/", msr->txcfg->webappid, "_", col_name, NULL);
else
dbm_filename = apr_pstrcat(msr->mp, msr->txcfg->data_dir, "/", col_name, NULL);
if (msr->txcfg->debuglog_level >= 9) {
msr_log(msr, 9, "collections_remove_stale: Retrieving collection (name \"%s\", filename \"%s\")",log_escape(msr->mp, col_name),
log_escape(msr->mp, dbm_filename));
}
rc = apr_sdbm_open(&dbm, dbm_filename, APR_CREATE | APR_WRITE | APR_SHARELOCK,
CREATEMODE, msr->mp);
if (rc != APR_SUCCESS) {
msr_log(msr, 1, "collections_remove_stale: Failed to access DBM file \"%s\": %s", log_escape(msr->mp, dbm_filename),
get_apr_error(msr->mp, rc));
dbm = NULL;
goto error;
}
/* First get a list of all keys. */
keys_arr = apr_array_make(msr->mp, 256, sizeof(char *));
rc = apr_sdbm_lock(dbm, APR_FLOCK_SHARED);
if (rc != APR_SUCCESS) {
msr_log(msr, 1, "collections_remove_stale: Failed to lock DBM file \"%s\": %s", log_escape(msr->mp, dbm_filename),
get_apr_error(msr->mp, rc));
goto error;
}
/* No one can write to the file while doing this so
* do it as fast as possible.
*/
rc = apr_sdbm_firstkey(dbm, &key);
while(rc == APR_SUCCESS) {
char *s = apr_pstrmemdup(msr->mp, key.dptr, key.dsize - 1);
*(char **)apr_array_push(keys_arr) = s;
rc = apr_sdbm_nextkey(dbm, &key);
}
apr_sdbm_unlock(dbm);
if (msr->txcfg->debuglog_level >= 9) {
msr_log(msr, 9, "collections_remove_stale: Found %d record(s) in file \"%s\".", keys_arr->nelts,
log_escape(msr->mp, dbm_filename));
}
/* Now retrieve the entires one by one. */
keys = (char **)keys_arr->elts;
for (i = 0; i < keys_arr->nelts; i++) {
key.dptr = keys[i];
key.dsize = strlen(key.dptr) + 1;
rc = apr_sdbm_fetch(dbm, &value, key);
if (rc != APR_SUCCESS) {
msr_log(msr, 1, "collections_remove_stale: Failed reading DBM file \"%s\": %s",
log_escape(msr->mp, dbm_filename), get_apr_error(msr->mp, rc));
goto error;
}
if (value.dptr != NULL) {
apr_table_t *col = NULL;
msc_string *var = NULL;
col = collection_unpack(msr, (const unsigned char *)value.dptr, value.dsize, 0);
if (col == NULL) {
goto error;
}
var = (msc_string *)apr_table_get(col, "__expire_KEY");
if (var == NULL) {
msr_log(msr, 1, "collections_remove_stale: Collection cleanup discovered entry with no "
"__expire_KEY (name \"%s\", key \"%s\").",
log_escape(msr->mp, col_name), log_escape_ex(msr->mp, key.dptr, key.dsize - 1));
} else {
unsigned int expiry_time = atoi(var->value);
if (msr->txcfg->debuglog_level >= 9) {
msr_log(msr, 9, "collections_remove_stale: Record (name \"%s\", key \"%s\") set to expire in %" APR_TIME_T_FMT " seconds.",
log_escape(msr->mp, col_name), log_escape_ex(msr->mp, key.dptr, key.dsize - 1),
expiry_time - now);
}
if (expiry_time <= now) {
rc = apr_sdbm_delete(dbm, key);
if (rc != APR_SUCCESS) {
msr_log(msr, 1, "collections_remove_stale: Failed deleting collection (name \"%s\", "
"key \"%s\"): %s", log_escape(msr->mp, col_name),
log_escape_ex(msr->mp, key.dptr, key.dsize - 1), get_apr_error(msr->mp, rc));
goto error;
}
if (msr->txcfg->debuglog_level >= 4) {
msr_log(msr, 4, "collections_remove_stale: Removed stale collection (name \"%s\", "
"key \"%s\").", log_escape(msr->mp, col_name),
log_escape_ex(msr->mp, key.dptr, key.dsize - 1));
}
}
}
} else {
/* Ignore entry not found - it may have been removed in the meantime. */
}
}
apr_sdbm_close(dbm);
return 1;
error:
if (dbm) {
apr_sdbm_close(dbm);
}
return -1;
}
int collection_store(modsec_rec *msr, apr_table_t *col) {
char *dbm_filename = NULL;
msc_string *var_name = NULL, *var_key = NULL;
unsigned char *blob = NULL;
unsigned int blob_size, blob_offset;
apr_status_t rc;
apr_sdbm_datum_t key;
apr_sdbm_datum_t value;
apr_sdbm_t *dbm = NULL;
const apr_array_header_t *arr;
apr_table_entry_t *te;
int i;
const apr_table_t *stored_col = NULL;
const apr_table_t *orig_col = NULL;
var_name = (msc_string *)apr_table_get(col, "__name");
if (var_name == NULL) {
goto error;
}
var_key = (msc_string *)apr_table_get(col, "__key");
if (var_key == NULL) {
goto error;
}
if (msr->txcfg->data_dir == NULL) {
msr_log(msr, 1, "collection_store: Unable to store collection (name \"%s\", key \"%s\"). Use "
"SecDataDir to define data directory first.", log_escape_ex(msr->mp, var_name->value, var_name->value_len),
log_escape_ex(msr->mp, var_key->value, var_key->value_len));
goto error;
}
// ENH: lowercase the var name in the filename
dbm_filename = apr_pstrcat(msr->mp, msr->txcfg->data_dir, "/", var_name->value, NULL);
if (msr->txcfg->debuglog_level >= 9) {
msr_log(msr, 9, "collection_store: Retrieving collection (name \"%s\", filename \"%s\")",log_escape(msr->mp, var_name->value),
log_escape(msr->mp, dbm_filename));
}
/* Delete IS_NEW on store. */
apr_table_unset(col, "IS_NEW");
/* Delete UPDATE_RATE on store to save space as it is calculated */
apr_table_unset(col, "UPDATE_RATE");
/* Update the timeout value. */
{
msc_string *var = (msc_string *)apr_table_get(col, "TIMEOUT");
if (var != NULL) {
int timeout = atoi(var->value);
var = (msc_string *)apr_table_get(col, "__expire_KEY");
if (var != NULL) {
var->value = apr_psprintf(msr->mp, "%" APR_TIME_T_FMT, (apr_time_t)(apr_time_sec(apr_time_now()) + timeout));
var->value_len = strlen(var->value);
}
}
}
/* LAST_UPDATE_TIME */
{
msc_string *var = (msc_string *)apr_table_get(col, "LAST_UPDATE_TIME");
if (var == NULL) {
var = (msc_string *)apr_pcalloc(msr->mp, sizeof(msc_string));
var->name = "LAST_UPDATE_TIME";
var->name_len = strlen(var->name);
apr_table_setn(col, var->name, (void *)var);
}
var->value = apr_psprintf(msr->mp, "%" APR_TIME_T_FMT, (apr_time_t)(apr_time_sec(apr_time_now())));
var->value_len = strlen(var->value);
}
/* UPDATE_COUNTER */
{
msc_string *var = (msc_string *)apr_table_get(col, "UPDATE_COUNTER");
int counter = 0;
if (var == NULL) {
var = (msc_string *)apr_pcalloc(msr->mp, sizeof(msc_string));
var->name = "UPDATE_COUNTER";
var->name_len = strlen(var->name);
apr_table_setn(col, var->name, (void *)var);
} else {
counter = atoi(var->value);
}
var->value = apr_psprintf(msr->mp, "%d", counter + 1);
var->value_len = strlen(var->value);
}
/* ENH Make the expiration timestamp accessible in blob form so that
* it is easier/faster to determine expiration without having to
* convert back to table form
*/
rc = apr_sdbm_open(&dbm, dbm_filename, APR_CREATE | APR_WRITE | APR_SHARELOCK,
CREATEMODE, msr->mp);
if (rc != APR_SUCCESS) {
msr_log(msr, 1, "collection_store: Failed to access DBM file \"%s\": %s", log_escape(msr->mp, dbm_filename),
get_apr_error(msr->mp, rc));
dbm = NULL;
goto error;
}
/* Need to lock to pull in the stored data again and apply deltas. */
rc = apr_sdbm_lock(dbm, APR_FLOCK_EXCLUSIVE);
if (rc != APR_SUCCESS) {
msr_log(msr, 1, "collection_store: Failed to exclusivly lock DBM file \"%s\": %s", log_escape(msr->mp, dbm_filename),
get_apr_error(msr->mp, rc));
goto error;
}
/* If there is an original value, then create a delta and
* apply the delta to the current value */
orig_col = (const apr_table_t *)apr_table_get(msr->collections_original, var_name->value);
if (orig_col != NULL) {
if (msr->txcfg->debuglog_level >= 9) {
msr_log(msr, 9, "collection_store: Re-retrieving collection prior to store: %s",
apr_psprintf(msr->mp, "%.*s", var_name->value_len, var_name->value));
}
stored_col = (const apr_table_t *)collection_retrieve_ex(dbm, msr, var_name->value, var_key->value, var_key->value_len);
}
/* Merge deltas and calculate the size first. */
blob_size = 3 + 2;
arr = apr_table_elts(col);
te = (apr_table_entry_t *)arr->elts;
for (i = 0; i < arr->nelts; i++) {
msc_string *var = (msc_string *)te[i].val;
int len;
/* If there is an original value, then apply the delta
* to the latest stored value */
if (stored_col != NULL) {
const msc_string *orig_var = (const msc_string *)apr_table_get(orig_col, var->name);
if (orig_var != NULL) {
const msc_string *stored_var = (const msc_string *)apr_table_get(stored_col, var->name);
if (stored_var != NULL) {
int origval = atoi(orig_var->value);
int ourval = atoi(var->value);
int storedval = atoi(stored_var->value);
int delta = ourval - origval;
int newval = storedval + delta;
if (newval < 0) newval = 0; /* Counters never go below zero. */
var->value = apr_psprintf(msr->mp, "%d", newval);
var->value_len = strlen(var->value);
if (msr->txcfg->debuglog_level >= 9) {
msr_log(msr, 9, "collection_store: Delta applied for %s.%s %d->%d (%d): %d + (%d) = %d [%s,%d]",
log_escape_ex(msr->mp, var_name->value, var_name->value_len),
log_escape_ex(msr->mp, var->name, var->name_len),
origval, ourval, delta, storedval, delta, newval, var->value, var->value_len);
}
}
}
}
len = var->name_len + 1;
if (len >= 65536) len = 65536;
blob_size += len + 2;
len = var->value_len + 1;
if (len >= 65536) len = 65536;
blob_size += len + 2;
}
/* Now generate the binary object. */
blob = apr_pcalloc(msr->mp, blob_size);
if (blob == NULL) {
goto error;
}
blob[0] = 0x49;
blob[1] = 0x52;
blob[2] = 0x01;
blob_offset = 3;
arr = apr_table_elts(col);
te = (apr_table_entry_t *)arr->elts;
for (i = 0; i < arr->nelts; i++) {
msc_string *var = (msc_string *)te[i].val;
int len;
len = var->name_len + 1;
if (len >= 65536) len = 65536;
blob[blob_offset + 0] = (len & 0xff00) >> 8;
blob[blob_offset + 1] = len & 0x00ff;
memcpy(blob + blob_offset + 2, var->name, len - 1);
blob[blob_offset + 2 + len - 1] = '\0';
blob_offset += 2 + len;
len = var->value_len + 1;
if (len >= 65536) len = 65536;
blob[blob_offset + 0] = (len & 0xff00) >> 8;
blob[blob_offset + 1] = len & 0x00ff;
memcpy(blob + blob_offset + 2, var->value, len - 1);
blob[blob_offset + 2 + len - 1] = '\0';
blob_offset += 2 + len;
if (msr->txcfg->debuglog_level >= 9) {
msr_log(msr, 9, "collection_store: Wrote variable: name \"%s\", value \"%s\".",
log_escape_ex(msr->mp, var->name, var->name_len),
log_escape_ex(msr->mp, var->value, var->value_len));
}
}
blob[blob_offset] = 0;
blob[blob_offset + 1] = 0;
/* And, finally, store it. */
key.dptr = var_key->value;
key.dsize = var_key->value_len + 1;
value.dptr = (char *)blob;
value.dsize = blob_size;
rc = apr_sdbm_store(dbm, key, value, APR_SDBM_REPLACE);
if (rc != APR_SUCCESS) {
msr_log(msr, 1, "collection_store: Failed to write to DBM file \"%s\": %s", dbm_filename,
get_apr_error(msr->mp, rc));
goto error;
}
apr_sdbm_close(dbm);
if (msr->txcfg->debuglog_level >= 4) {
msr_log(msr, 4, "collection_store: Persisted collection (name \"%s\", key \"%s\").",
log_escape_ex(msr->mp, var_name->value, var_name->value_len),
log_escape_ex(msr->mp, var_key->value, var_key->value_len));
}
return 0;
error:
if (dbm) {
apr_sdbm_close(dbm);
}
return -1;
}
static apr_table_t *collection_unpack(modsec_rec *msr, const unsigned char *blob, unsigned int blob_size,
int log_vars)
{
apr_table_t *col = NULL;
unsigned int blob_offset;
col = apr_table_make(msr->mp, 32);
if (col == NULL) return NULL;
/* ENH verify the first 3 bytes (header) */
blob_offset = 3;
while (blob_offset + 1 < blob_size) {
msc_string *var = apr_pcalloc(msr->mp, sizeof(msc_string));
var->name_len = (blob[blob_offset] << 8) + blob[blob_offset + 1];
if (var->name_len == 0) {
/* Is the length a name length, or just the end of the blob? */
if (blob_offset < blob_size - 2) {
/* This should never happen as the name length
* includes the terminating NUL and should be 1 for ""
*/
if (msr->txcfg->debuglog_level >= 9) {
msr_log(msr, 9, "collection_unpack: BLOB[%d]: %s", blob_offset, log_escape_hex(msr->mp, blob + blob_offset, blob_size - blob_offset));
}
msr_log(msr, 4, "collection_unpack: Possibly corrupted database: var name length = 0 at blob offset %u-%u.", blob_offset, blob_offset + 1);
}
break;
}
else if (var->name_len > 65536) {
/* This should never happen as the length is restricted on store
* to 65536.
*/
if (msr->txcfg->debuglog_level >= 9) {
msr_log(msr, 9, "collection_unpack: BLOB[%d]: %s", blob_offset, log_escape_hex(msr->mp, blob + blob_offset, blob_size - blob_offset));
}
msr_log(msr, 4, "collection_unpack: Possibly corrupted database: var name length > 65536 (0x%04x) at blob offset %u-%u.", var->name_len, blob_offset, blob_offset + 1);
break;
}
blob_offset += 2;
if (blob_offset + var->name_len > blob_size) return NULL;
var->name = apr_pstrmemdup(msr->mp, (const char *)blob + blob_offset, var->name_len - 1);
blob_offset += var->name_len;
var->name_len--;
var->value_len = (blob[blob_offset] << 8) + blob[blob_offset + 1];
blob_offset += 2;
if (blob_offset + var->value_len > blob_size) return NULL;
var->value = apr_pstrmemdup(msr->mp, (const char *)blob + blob_offset, var->value_len - 1);
blob_offset += var->value_len;
var->value_len--;
if (log_vars && (msr->txcfg->debuglog_level >= 9)) {
msr_log(msr, 9, "collection_unpack: Read variable: name \"%s\", value \"%s\".",
log_escape_ex(msr->mp, var->name, var->name_len),
log_escape_ex(msr->mp, var->value, var->value_len));
}
apr_table_addn(col, var->name, (void *)var);
}
return col;
}
