Transformation caching fixes. See #364.

This commit is contained in:
brectanus
2008-07-29 00:18:16 +00:00
parent ade22567bf
commit 6ebc5ad6e7
8 changed files with 425 additions and 114 deletions

23
CHANGES
View File

@@ -1,3 +1,26 @@
25 Jun 2008 - 2.5.6
-------------------
* Fixed an issue with transformation cache using the original value
when the last transformation in a chain did not modify the value. This
fixes the potential match failure due to a failed transformation.
* Fixed an issue with transformation cache where only the first of duplicate
values in a collection was inspected. This fixes the potential of missing
a duplicate target value for inspection.
* Fixed an issue with the transformation cache using too much RAM, potentially
crashing Apache with a large number of cache entries. To better control
caching, two new options have been added:
maxitems: Max number of items to cache (default 1024)
incremental: Whether to cache incrementally (default off)
* Transformation caching is now off by default as it may not be appropriate
in all environments.
* Added an experimental regression testing suite.
05 Jun 2008 - 2.5.5 05 Jun 2008 - 2.5.5
------------------- -------------------

View File

@@ -102,8 +102,10 @@ void *create_directory_config(apr_pool_t *mp, char *path) {
/* Cache */ /* Cache */
dcfg->cache_trans = NOT_SET; dcfg->cache_trans = NOT_SET;
dcfg->cache_trans_incremental = NOT_SET;
dcfg->cache_trans_min = NOT_SET; dcfg->cache_trans_min = NOT_SET;
dcfg->cache_trans_max = NOT_SET; dcfg->cache_trans_max = NOT_SET;
dcfg->cache_trans_maxitems = NOT_SET;
dcfg->component_signatures = apr_array_make(mp, 16, sizeof(char *)); dcfg->component_signatures = apr_array_make(mp, 16, sizeof(char *));
@@ -439,10 +441,14 @@ void *merge_directory_configs(apr_pool_t *mp, void *_parent, void *_child) {
/* Cache */ /* Cache */
merged->cache_trans = (child->cache_trans == NOT_SET merged->cache_trans = (child->cache_trans == NOT_SET
? parent->cache_trans : child->cache_trans); ? parent->cache_trans : child->cache_trans);
merged->cache_trans_incremental = (child->cache_trans_incremental == NOT_SET
? parent->cache_trans_incremental : child->cache_trans_incremental);
merged->cache_trans_min = (child->cache_trans_min == (apr_size_t)NOT_SET merged->cache_trans_min = (child->cache_trans_min == (apr_size_t)NOT_SET
? parent->cache_trans_min : child->cache_trans_min); ? parent->cache_trans_min : child->cache_trans_min);
merged->cache_trans_max = (child->cache_trans_max == (apr_size_t)NOT_SET merged->cache_trans_max = (child->cache_trans_max == (apr_size_t)NOT_SET
? parent->cache_trans_max : child->cache_trans_max); ? parent->cache_trans_max : child->cache_trans_max);
merged->cache_trans_maxitems = (child->cache_trans_maxitems == (apr_size_t)NOT_SET
? parent->cache_trans_maxitems : child->cache_trans_maxitems);
/* Merge component signatures. */ /* Merge component signatures. */
merged->component_signatures = apr_array_append(mp, parent->component_signatures, merged->component_signatures = apr_array_append(mp, parent->component_signatures,
@@ -528,9 +534,11 @@ void init_directory_config(directory_config *dcfg) {
if (dcfg->geo == NOT_SET_P) dcfg->geo = NULL; if (dcfg->geo == NOT_SET_P) dcfg->geo = NULL;
/* Cache */ /* Cache */
if (dcfg->cache_trans == NOT_SET) dcfg->cache_trans = MODSEC_CACHE_ENABLED; if (dcfg->cache_trans == NOT_SET) dcfg->cache_trans = MODSEC_CACHE_DISABLED;
if (dcfg->cache_trans_min == (apr_size_t)NOT_SET) dcfg->cache_trans_min = 15; if (dcfg->cache_trans_incremental == NOT_SET) dcfg->cache_trans_incremental = 0;
if (dcfg->cache_trans_max == (apr_size_t)NOT_SET) dcfg->cache_trans_max = 0; if (dcfg->cache_trans_min == (apr_size_t)NOT_SET) dcfg->cache_trans_min = 32;
if (dcfg->cache_trans_max == (apr_size_t)NOT_SET) dcfg->cache_trans_max = 1024;
if (dcfg->cache_trans_maxitems == (apr_size_t)NOT_SET) dcfg->cache_trans_maxitems = 1024;
if (dcfg->request_encoding == NOT_SET_P) dcfg->request_encoding = NULL; if (dcfg->request_encoding == NOT_SET_P) dcfg->request_encoding = NULL;
} }
@@ -1650,7 +1658,7 @@ static const char *cmd_cache_transformations(cmd_parms *cmd, void *_dcfg, const
/* Process options */ /* Process options */
if (p2 != NULL) { if (p2 != NULL) {
apr_table_t *vartable = apr_table_make(cmd->pool, 10); apr_table_t *vartable = apr_table_make(cmd->pool, 4);
apr_status_t rc; apr_status_t rc;
char *error_msg = NULL; char *error_msg = NULL;
const char *charval = NULL; const char *charval = NULL;
@@ -1664,7 +1672,18 @@ static const char *cmd_cache_transformations(cmd_parms *cmd, void *_dcfg, const
return apr_psprintf(cmd->pool, "ModSecurity: Unable to parse options for SecCacheTransformations: %s", error_msg); return apr_psprintf(cmd->pool, "ModSecurity: Unable to parse options for SecCacheTransformations: %s", error_msg);
} }
/* minval */ /* incremental */
charval = apr_table_get(vartable, "incremental");
if (charval != NULL) {
if (strcasecmp(charval, "on") == 0)
dcfg->cache_trans_incremental = 1;
else if (strcasecmp(charval, "off") == 0)
dcfg->cache_trans_incremental = 0;
else
return apr_psprintf(cmd->pool, "ModSecurity: SecCacheTransformations invalid incremental value: %s", charval);
}
/* minlen */
charval = apr_table_get(vartable, "minlen"); charval = apr_table_get(vartable, "minlen");
if (charval != NULL) { if (charval != NULL) {
intval = apr_atoi64(charval); intval = apr_atoi64(charval);
@@ -1684,7 +1703,7 @@ static const char *cmd_cache_transformations(cmd_parms *cmd, void *_dcfg, const
dcfg->cache_trans_min = (apr_size_t)intval; dcfg->cache_trans_min = (apr_size_t)intval;
} }
/* maxval */ /* maxlen */
charval = apr_table_get(vartable, "maxlen"); charval = apr_table_get(vartable, "maxlen");
if (charval != NULL) { if (charval != NULL) {
intval = apr_atoi64(charval); intval = apr_atoi64(charval);
@@ -1707,6 +1726,19 @@ static const char *cmd_cache_transformations(cmd_parms *cmd, void *_dcfg, const
dcfg->cache_trans_max = (apr_size_t)intval; dcfg->cache_trans_max = (apr_size_t)intval;
} }
/* maxitems */
charval = apr_table_get(vartable, "maxitems");
if (charval != NULL) {
intval = apr_atoi64(charval);
if (errno == ERANGE) {
return apr_psprintf(cmd->pool, "ModSecurity: SecCacheTransformations maxitems out of range: %s", charval);
}
if (intval < 0) {
return apr_psprintf(cmd->pool, "ModSecurity: SecCacheTransformations maxitems must be positive: %s", charval);
}
dcfg->cache_trans_maxitems = (apr_size_t)intval;
}
} }
return NULL; return NULL;

View File

@@ -312,8 +312,9 @@ apr_status_t modsecurity_tx_init(modsec_rec *msr) {
if (msr->collections_dirty == NULL) return -1; if (msr->collections_dirty == NULL) return -1;
/* Other */ /* Other */
msr->tcache = apr_hash_make(msr->mp); msr->tcache = NULL;
if (msr->tcache == NULL) return -1; msr->tcache_items = 0;
msr->tcache_limit_warn = 0;
msr->matched_rules = apr_array_make(msr->mp, 16, sizeof(void *)); msr->matched_rules = apr_array_make(msr->mp, 16, sizeof(void *));
if (msr->matched_rules == NULL) return -1; if (msr->matched_rules == NULL) return -1;
@@ -495,19 +496,76 @@ static apr_status_t modsecurity_process_phase_logging(modsec_rec *msr) {
apr_status_t modsecurity_process_phase(modsec_rec *msr, unsigned int phase) { apr_status_t modsecurity_process_phase(modsec_rec *msr, unsigned int phase) {
/* Check if we should run. */ /* Check if we should run. */
if ((msr->was_intercepted)&&(phase != PHASE_LOGGING)) { if ((msr->was_intercepted)&&(phase != PHASE_LOGGING)) {
msr_log(msr, 4, "Skipping phase %i as request was already intercepted.", phase); msr_log(msr, 4, "Skipping phase %d as request was already intercepted.", phase);
return 0; return 0;
} }
/* Do not process the same phase twice. */ /* Do not process the same phase twice. */
if (msr->phase >= phase) { if (msr->phase >= phase) {
msr_log(msr, 4, "Skipping phase %i because it was previously run (at %i now).", msr_log(msr, 4, "Skipping phase %d because it was previously run (at %d now).",
phase, msr->phase); phase, msr->phase);
return 0; return 0;
} }
msr->phase = phase; msr->phase = phase;
/* Clear out the transformation cache at the start of each phase */
if (msr->txcfg->cache_trans == MODSEC_CACHE_ENABLED) {
if (msr->tcache) {
apr_hash_index_t *hi;
void *dummy;
apr_table_t *tab;
const void *key;
apr_ssize_t klen;
#ifdef CACHE_DEBUG
apr_pool_t *mptmp = msr->msc_rule_mptmp;
const apr_array_header_t *ctarr;
const apr_table_entry_t *ctelts;
msre_cache_rec *rec;
int cn = 0;
int ri;
#endif
for (hi = apr_hash_first(msr->mp, msr->tcache); hi; hi = apr_hash_next(hi)) {
msre_var *keyvar = NULL;
apr_hash_this(hi, &key, &klen, &dummy);
tab = (apr_table_t *)dummy;
if (tab == NULL) continue;
#ifdef CACHE_DEBUG
/* Dump the cache out as we clear */
keyvar = (msre_var *)key;
ctarr = apr_table_elts(tab);
ctelts = (const apr_table_entry_t*)ctarr->elts;
for (ri = 0; ri < ctarr->nelts; ri++) {
cn++;
rec = (msre_cache_rec *)ctelts[ri].val;
if (rec->changed) {
if (msr->txcfg->debuglog_level >= 9) {
msr_log(msr, 9, "CACHE: %5d) hits=%d key=%pp var=\"%s\" %x;%s=\"%s\" (%pp - %pp)", cn, rec->hits, keyvar, keyvar->name, rec->num, rec->path, log_escape_nq_ex(mptmp, rec->val, rec->val_len), rec->val, rec->val + rec->val_len);
}
}
else {
if (msr->txcfg->debuglog_level >= 9) {
msr_log(msr, 9, "CACHE: %5d) hits=%d key=%pp var=\"%s\" %x;%s=<no change>", cn, rec->hits, keyvar, keyvar->name, rec->num, rec->path);
}
}
}
#endif
apr_table_clear(tab);
apr_hash_set(msr->tcache, key, klen, NULL);
}
msr_log(msr, 9, "Cleared transformation cache for phase %d", msr->phase);
}
msr->tcache_items = 0;
msr->tcache = apr_hash_make(msr->mp);
if (msr->tcache == NULL) return -1;
}
switch(phase) { switch(phase) {
case 1 : case 1 :
return modsecurity_process_phase_request_headers(msr); return modsecurity_process_phase_request_headers(msr);

View File

@@ -365,6 +365,8 @@ struct modsec_rec {
/* data cache */ /* data cache */
apr_hash_t *tcache; apr_hash_t *tcache;
apr_size_t tcache_items;
int tcache_limit_warn;
/* removed rules */ /* removed rules */
apr_array_header_t *removed_rules; apr_array_header_t *removed_rules;
@@ -474,8 +476,10 @@ struct directory_config {
/* Cache */ /* Cache */
int cache_trans; int cache_trans;
int cache_trans_incremental;
apr_size_t cache_trans_min; apr_size_t cache_trans_min;
apr_size_t cache_trans_max; apr_size_t cache_trans_max;
apr_size_t cache_trans_maxitems;
/* Array to hold signatures of components, which will /* Array to hold signatures of components, which will
* appear in the ModSecurity signature in the audit log. * appear in the ModSecurity signature in the audit log.

View File

@@ -1774,7 +1774,7 @@ static apr_status_t msre_rule_process_normal(msre_rule *rule, modsec_rec *msr) {
apr_pool_t *mptmp = msr->msc_rule_mptmp; apr_pool_t *mptmp = msr->msc_rule_mptmp;
apr_table_t *tartab = NULL; apr_table_t *tartab = NULL;
apr_table_t *vartab = NULL; apr_table_t *vartab = NULL;
int i, rc, match_count = 0; int i, rc = 0, match_count = 0;
int invocations = 0; int invocations = 0;
int multi_match = 0; int multi_match = 0;
@@ -1857,12 +1857,12 @@ static apr_status_t msre_rule_process_normal(msre_rule *rule, modsec_rec *msr) {
for (i = 0; i < arr->nelts; i++) { for (i = 0; i < arr->nelts; i++) {
int changed; int changed;
int usecache = 0; int usecache = 0;
apr_table_t **carr = NULL;
apr_table_t *cachetab = NULL; apr_table_t *cachetab = NULL;
apr_time_t time_before_trans = 0; apr_time_t time_before_trans = 0;
msre_var *var;
/* Take one target. */ /* Take one target. */
msre_var *var = (msre_var *)te[i].val; var = (msre_var *)te[i].val;
/* Is this var cacheable? */ /* Is this var cacheable? */
if (msr->txcfg->cache_trans != MODSEC_CACHE_DISABLED) { if (msr->txcfg->cache_trans != MODSEC_CACHE_DISABLED) {
@@ -1889,23 +1889,29 @@ static apr_status_t msre_rule_process_normal(msre_rule *rule, modsec_rec *msr) {
msr_log(msr, 9, "CACHE: Enabled"); msr_log(msr, 9, "CACHE: Enabled");
} }
#ifdef CACHE_DEBUG
msr_log(msr, 9, "CACHE: Fetching cache entry from hash=%pp: %pp=%s", msr->tcache, var, var->name);
#endif
/* Fetch cache table for this target */ /* Fetch cache table for this target */
carr = (apr_table_t **)apr_hash_get(msr->tcache, var->name, APR_HASH_KEY_STRING); cachetab = (apr_table_t *)apr_hash_get(msr->tcache, var, sizeof(msre_var *));
if (carr != NULL) { /* Create an empty cache table if this is the first time */
cachetab = carr[msr->phase]; #ifdef CACHE_DEBUG
if (cachetab) {
msr_log(msr, 9, "CACHE: Using cache table %pp", cachetab);
} }
else { else {
/* Create an array of cache tables (one table per phase) */ #else
carr = (apr_table_t **)apr_pcalloc(msr->mp, (sizeof(apr_table_t *) * (PHASE_LAST + 1))); if (cachetab == NULL) {
if (carr == NULL) return -1; #endif
memset(carr, 0, (sizeof(apr_table_t *) * (PHASE_LAST + 1))); cachetab = apr_table_make(msr->mp, 3);
apr_hash_set(msr->tcache, var->name, APR_HASH_KEY_STRING, carr); apr_hash_set(msr->tcache, var, sizeof(msre_var *), cachetab);
#ifdef CACHE_DEBUG
msr_log(msr, 9, "CACHE: Created a new cache table %pp", cachetab);
#endif
} }
/* Create an empty cache table if this is the first time */
if (cachetab == NULL) {
cachetab = carr[msr->phase] = apr_table_make(msr->mp, 5);
}
} }
else { else {
usecache = 0; usecache = 0;
@@ -1936,7 +1942,10 @@ static apr_status_t msre_rule_process_normal(msre_rule *rule, modsec_rec *msr) {
msre_action *action; msre_action *action;
msre_tfn_metadata *metadata; msre_tfn_metadata *metadata;
apr_table_t *normtab; apr_table_t *normtab;
const char *lastvarval = NULL;
apr_size_t lastvarlen = 0;
changed = 0;
normtab = apr_table_make(mptmp, 10); normtab = apr_table_make(mptmp, 10);
if (normtab == NULL) return -1; if (normtab == NULL) return -1;
tarr = apr_table_elts(rule->actionset->actions); tarr = apr_table_elts(rule->actionset->actions);
@@ -1971,6 +1980,10 @@ static apr_status_t msre_rule_process_normal(msre_rule *rule, modsec_rec *msr) {
tfnspath = apr_psprintf(msr->mp, "%s%s%s", (tfnspath?tfnspath:""), (tfnspath?",":""), action->param); tfnspath = apr_psprintf(msr->mp, "%s%s%s", (tfnspath?tfnspath:""), (tfnspath?",":""), action->param);
tfnskey = apr_psprintf(msr->mp, "%x;%s", tfnscount, tfnspath); tfnskey = apr_psprintf(msr->mp, "%x;%s", tfnscount, tfnspath);
crec = (msre_cache_rec *)apr_table_get(cachetab, tfnskey); crec = (msre_cache_rec *)apr_table_get(cachetab, tfnskey);
#ifdef CACHE_DEBUG
msr_log(msr, 9, "CACHE: %s %s cached=%d", var->name, tfnskey, (crec ? 1 : 0));
#endif
if (crec != NULL) { if (crec != NULL) {
last_crec = crec; last_crec = crec;
last_cached_tfn = tfnscount; last_cached_tfn = tfnscount;
@@ -1983,7 +1996,9 @@ static apr_status_t msre_rule_process_normal(msre_rule *rule, modsec_rec *msr) {
/* If the last cached tfn is the last in the list /* If the last cached tfn is the last in the list
* then we can stop here and just execute the action immediatly * then we can stop here and just execute the action immediatly
*/ */
if (usecache && !multi_match && (crec != NULL) && (crec == last_crec)) { if (usecache && !multi_match &&
(crec != NULL) && (crec == last_crec))
{
crec->hits++; crec->hits++;
if (crec->changed) { if (crec->changed) {
var->value = apr_pmemdup(msr->mp, crec->val, crec->val_len); var->value = apr_pmemdup(msr->mp, crec->val, crec->val_len);
@@ -1991,7 +2006,7 @@ static apr_status_t msre_rule_process_normal(msre_rule *rule, modsec_rec *msr) {
} }
if (msr->txcfg->debuglog_level >= 9) { if (msr->txcfg->debuglog_level >= 9) {
msr_log(msr, 9, "T (%d) %s: \"%s\" [cached hits=%d]", crec->changed, crec->path, log_escape_nq_ex(mptmp, var->value, var->value_len), crec->hits); msr_log(msr, 9, "T (%d) %s: \"%s\" [fully cached hits=%d]", crec->changed, crec->path, log_escape_nq_ex(mptmp, var->value, var->value_len), crec->hits);
} }
#if !defined(PERFORMANCE_MEASUREMENT) #if !defined(PERFORMANCE_MEASUREMENT)
@@ -2046,7 +2061,7 @@ static apr_status_t msre_rule_process_normal(msre_rule *rule, modsec_rec *msr) {
tfnspath = last_crec->path; tfnspath = last_crec->path;
last_crec->hits++; last_crec->hits++;
if ((changed = last_crec->changed) == 1) { if ((changed = last_crec->changed) > 0) {
var->value = apr_pmemdup(msr->mp, last_crec->val, last_crec->val_len); var->value = apr_pmemdup(msr->mp, last_crec->val, last_crec->val_len);
var->value_len = last_crec->val_len; var->value_len = last_crec->val_len;
} }
@@ -2056,7 +2071,6 @@ static apr_status_t msre_rule_process_normal(msre_rule *rule, modsec_rec *msr) {
} }
} }
else { else {
changed = 1;
tfnspath = NULL; tfnspath = NULL;
k = 0; k = 0;
} }
@@ -2065,13 +2079,14 @@ static apr_status_t msre_rule_process_normal(msre_rule *rule, modsec_rec *msr) {
for (; k < tarr->nelts; k++) { for (; k < tarr->nelts; k++) {
char *rval = NULL; char *rval = NULL;
long int rval_length = -1; long int rval_length = -1;
int tfnchanged = 0;
/* In multi-match mode we execute the operator /* In multi-match mode we execute the operator
* once at the beginning and then once every * once at the beginning and then once every
* time the variable is changed by the transformation * time the variable is changed by the transformation
* function. * function.
*/ */
if (multi_match && changed) { if (multi_match && (k == 0 || tfnchanged)) {
invocations++; invocations++;
#if !defined(PERFORMANCE_MEASUREMENT) #if !defined(PERFORMANCE_MEASUREMENT)
@@ -2109,45 +2124,38 @@ static apr_status_t msre_rule_process_normal(msre_rule *rule, modsec_rec *msr) {
action = (msre_action *)telts[k].val; action = (msre_action *)telts[k].val;
metadata = (msre_tfn_metadata *)action->param_data; metadata = (msre_tfn_metadata *)action->param_data;
/* Try to use the cache */ tfnchanged = metadata->execute(mptmp,
if (usecache) { (unsigned char *)var->value, var->value_len,
/* Generate the cache key */
tfnspath = apr_psprintf(msr->mp, "%s%s%s", (tfnspath?tfnspath:""), (tfnspath?",":""), action->param);
tfnskey = apr_psprintf(msr->mp, "%x;%s", (k + 1), tfnspath);
/* Try to fetch this transformation from cache */
#ifdef CACHE_DEBUG
msr_log(msr, 9, "CACHE: Fetching %s %s ", var->name, tfnskey);
#endif
crec = (msre_cache_rec *)apr_table_get(cachetab, tfnskey);
if (crec != NULL) {
crec->hits++;
if ((changed = crec->changed) == 1) {
var->value = apr_pmemdup(msr->mp, crec->val, crec->val_len);
var->value_len = crec->val_len;
}
if (msr->txcfg->debuglog_level >= 9) {
msr_log(msr, 9, "T (%d) %s: \"%s\" [cached hits=%d]", crec->changed, metadata->name, log_escape_nq_ex(mptmp, var->value, var->value_len), crec->hits);
}
continue;
}
}
rc = metadata->execute(mptmp, (unsigned char *)var->value, var->value_len,
&rval, &rval_length); &rval, &rval_length);
if (rc < 0) { if (tfnchanged < 0) {
return -1; return -1;
} }
changed = rc; if (tfnchanged) {
changed++;
}
var->value = rval; var->value = rval;
var->value_len = rval_length; var->value_len = rval_length;
/* Cache the transformation */ /* Cache the transformation */
if (usecache) { if (usecache) {
int tfnsnum = k + 1;
/* Generate the cache key */
tfnspath = apr_psprintf(msr->mp, "%s%s%s", (tfnspath?tfnspath:""), (tfnspath?",":""), action->param);
tfnskey = apr_psprintf(msr->mp, "%x;%s", tfnsnum, tfnspath);
if ((msr->txcfg->cache_trans_maxitems != 0) &&
(msr->tcache_items >= msr->txcfg->cache_trans_maxitems))
{
msr_log(msr, 4, "CACHE: Disabled - maxitems=%" APR_SIZE_T_FMT
" limit reached.",
msr->txcfg->cache_trans_maxitems);
}
else if (msr->txcfg->cache_trans_incremental ||
(tfnsnum == tarr->nelts))
{
/* ENH1: Add flag to vars to tell which ones can change across phases store the rest in a global cache */ /* ENH1: Add flag to vars to tell which ones can change across phases store the rest in a global cache */
crec = (msre_cache_rec *)apr_pcalloc(msr->mp, sizeof(msre_cache_rec)); crec = (msre_cache_rec *)apr_pcalloc(msr->mp, sizeof(msre_cache_rec));
if (crec == NULL) return -1; if (crec == NULL) return -1;
@@ -2156,13 +2164,39 @@ static apr_status_t msre_rule_process_normal(msre_rule *rule, modsec_rec *msr) {
crec->changed = changed; crec->changed = changed;
crec->num = k + 1; crec->num = k + 1;
crec->path = tfnspath; crec->path = tfnspath;
crec->val = changed ? apr_pmemdup(msr->mp, var->value, var->value_len) : NULL;
crec->val_len = changed ? var->value_len : 0; /* We want to cache a copy if it changed otherwise
* we just want to use a pointer to the last changed value.
*/
crec->val = (!lastvarval || tfnchanged) ? apr_pmemdup(msr->mp, var->value, var->value_len) : lastvarval;
crec->val_len = changed ? ((!lastvarval || tfnchanged) ? var->value_len : lastvarlen) : 0;
/* Keep track of the last changed var value */
if (tfnchanged) {
lastvarval = crec->val;
lastvarlen = crec->val_len;
}
#ifdef CACHE_DEBUG #ifdef CACHE_DEBUG
msr_log(msr, 9, "CACHE: Caching %s=\"%.*s\"", tfnskey, var->value_len, log_escape_nq_ex(mptmp, var->value, var->value_len)); if (changed) {
msr_log(msr, 9, "CACHE: Caching %s=\"%s\" (%pp)",
tfnskey,
log_escape_nq_ex(mptmp,
crec->val,
crec->val_len),
var);
}
else {
msr_log(msr, 9, "CACHE: Caching %s=<no change> (%pp)",
tfnskey,
var);
}
#endif #endif
msr->tcache_items++;
apr_table_setn(cachetab, tfnskey, (void *)crec); apr_table_setn(cachetab, tfnskey, (void *)crec);
} }
}
if (msr->txcfg->debuglog_level >= 9) { if (msr->txcfg->debuglog_level >= 9) {
msr_log(msr, 9, "T (%d) %s: \"%s\"", rc, metadata->name, msr_log(msr, 9, "T (%d) %s: \"%s\"", rc, metadata->name,
@@ -2210,44 +2244,6 @@ static apr_status_t msre_rule_process_normal(msre_rule *rule, modsec_rec *msr) {
} }
} }
#ifdef CACHE_DEBUG
if (msr->txcfg->debuglog_level >= 9) {
apr_hash_index_t *hi;
void *dummy;
apr_table_t **tab;
const apr_array_header_t *ctarr;
const apr_table_entry_t *ctelts;
msre_cache_rec *rec;
int cn = 0;
int ti, ri;
for (hi = apr_hash_first(msr->mp, msr->tcache); hi; hi = apr_hash_next(hi)) {
apr_hash_this(hi, NULL, NULL, &dummy);
tab = (apr_table_t **)dummy;
if (tab == NULL) continue;
for (ti = PHASE_FIRST; ti <= PHASE_LAST; ti++) {
if (tab[ti] == NULL) continue;
ctarr = apr_table_elts(tab[ti]);
ctelts = (const apr_table_entry_t*)ctarr->elts;
for (ri = 0; ri < ctarr->nelts; ri++) {
cn++;
rec = (msre_cache_rec *)ctelts[ri].val;
if (rec->changed) {
if (msr->txcfg->debuglog_level >= 9) {
msr_log(msr, 9, "CACHE: %5d) phase=%d hits=%d %x;%s=\"%s\"", cn, msr->phase, rec->hits, rec->num, rec->path, log_escape_nq_ex(mptmp, rec->val, rec->val_len));
}
}
else {
if (msr->txcfg->debuglog_level >= 9) {
msr_log(msr, 9, "CACHE: %5d) phase=%d hits=%d %x;%s=<no change>", cn, msr->phase, rec->hits, rec->num, rec->path);
}
}
}
}
}
}
#endif
return (match_count ? RULE_MATCH : RULE_NO_MATCH); return (match_count ? RULE_MATCH : RULE_NO_MATCH);
} }

View File

@@ -0,0 +1,183 @@
### Transformation Caching
{
type => "misc",
comment => "tfncache - simple fully cached",
conf => qq(
SecRuleEngine On
SecDebugLog $ENV{DEBUG_LOG}
SecDebugLogLevel 9
# We need to make this work no matter what the defaults may change to
SecCacheTransformations On "minlen:1,maxlen:0"
# This should cache it
SecRule ARGS "WillNotMatch" "phase:1,t:none,t:removeWhiteSpace,t:lowercase,pass,nolog"
# This should use the cached value
SecRule ARGS:test "foobar" "phase:1,t:none,t:removeWhiteSpace,t:lowercase,deny"
),
match_log => {
debug => [ qr/removeWhiteSpace,lowercase: "foobar" .*cached/, 1 ],
-debug => [ qr/partially cached/, 1 ],
},
match_response => {
status => qr/^403$/,
},
request => new HTTP::Request(
GET => "http://$ENV{SERVER_NAME}:$ENV{SERVER_PORT}/index.html?test=Foo+Bar",
),
},
{
type => "misc",
comment => "tfncache - simple partially cached",
conf => qq(
SecRuleEngine On
SecDebugLog $ENV{DEBUG_LOG}
SecDebugLogLevel 9
# We need to make this work no matter what the defaults may change to
SecCacheTransformations On "minlen:1,maxlen:0,incremental:off,maxitems:0"
# This should cache it
SecRule ARGS "WillNotMatch" "phase:1,t:none,t:removeWhiteSpace,pass,nolog"
# This should use the partially cached value
SecRule ARGS:test "foobar" "phase:1,t:none,t:removeWhiteSpace,t:lowercase,deny"
),
match_log => {
debug => [ qr/removeWhiteSpace: "FooBar" .*partially cached/, 1 ],
},
match_response => {
status => qr/^403$/,
},
request => new HTTP::Request(
GET => "http://$ENV{SERVER_NAME}:$ENV{SERVER_PORT}/index.html?test=Foo+Bar",
),
},
{
type => "misc",
comment => "tfncache - separate phases",
conf => qq(
SecRuleEngine On
SecDebugLog $ENV{DEBUG_LOG}
SecDebugLogLevel 9
# We need to make this work no matter what the defaults may change to
SecCacheTransformations On "minlen:1,maxlen:0"
# This should cache it
SecRule ARGS "WillNotMatch" "phase:1,t:none,t:removeWhiteSpace,t:lowercase,pass,nolog"
# This should use the cached value
SecRule ARGS:test "foobar" "phase:2,t:none,t:removeWhiteSpace,t:lowercase,deny"
),
match_log => {
-debug => [ qr/removeWhiteSpace,lowercase: "foobar" .*cached/, 1 ],
},
match_response => {
status => qr/^403$/,
},
request => new HTTP::Request(
GET => "http://$ENV{SERVER_NAME}:$ENV{SERVER_PORT}/index.html?test=Foo+Bar",
),
},
{
type => "misc",
comment => "tfncache - non-modifying tfns cached",
conf => qq(
SecRuleEngine On
SecDebugLog $ENV{DEBUG_LOG}
SecDebugLogLevel 9
# We need to make this work no matter what the defaults may change to
SecCacheTransformations On "minlen:1,maxlen:0"
# This should cache it
SecRule ARGS "WillNotMatch" "phase:1,t:none,t:removeWhiteSpace,t:lowercase,pass,nolog"
# This should use the cached value
SecRule ARGS:test "foobar" "phase:1,t:none,t:removeWhiteSpace,t:lowercase,deny"
),
match_log => {
debug => [ qr/removeWhiteSpace,lowercase: "foobar" .*cached/, 1 ],
},
match_response => {
status => qr/^403$/,
},
request => new HTTP::Request(
GET => "http://$ENV{SERVER_NAME}:$ENV{SERVER_PORT}/index.html?test=foo+bar",
),
},
{
type => "misc",
comment => "tfncache - unique keys",
conf => qq(
SecRuleEngine On
SecDebugLog $ENV{DEBUG_LOG}
SecDebugLogLevel 9
# We need to make this work no matter what the defaults may change to
SecCacheTransformations On "minlen:1,maxlen:0"
# This should cache it
SecRule ARGS "WillNotMatch" "phase:1,t:none,t:removeWhiteSpace,t:lowercase,pass"
# This should see cached versions of *both* ARGS
SecRule ARGS:test "firstval" "phase:1,t:none,t:removeWhiteSpace,t:lowercase,deny,chain"
SecRule ARGS:test "secondval" "t:none,t:removeWhiteSpace,t:lowercase"
),
match_log => {
debug => [ qr/removeWhiteSpace,lowercase: "firstval" .*cached.*removeWhiteSpace,lowercase: "secondval" .*cached/s, 1 ],
},
match_response => {
status => qr/^403$/,
},
request => new HTTP::Request(
GET => "http://$ENV{SERVER_NAME}:$ENV{SERVER_PORT}/index.html?test=First+Val&test=Second+Val",
),
},
{
type => "misc",
comment => "tfncache - large cache",
conf => qq(
SecRuleEngine On
SecDebugLog $ENV{DEBUG_LOG}
SecDebugLogLevel 9
SecRequestBodyAccess On
<IfDefine MODSEC_2.5>
SecRequestBodyNoFilesLimit 1048576
</IfDefine>
SecRequestBodyInMemoryLimit 131072
SecResponseBodyLimit 1048576
# We need to make this work no matter what the defaults may change to
# SecCacheTransformations On "minlen:1,maxlen:0"
SecCacheTransformations Off
# This should cache it in all phases
SecRule ARGS "WillNotMatch" "phase:1,t:none,t:removeWhiteSpace,t:lowercase,pass,nolog"
SecRule ARGS "WillNotMatch" "phase:2,t:none,t:removeWhiteSpace,t:lowercase,pass,nolog"
SecRule ARGS "WillNotMatch" "phase:3,t:none,t:removeWhiteSpace,t:lowercase,pass,nolog"
SecRule ARGS "WillNotMatch" "phase:4,t:none,t:removeWhiteSpace,t:lowercase,pass,nolog"
# This should use the cached value
SecRule ARGS "foobar" "phase:4,t:none,t:removeWhiteSpace,t:lowercase,deny"
),
match_log => {
debug => [ qr/Adding request argument \(BODY\): name "test", value "foobar"/, 15 ],
-error => [ qr/segmentation fault/i, 15 ],
},
match_response => {
status => qr/^403$/,
},
request => new HTTP::Request(
POST => "http://$ENV{SERVER_NAME}:$ENV{SERVER_PORT}/index.html",
[
"Content-Type" => "application/x-www-form-urlencoded",
],
# 1000 Args
join("&", map { sprintf "arg%08d=0123456789abcdef+0123456789ABCDEF+0123456789abcdef", $_ } (1 .. 1000))."&test=foobar",
),
},

View File

@@ -279,6 +279,7 @@ sub runfile {
# Search for all file matches # Search for all file matches
if ($rc == 0 and exists $t{match_file} and defined $t{match_file}) { if ($rc == 0 and exists $t{match_file} and defined $t{match_file}) {
sleep 1; # Make sure the file exists
for my $key (keys %{ $t{match_file} || {}}) { for my $key (keys %{ $t{match_file} || {}}) {
my($neg,$fn) = ($key =~ m/^(-?)(.*)$/); my($neg,$fn) = ($key =~ m/^(-?)(.*)$/);
my $m = $t{match_file}{$key}; my $m = $t{match_file}{$key};

View File

@@ -858,10 +858,10 @@ SecAuditLogStorageDir logs/audit
</section> </section>
<section> <section>
<title><literal>SecCacheTransformations</literal></title> <title><literal>SecCacheTransformations</literal> (Experimental)</title>
<para><emphasis>Description:</emphasis> Controls caching of <para><emphasis>Description:</emphasis> Controls caching of
transformations.</para> transformations. Caching is off by default.</para>
<para><emphasis>Syntax:</emphasis> <literal <para><emphasis>Syntax:</emphasis> <literal
moreinfo="none">SecCacheTransformations On|Off moreinfo="none">SecCacheTransformations On|Off
@@ -898,16 +898,30 @@ SecAuditLogStorageDir logs/audit
<para>The following options are allowed (comma separated):</para> <para>The following options are allowed (comma separated):</para>
<itemizedlist> <itemizedlist>
<listitem>
<para><literal moreinfo="none">incremental:on|off</literal> -
enabling this option will cache every transformation instead of just
the final transformation. (default: off)</para>
</listitem>
<listitem>
<para><literal moreinfo="none">maxitems:N</literal> - do not allow
more than N transformations to be cached. The cache will then be
disabled. A zero value is interpreted as "unlimited". This option
may be useful to limit caching for a form with a large number of
ARGS. (default: 1024)</para>
</listitem>
<listitem> <listitem>
<para><literal moreinfo="none">minlen:N</literal> - do not cache the <para><literal moreinfo="none">minlen:N</literal> - do not cache the
transformation if the value's length is less than N bytes. (default: transformation if the value's length is less than N bytes. (default:
15)</para> 32)</para>
</listitem> </listitem>
<listitem> <listitem>
<para><literal moreinfo="none">maxlen:N</literal> - do not cache the <para><literal moreinfo="none">maxlen:N</literal> - do not cache the
transformation if the value's length is more than N bytes. A zero transformation if the value's length is more than N bytes. A zero
value is interpreted as "unlimited". (default: 0)</para> value is interpreted as "unlimited". (default: 1024)</para>
</listitem> </listitem>
</itemizedlist> </itemizedlist>
</section> </section>