ModSecurity/apache2/persist_dbm.c
Marc Stern 35e97b5145 When there's a problem writing a collection key (it's too big for instance), we have no info on the involved key.
This adds the key name in the log (and its size, as this is the problem most of the time).
2024-02-01 11:48:21 +01:00

809 lines
29 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 "persist_dbm.h"
#include "apr_sdbm.h"
/**
*
*/
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;
}
/**
*
*/
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;
char *userinfo = get_username(msr->mp);
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, "/", userinfo, "-", 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) {
#ifdef GLOBAL_COLLECTION_LOCK
rc = apr_global_mutex_lock(msr->modsecurity->dbm_lock);
if (rc != APR_SUCCESS) {
msr_log(msr, 1, "collection_retrieve_ex: Failed to lock proc mutex: %s",
get_apr_error(msr->mp, rc));
goto cleanup;
}
#endif
rc = apr_sdbm_open(&dbm, dbm_filename, APR_READ | APR_SHARELOCK,
CREATEMODE, msr->mp);
if (rc != APR_SUCCESS) {
dbm = NULL;
#ifdef GLOBAL_COLLECTION_LOCK
apr_global_mutex_unlock(msr->modsecurity->dbm_lock);
#endif
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);
#ifdef GLOBAL_COLLECTION_LOCK
apr_global_mutex_unlock(msr->modsecurity->dbm_lock);
#endif
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) {
#ifdef GLOBAL_COLLECTION_LOCK
rc = apr_global_mutex_lock(msr->modsecurity->dbm_lock);
if (rc != APR_SUCCESS) {
msr_log(msr, 1, "collection_retrieve_ex: Failed to lock proc mutex: %s",
get_apr_error(msr->mp, rc));
goto cleanup;
}
#endif
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;
#ifdef GLOBAL_COLLECTION_LOCK
apr_global_mutex_unlock(msr->modsecurity->dbm_lock);
#endif
goto cleanup;
}
}
else {
dbm = existing_dbm;
}
rc = apr_sdbm_delete(dbm, key);
if (rc != APR_SUCCESS) {
#ifdef LOG_NO_COLL_DELET_PB
if (msr->txcfg->debuglog_level >= 9)
#endif
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));
msr->msc_sdbm_delete_error = 1;
goto cleanup;
}
if (existing_dbm == NULL) {
apr_sdbm_close(dbm);
#ifdef GLOBAL_COLLECTION_LOCK
apr_global_mutex_unlock(msr->modsecurity->dbm_lock);
#endif
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);
#ifdef GLOBAL_COLLECTION_LOCK
apr_global_mutex_unlock(msr->modsecurity->dbm_lock);
#endif
}
return col;
cleanup:
if ((existing_dbm == NULL) && dbm) {
apr_sdbm_close(dbm);
#ifdef GLOBAL_COLLECTION_LOCK
apr_global_mutex_unlock(msr->modsecurity->dbm_lock);
#endif
}
return NULL;
}
/**
*
*/
apr_table_t *collection_retrieve(modsec_rec *msr, const char *col_name,
const char *col_key, int col_key_len)
{
apr_time_t time_before = apr_time_now();
apr_table_t *rtable = NULL;
rtable = collection_retrieve_ex(NULL, msr, col_name, col_key, col_key_len);
msr->time_storage_read += apr_time_now() - time_before;
return rtable;
}
/**
*
*/
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;
char *userinfo = get_username(msr->mp);
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, "/", userinfo, "-", 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));
}
#ifdef GLOBAL_COLLECTION_LOCK
/* Need to lock to pull in the stored data again and apply deltas. */
rc = apr_global_mutex_lock(msr->modsecurity->dbm_lock);
if (rc != APR_SUCCESS) {
msr_log(msr, 1, "collection_store: Failed to lock proc mutex: %s",
get_apr_error(msr->mp, rc));
goto error;
}
#endif
/* 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) {
#ifdef GLOBAL_COLLECTION_LOCK
apr_global_mutex_unlock(msr->modsecurity->dbm_lock);
#endif
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;
}
#ifndef GLOBAL_COLLECTION_LOCK
/* 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;
}
#endif
/* 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);
}
}
}
}
// Allocate blob_size for keys
len = var->name_len + 1;
if (len >= 65536) len = 65536;
blob_size += len + 2;
// Allocate blob_size for values
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) {
if (dbm != NULL) {
#ifdef GLOBAL_COLLECTION_LOCK
apr_sdbm_close(dbm);
apr_global_mutex_unlock(msr->modsecurity->dbm_lock);
#else
apr_sdbm_unlock(dbm);
apr_sdbm_close(dbm);
#endif
}
return -1;
}
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 (key=%s, length=%d)", dbm_filename,
get_apr_error(msr->mp, rc), key.dptr, value.dsize);
if (dbm != NULL) {
#ifdef GLOBAL_COLLECTION_LOCK
apr_sdbm_close(dbm);
apr_global_mutex_unlock(msr->modsecurity->dbm_lock);
#else
apr_sdbm_unlock(dbm);
apr_sdbm_close(dbm);
#endif
}
return -1;
}
#ifdef GLOBAL_COLLECTION_LOCK
apr_sdbm_close(dbm);
apr_global_mutex_unlock(msr->modsecurity->dbm_lock);
#else
apr_sdbm_unlock(dbm);
apr_sdbm_close(dbm);
#endif
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:
return -1;
}
/**
*
*/
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;
char *userinfo = get_username(msr->mp);
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, "/", userinfo, "-", msr->txcfg->webappid, "_", col_name, NULL);
else
dbm_filename = apr_pstrcat(msr->mp, msr->txcfg->data_dir, "/", userinfo, "-", 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));
}
#ifdef GLOBAL_COLLECTION_LOCK
rc = apr_global_mutex_lock(msr->modsecurity->dbm_lock);
if (rc != APR_SUCCESS) {
msr_log(msr, 1, "collections_remove_stale: Failed to lock proc mutex: %s",
get_apr_error(msr->mp, rc));
goto error;
}
#endif
rc = apr_sdbm_open(&dbm, dbm_filename, APR_CREATE | APR_WRITE | APR_SHARELOCK,
CREATEMODE, msr->mp);
if (rc != APR_SUCCESS) {
#ifdef GLOBAL_COLLECTION_LOCK
apr_global_mutex_unlock(msr->modsecurity->dbm_lock);
#endif
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 *));
#ifndef GLOBAL_COLLECTION_LOCK
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;
}
#endif
/* 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) {
if (key.dsize) {
char *s = apr_pstrmemdup(msr->mp, key.dptr, key.dsize - 1);
*(char **)apr_array_push(keys_arr) = s;
}
rc = apr_sdbm_nextkey(dbm, &key);
}
#ifndef GLOBAL_COLLECTION_LOCK
apr_sdbm_unlock(dbm);
#endif
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) {
#ifdef LOG_NO_COLL_DELET_PB
if (msr->txcfg->debuglog_level >= 9)
#endif
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));
msr->msc_sdbm_delete_error = 1;
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);
#ifdef GLOBAL_COLLECTION_LOCK
apr_global_mutex_unlock(msr->modsecurity->dbm_lock);
#endif
return 1;
error:
if (dbm) {
apr_sdbm_close(dbm);
#ifdef GLOBAL_COLLECTION_LOCK
apr_global_mutex_unlock(msr->modsecurity->dbm_lock);
#endif
}
return -1;
}