/**
* Converts an Apache error log message into one line of text.
*/
char *format_error_log_message(apr_pool_t *mp, error_message_t *em) {
char *s_file = "", *s_line = "", *s_level = "";
char *s_status = "", *s_message = "";
char *msg = NULL;
if (em == NULL) return NULL;
if (em->file != NULL) {
s_file = apr_psprintf(mp, "[file \"%s\"] ",
log_escape(mp, (char *)em->file));
if (s_file == NULL) return NULL;
}
if (em->line > 0) {
s_line = apr_psprintf(mp, "[line %d] ", em->line);
if (s_line == NULL) return NULL;
}
s_level = apr_psprintf(mp, "[level %d] ", em->level);
if (s_level == NULL) return NULL;
if (em->status != 0) {
s_status = apr_psprintf(mp, "[status %d] ", em->status);
if (s_status == NULL) return NULL;
}
if (em->message != NULL) {
s_message = log_escape_nq(mp, em->message);
if (s_message == NULL) return NULL;
}
msg = apr_psprintf(mp, "%s%s%s%s%s", s_file, s_line, s_level, s_status, s_message);
if (msg == NULL) return NULL;
return msg;
}
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, "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: 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, "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, "Removing key \"%s\" from collection.", key_to_expire + 9);
msr_log(msr, 9, "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, "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, "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, "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 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, "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, "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, "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, "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, "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, "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, "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, "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, "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, "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, "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, "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, "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, "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, "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, "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, "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, "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, "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;
}
int parse_cookies_v1(modsec_rec *msr, char *_cookie_header,
apr_table_t *cookies)
{
char *attr_name = NULL, *attr_value = NULL, *p = NULL;
char *prev_attr_name = NULL;
char *cookie_header = NULL;
int cookie_count = 0;
if (_cookie_header == NULL) return -1;
// XXX Should it not match _v0 parser?
//if (_cookie_header == NULL) {
// msr_log(msr, 1, "Cookie parser: Received null for argument.");
// return -1;
//}
cookie_header = strdup(_cookie_header);
if (cookie_header == NULL) return -1;
p = cookie_header;
while(*p != 0) {
attr_name = NULL;
attr_value = NULL;
/* attribute name */
/* remove space from the beginning */
while((isspace(*p))&&(*p != 0)) p++;
attr_name = p;
while((*p != 0)&&(*p != '=')&&(*p != ';')&&(*p != ',')) p++;
/* if we've reached the end of string */
if (*p == 0) goto add_cookie;
/* if there is no cookie value supplied */
if ((*p == ';')||(*p == ',')) {
*p++ = 0; /* terminate the name */
goto add_cookie;
}
/* terminate the attribute name,
* writing over the = character
*/
*p++ = 0;
/* attribute value */
/* skip over the whitespace at the beginning */
while((isspace(*p))&&(*p != 0)) p++;
/* no value supplied */
if (*p == 0) goto add_cookie;
if (*p == '"') {
if (*++p == 0) goto add_cookie;
attr_value = p;
while((*p != 0)&&(*p != '"')) p++;
if (*p != 0) *p++ = 0;
else {
/* Do nothing about this. */
}
} else {
attr_value = p;
while((*p != 0)&&(*p != ',')&&(*p != ';')) p++;
if (*p != 0) *p++ = 0;
/* remove the whitespace from the end of cookie value */
if (attr_value != NULL) {
char *t = attr_value;
int i = 0;
while(*t != 0) {
t++;
i++;
}
while((i-- > 0)&&(isspace(*(--t)))) *t = 0;
}
}
add_cookie:
/* remove the whitespace from the end of cookie name */
if (attr_name != NULL) {
char *t = attr_name;
int i = 0;
while(*t != 0) {
t++;
i++;
}
while((i-- > 0)&&(isspace(*(--t)))) *t = 0;
}
/* add the cookie to the list now */
if ((attr_name != NULL)&&(strlen(attr_name) != 0)) {
/* handle special attribute names */
if (attr_name[0] == '$') {
if (prev_attr_name != NULL) {
/* cookie keyword, we change the name we use
* so they can have a unique name in the cookie table
*/
attr_name = apr_psprintf(msr->mp, "$%s_%s", prev_attr_name, attr_name + 1);
}
}
if (attr_value != NULL) {
if (msr->txcfg->debuglog_level >= 5) {
msr_log(msr, 5, "Adding request cookie: name \"%s\", value \"%s\"",
log_escape(msr->mp, attr_name), log_escape(msr->mp, attr_value));
}
apr_table_add(cookies, attr_name, attr_value);
} else {
if (msr->txcfg->debuglog_level >= 5) {
msr_log(msr, 5, "Adding request cookie: name \"%s\", value empty",
log_escape(msr->mp, attr_name));
}
apr_table_add(cookies, attr_name, "");
}
cookie_count++;
/* only keep the cookie names for later */
if (attr_name[0] != '$') prev_attr_name = attr_name;
}
/* at this point the *p is either 0 (in which case we exit), or
* right after the current cookie ended - we need to look for
* the next cookie
*/
while( (*p != 0)&&( (*p == ',')||(*p == ';')||(isspace(*p)) ) ) p++;
}
free(cookie_header);
return cookie_count;
}
int parse_cookies_v0(modsec_rec *msr, char *_cookie_header,
apr_table_t *cookies, const char *delim)
{
char *attr_name = NULL, *attr_value = NULL;
char *cookie_header;
char *saveptr = NULL;
int cookie_count = 0;
char *p = NULL;
if (_cookie_header == NULL) {
msr_log(msr, 1, "Cookie parser: Received null for argument.");
return -1;
}
cookie_header = strdup(_cookie_header);
if (cookie_header == NULL) return -1;
p = apr_strtok(cookie_header, delim, &saveptr);
while(p != NULL) {
attr_name = NULL;
attr_value = NULL;
/* ignore whitespace at the beginning of cookie name */
while(isspace(*p)) p++;
attr_name = p;
attr_value = strstr(p, "=");
if (attr_value != NULL) {
/* terminate cookie name */
*attr_value = 0;
/* move over to the beginning of the value */
attr_value++;
}
/* we ignore cookies with empty names */
if ((attr_name != NULL)&&(strlen(attr_name) != 0)) {
if (attr_value != NULL) {
if (msr->txcfg->debuglog_level >= 5) {
msr_log(msr, 5, "Adding request cookie: name \"%s\", value \"%s\"",
log_escape(msr->mp, attr_name), log_escape(msr->mp, attr_value));
}
apr_table_add(cookies, attr_name, attr_value);
} else {
if (msr->txcfg->debuglog_level >= 5) {
msr_log(msr, 5, "Adding request cookie: name \"%s\", value empty",
log_escape(msr->mp, attr_name));
}
apr_table_add(cookies, attr_name, "");
}
cookie_count++;
}
p = apr_strtok(NULL, delim, &saveptr);
}
free(cookie_header);
return cookie_count;
}
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;
}
/**
* 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;
}
/**
* 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;
}
/**
* Extended internal log helper function. Use msr_log instead. If fixup is
* true, the message will be stripped of any trailing newline and any
* required bytes will be escaped.
*/
static void internal_log_ex(request_rec *r, directory_config *dcfg, modsec_rec *msr,
int level, int fixup, const char *text, va_list ap)
{
apr_size_t nbytes, nbytes_written;
apr_file_t *debuglog_fd = NULL;
int filter_debug_level = 0;
char *remote = NULL;
char *parse_remote = NULL;
char *saved = NULL;
char *str = NULL;
char str1[1024] = "";
char str2[1256] = "";
/* Find the logging FD and determine the logging level from configuration. */
if (dcfg != NULL) {
if ((dcfg->debuglog_fd != NULL)&&(dcfg->debuglog_fd != NOT_SET_P)) {
debuglog_fd = dcfg->debuglog_fd;
}
if (dcfg->debuglog_level != NOT_SET) {
filter_debug_level = dcfg->debuglog_level;
}
}
/* Return immediately if we don't have where to write
* or if the log level of the message is higher than
* wanted in the log.
*/
if ((level > 3)&&( (debuglog_fd == NULL) || (level > filter_debug_level) )) return;
/* Construct the message. */
apr_vsnprintf(str1, sizeof(str1), text, ap);
if (fixup) {
int len = strlen(str1);
/* Strip line ending. */
if (len && str1[len - 1] == '\n') {
str1[len - 1] = '\0';
}
if (len > 1 && str1[len - 2] == '\r') {
str1[len - 2] = '\0';
}
}
/* Construct the log entry. */
apr_snprintf(str2, sizeof(str2),
"[%s] [%s/sid#%pp][rid#%pp][%s][%d] %s\n",
current_logtime(msr->mp), ap_get_server_name(r), (r->server),
r, ((r->uri == NULL) ? "" : log_escape_nq(msr->mp, r->uri)),
level, (fixup ? log_escape_nq(msr->mp, str1) : str1));
/* Write to the debug log. */
if ((debuglog_fd != NULL)&&(level <= filter_debug_level)) {
nbytes = strlen(str2);
apr_file_write_full(debuglog_fd, str2, nbytes, &nbytes_written);
}
/* Send message levels 1-3 to the Apache error log and
* add it to the message list in the audit log. */
if (level <= 3) {
char *unique_id = (char *)get_env_var(r, "UNIQUE_ID");
char *hostname = (char *)msr->hostname;
if (unique_id != NULL) {
unique_id = apr_psprintf(msr->mp, " [unique_id \"%s\"]",
log_escape(msr->mp, unique_id));
}
else unique_id = "";
if (hostname != NULL) {
hostname = apr_psprintf(msr->mp, " [hostname \"%s\"]",
log_escape(msr->mp, hostname));
}
else hostname = "";
#if AP_SERVER_MAJORVERSION_NUMBER > 1 && AP_SERVER_MINORVERSION_NUMBER > 2
ap_log_rerror(APLOG_MARK, APLOG_ERR | APLOG_NOERRNO, 0, r,
"[client %s] ModSecurity: %s%s [uri \"%s\"]%s", r->useragent_ip ? r->useragent_ip : r->connection->client_ip, str1,
hostname, log_escape(msr->mp, r->uri), unique_id);
#else
ap_log_error(APLOG_MARK, APLOG_ERR | APLOG_NOERRNO, 0, r->server,
"[client %s] ModSecurity: %s%s [uri \"%s\"]%s", msr->remote_addr ? msr->remote_addr : r->connection->remote_ip, str1,
hostname, log_escape(msr->mp, r->uri), unique_id);
#endif
/* Add this message to the list. */
if (msr != NULL) {
/* Force relevency if this is an alert */
msr->is_relevant++;
*(const char **)apr_array_push(msr->alerts) = apr_pstrdup(msr->mp, str1);
}
}
return;
}
