/** * 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; }