diff --git a/apache2/configure.in b/apache2/configure.in index 717221d6..2825c8b4 100644 --- a/apache2/configure.in +++ b/apache2/configure.in @@ -225,6 +225,21 @@ AC_ARG_ENABLE(debug-acmp, debug_acmp= ]) +# DEBUG_MEM +AC_ARG_ENABLE(debug-mem, + AS_HELP_STRING([--enable-debug-mem], + [Enable debug during configuration.]), +[ + if test "$enableval" != "no"; then + debug_mem="-DDEBUG_MEM" + else + debug_mem= + fi +], +[ + debug_mem= +]) + # PERFORMANCE_MEASUREMENT AC_ARG_ENABLE(performance-measurement, AS_HELP_STRING([--enable-performance-measurement], @@ -257,8 +272,12 @@ AC_ARG_ENABLE(modsec-api, ### Build *EXTRA_CFLAGS vars -EXTRA_CFLAGS="-O2 -g -Wall $strict_compile" -MODSEC_EXTRA_CFLAGS="$debug_conf $debug_cache $debug_acmp $perf_meas $modsec_api" +if test -n "$debug_mem"; then + EXTRA_CFLAGS="-O0 -g -Wall" +else + EXTRA_CFLAGS="-O2 -g -Wall $strict_compile" +fi +MODSEC_EXTRA_CFLAGS="$debug_conf $debug_cache $debug_acmp $debug_mem $perf_meas $modsec_api" APXS_WRAPPER=build/apxs-wrapper APXS_EXTRA_CFLAGS="" diff --git a/apache2/modsecurity.c b/apache2/modsecurity.c index 685e9fbe..1751c44e 100644 --- a/apache2/modsecurity.c +++ b/apache2/modsecurity.c @@ -517,17 +517,17 @@ apr_status_t modsecurity_process_phase(modsec_rec *msr, unsigned int phase) { const void *key; apr_ssize_t klen; #ifdef CACHE_DEBUG - apr_pool_t *mptmp = msr->msc_rule_mptmp; + apr_pool_t *mp = msr->msc_rule_mptmp; const apr_array_header_t *ctarr; const apr_table_entry_t *ctelts; msre_cache_rec *rec; int cn = 0; int ri; + #else + apr_pool_t *mp = msr->mp; #endif - for (hi = apr_hash_first(msr->mp, msr->tcache); hi; hi = apr_hash_next(hi)) { - msre_var *keyvar = NULL; - + for (hi = apr_hash_first(mp, msr->tcache); hi; hi = apr_hash_next(hi)) { apr_hash_this(hi, &key, &klen, &dummy); tab = (apr_table_t *)dummy; @@ -535,7 +535,6 @@ apr_status_t modsecurity_process_phase(modsec_rec *msr, unsigned int phase) { #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++) { @@ -543,12 +542,12 @@ apr_status_t modsecurity_process_phase(modsec_rec *msr, unsigned int phase) { 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); + msr_log(msr, 9, "CACHE: %5d) hits=%d key=%pp %x;%s=\"%s\" (%pp - %pp)", cn, rec->hits, key, rec->num, rec->path, log_escape_nq_ex(mp, rec->val, rec->val_len), rec->val, rec->val + rec->val_len); } } else { if (msr->txcfg->debuglog_level >= 9) { - msr_log(msr, 9, "CACHE: %5d) hits=%d key=%pp var=\"%s\" %x;%s=", cn, rec->hits, keyvar, keyvar->name, rec->num, rec->path); + msr_log(msr, 9, "CACHE: %5d) hits=%d key=%pp %x;%s=", cn, rec->hits, key, rec->num, rec->path); } } } diff --git a/apache2/modsecurity.h b/apache2/modsecurity.h index 159a2fe3..b973d86e 100644 --- a/apache2/modsecurity.h +++ b/apache2/modsecurity.h @@ -30,6 +30,10 @@ typedef struct msc_string msc_string; #define DSOLOCAL #endif +#if defined(DEBUG_MEM) +/* Nothing Yet */ +#endif + /* For GNU C, tell the compiler to check printf like formatters */ #if (defined(__GNUC__) && !defined(SOLARIS2)) #define PRINTF_ATTRIBUTE(a,b) __attribute__((format (printf, a, b))) diff --git a/apache2/re.c b/apache2/re.c index 2c572c9b..c83760cc 100644 --- a/apache2/re.c +++ b/apache2/re.c @@ -1789,6 +1789,7 @@ static apr_status_t msre_rule_process_normal(msre_rule *rule, modsec_rec *msr) { multi_match = 1; } + /* ENH: What is a good initial size? */ tartab = apr_table_make(mptmp, 24); if (tartab == NULL) return -1; vartab = apr_table_make(mptmp, 24); @@ -1868,14 +1869,30 @@ static apr_status_t msre_rule_process_normal(msre_rule *rule, modsec_rec *msr) { if (msr->txcfg->cache_trans != MODSEC_CACHE_DISABLED) { usecache = 1; + /* Counting vars are not cacheable due to them being created + * in a local per-rule pool. + */ + if (var->is_counting) { + if (msr->txcfg->debuglog_level >= 9) { + msr_log(msr, 9, "CACHE: Disabled - &%s is dynamic", var->name); + } + usecache = 0; + } + /* Only cache if if the variable is available in this phase */ + else if (msr->phase < var->metadata->availability) { + if (msr->txcfg->debuglog_level >= 9) { + msr_log(msr, 9, "CACHE: Disabled - %s is not yet available in phase %d (requires phase %d or later)", var->name, msr->phase, var->metadata->availability); + } + usecache = 0; + } /* check the cache options */ - if (var->value_len < msr->txcfg->cache_trans_min) { + else if (var->value_len < msr->txcfg->cache_trans_min) { if (msr->txcfg->debuglog_level >= 9) { msr_log(msr, 9, "CACHE: Disabled - %s value length=%u, smaller than minlen=%" APR_SIZE_T_FMT, var->name, var->value_len, msr->txcfg->cache_trans_min); } usecache = 0; } - if ((msr->txcfg->cache_trans_max != 0) && (var->value_len > msr->txcfg->cache_trans_max)) { + else if ((msr->txcfg->cache_trans_max != 0) && (var->value_len > msr->txcfg->cache_trans_max)) { if (msr->txcfg->debuglog_level >= 9) { msr_log(msr, 9, "CACHE: Disabled - %s value length=%u, larger than maxlen=%" APR_SIZE_T_FMT, var->name, var->value_len, msr->txcfg->cache_trans_max); } @@ -1894,21 +1911,31 @@ static apr_status_t msre_rule_process_normal(msre_rule *rule, modsec_rec *msr) { #endif /* Fetch cache table for this target */ - cachetab = (apr_table_t *)apr_hash_get(msr->tcache, var, sizeof(msre_var *)); + cachetab = (apr_table_t *)apr_hash_get(msr->tcache, var->value, sizeof(var->value)); /* Create an empty cache table if this is the first time */ #ifdef CACHE_DEBUG if (cachetab) { msr_log(msr, 9, "CACHE: Using cache table %pp", cachetab); } - else { + else #else - if (cachetab == NULL) { + if (cachetab == NULL) #endif + { + /* NOTE: We use the pointer to the var value as a hash + * key as it is unique. This pointer *must* + * remain valid through the entire phase. If + * it does not, then we will not receive a cache + * hit and just wasted RAM. So, it is important + * that any such vars be marked as VAR_DONT_CACHE. + * + * ENH: Only use pointer for non-scalar vars + */ cachetab = apr_table_make(msr->mp, 3); - apr_hash_set(msr->tcache, var, sizeof(msre_var *), cachetab); + apr_hash_set(msr->tcache, var->value, sizeof(var->value), cachetab); #ifdef CACHE_DEBUG - msr_log(msr, 9, "CACHE: Created a new cache table %pp", cachetab); + msr_log(msr, 9, "CACHE: Created a new cache table %pp for %pp", cachetab, var->value); #endif } @@ -1977,8 +2004,8 @@ static apr_status_t msre_rule_process_normal(msre_rule *rule, modsec_rec *msr) { * starting point */ if (usecache) { - tfnspath = apr_psprintf(msr->mp, "%s%s%s", (tfnspath?tfnspath:""), (tfnspath?",":""), action->param); - tfnskey = apr_psprintf(msr->mp, "%x;%s", tfnscount, tfnspath); + tfnspath = apr_psprintf(mptmp, "%s%s%s", (tfnspath?tfnspath:""), (tfnspath?",":""), action->param); + tfnskey = apr_psprintf(mptmp, "%x;%s", tfnscount, tfnspath); 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)); @@ -2001,7 +2028,7 @@ static apr_status_t msre_rule_process_normal(msre_rule *rule, modsec_rec *msr) { { crec->hits++; if (crec->changed) { - var->value = apr_pmemdup(msr->mp, crec->val, crec->val_len); + var->value = apr_pmemdup(mptmp, crec->val, crec->val_len); var->value_len = crec->val_len; } @@ -2045,14 +2072,6 @@ static apr_status_t msre_rule_process_normal(msre_rule *rule, modsec_rec *msr) { tarr = apr_table_elts(normtab); - /* Make a copy of the variable value so that - * we can change it in-place. - */ - if (tarr->nelts) { - var->value = apr_pstrmemdup(mptmp, var->value, var->value_len); - /* var->value_len remains the same */ - } - /* Execute transformations in a loop. */ /* Start after the last known cached transformation if we can */ @@ -2062,7 +2081,7 @@ static apr_status_t msre_rule_process_normal(msre_rule *rule, modsec_rec *msr) { last_crec->hits++; if ((changed = last_crec->changed) > 0) { - var->value = apr_pmemdup(msr->mp, last_crec->val, last_crec->val_len); + var->value = last_crec->val; var->value_len = last_crec->val_len; } @@ -2075,6 +2094,12 @@ static apr_status_t msre_rule_process_normal(msre_rule *rule, modsec_rec *msr) { k = 0; } + /* Make a copy of the value so that we can change it in-place. */ + if (tarr->nelts) { + var->value = apr_pstrmemdup(mptmp, var->value, var->value_len); + /* var->value_len remains the same */ + } + telts = (const apr_table_entry_t*)tarr->elts; for (; k < tarr->nelts; k++) { char *rval = NULL; @@ -2094,9 +2119,11 @@ static apr_status_t msre_rule_process_normal(msre_rule *rule, modsec_rec *msr) { #endif { apr_time_t t1 = apr_time_now(); + #if defined(PERFORMANCE_MEASUREMENT) rule->trans_time += (t1 - time_before_trans); #endif + msr_log(msr, 4, "Transformation completed in %" APR_TIME_T_FMT " usec.", (t1 - time_before_trans)); } @@ -2123,10 +2150,10 @@ static apr_status_t msre_rule_process_normal(msre_rule *rule, modsec_rec *msr) { /* Perform one transformation. */ action = (msre_action *)telts[k].val; metadata = (msre_tfn_metadata *)action->param_data; - tfnchanged = metadata->execute(mptmp, (unsigned char *)var->value, var->value_len, &rval, &rval_length); + if (tfnchanged < 0) { return -1; } @@ -2135,6 +2162,7 @@ static apr_status_t msre_rule_process_normal(msre_rule *rule, modsec_rec *msr) { changed++; } + /* Use the new values */ var->value = rval; var->value_len = rval_length; @@ -2223,9 +2251,11 @@ static apr_status_t msre_rule_process_normal(msre_rule *rule, modsec_rec *msr) { #endif { apr_time_t t1 = apr_time_now(); + #if defined(PERFORMANCE_MEASUREMENT) rule->trans_time += (t1 - time_before_trans); #endif + msr_log(msr, 4, "Transformation completed in %" APR_TIME_T_FMT " usec.", (t1 - time_before_trans)); } diff --git a/apache2/re_variables.c b/apache2/re_variables.c index 91bf97e6..80435e5c 100644 --- a/apache2/re_variables.c +++ b/apache2/re_variables.c @@ -450,7 +450,7 @@ static int var_request_uri_raw_generate(modsec_rec *msr, msre_var *var, msre_rul /* REQUEST_URI */ static int var_request_uri_generate(modsec_rec *msr, msre_var *var, msre_rule *rule, - apr_table_t *vartab, apr_pool_t *mptmp) + apr_table_t *vartab, apr_pool_t *mptmp) /* dynamic */ { char *value = NULL; @@ -2134,7 +2134,7 @@ void msre_engine_register_default_variables(msre_engine *engine) { 0, 0, NULL, var_args_combined_size_generate, - VAR_DONT_CACHE, + VAR_DONT_CACHE, /* dynamic */ PHASE_REQUEST_HEADERS ); @@ -2233,7 +2233,7 @@ void msre_engine_register_default_variables(msre_engine *engine) { 0, 0, NULL, var_files_combined_size_generate, - VAR_CACHE, + VAR_DONT_CACHE, /* temp copy */ PHASE_REQUEST_BODY ); @@ -2255,7 +2255,7 @@ void msre_engine_register_default_variables(msre_engine *engine) { 0, 1, var_generic_list_validate, var_files_sizes_generate, - VAR_CACHE, + VAR_DONT_CACHE, /* temp copy */ PHASE_REQUEST_BODY ); @@ -2277,7 +2277,7 @@ void msre_engine_register_default_variables(msre_engine *engine) { 1, 1, var_generic_list_validate, var_geo_generate, - VAR_DONT_CACHE, + VAR_DONT_CACHE, /* dynamic */ PHASE_REQUEST_HEADERS ); @@ -2288,7 +2288,7 @@ void msre_engine_register_default_variables(msre_engine *engine) { 1, 1, var_generic_list_validate, var_global_generate, - VAR_DONT_CACHE, + VAR_DONT_CACHE, /* dynamic */ PHASE_REQUEST_HEADERS ); @@ -2299,7 +2299,7 @@ void msre_engine_register_default_variables(msre_engine *engine) { 0, 0, NULL, var_highest_severity_generate, - VAR_DONT_CACHE, + VAR_DONT_CACHE, /* dynamic */ PHASE_REQUEST_HEADERS ); @@ -2310,7 +2310,7 @@ void msre_engine_register_default_variables(msre_engine *engine) { 1, 1, var_generic_list_validate, var_ip_generate, - VAR_DONT_CACHE, + VAR_DONT_CACHE, /* dynamic */ PHASE_REQUEST_HEADERS ); @@ -2321,7 +2321,7 @@ void msre_engine_register_default_variables(msre_engine *engine) { 0, 0, NULL, var_matched_var_generate, - VAR_DONT_CACHE, + VAR_DONT_CACHE, /* dynamic */ PHASE_REQUEST_HEADERS ); @@ -2332,7 +2332,7 @@ void msre_engine_register_default_variables(msre_engine *engine) { 0, 0, NULL, var_matched_var_name_generate, - VAR_DONT_CACHE, + VAR_DONT_CACHE, /* dynamic */ PHASE_REQUEST_HEADERS ); @@ -2354,7 +2354,7 @@ void msre_engine_register_default_variables(msre_engine *engine) { 0, 0, NULL, var_multipart_boundary_quoted_generate, - VAR_CACHE, + VAR_DONT_CACHE, /* flag */ PHASE_REQUEST_BODY ); @@ -2365,7 +2365,7 @@ void msre_engine_register_default_variables(msre_engine *engine) { 0, 0, NULL, var_multipart_boundary_whitespace_generate, - VAR_CACHE, + VAR_DONT_CACHE, /* flag */ PHASE_REQUEST_BODY ); @@ -2376,7 +2376,7 @@ void msre_engine_register_default_variables(msre_engine *engine) { 0, 0, NULL, var_multipart_data_after_generate, - VAR_CACHE, + VAR_DONT_CACHE, /* flag */ PHASE_REQUEST_BODY ); @@ -2387,7 +2387,7 @@ void msre_engine_register_default_variables(msre_engine *engine) { 0, 0, NULL, var_multipart_data_before_generate, - VAR_CACHE, + VAR_DONT_CACHE, /* flag */ PHASE_REQUEST_BODY ); @@ -2398,7 +2398,7 @@ void msre_engine_register_default_variables(msre_engine *engine) { 0, 0, NULL, var_multipart_header_folding_generate, - VAR_CACHE, + VAR_DONT_CACHE, /* flag */ PHASE_REQUEST_BODY ); @@ -2409,7 +2409,7 @@ void msre_engine_register_default_variables(msre_engine *engine) { 0, 0, NULL, var_multipart_crlf_line_generate, - VAR_CACHE, + VAR_DONT_CACHE, /* flag */ PHASE_REQUEST_BODY ); @@ -2420,7 +2420,7 @@ void msre_engine_register_default_variables(msre_engine *engine) { 0, 0, NULL, var_multipart_crlf_lf_lines_generate, - VAR_CACHE, + VAR_DONT_CACHE, /* flag */ PHASE_REQUEST_BODY ); @@ -2431,7 +2431,7 @@ void msre_engine_register_default_variables(msre_engine *engine) { 0, 0, NULL, var_multipart_lf_line_generate, - VAR_CACHE, + VAR_DONT_CACHE, /* flag */ PHASE_REQUEST_BODY ); @@ -2442,7 +2442,7 @@ void msre_engine_register_default_variables(msre_engine *engine) { 0, 0, NULL, var_multipart_missing_semicolon_generate, - VAR_CACHE, + VAR_DONT_CACHE, /* flag */ PHASE_REQUEST_BODY ); @@ -2453,7 +2453,7 @@ void msre_engine_register_default_variables(msre_engine *engine) { 0, 0, NULL, var_multipart_strict_error_generate, - VAR_CACHE, + VAR_DONT_CACHE, /* flag */ PHASE_REQUEST_BODY ); @@ -2464,7 +2464,7 @@ void msre_engine_register_default_variables(msre_engine *engine) { 0, 0, NULL, var_multipart_unmatched_boundary_generate, - VAR_CACHE, + VAR_DONT_CACHE, /* flag */ PHASE_REQUEST_BODY ); @@ -2519,7 +2519,7 @@ void msre_engine_register_default_variables(msre_engine *engine) { 0, 0, NULL, var_remote_port_generate, - VAR_CACHE, + VAR_DONT_CACHE, /* temp copy */ PHASE_REQUEST_BODY ); @@ -2541,7 +2541,7 @@ void msre_engine_register_default_variables(msre_engine *engine) { 1, 1, var_generic_list_validate, var_resource_generate, - VAR_DONT_CACHE, + VAR_DONT_CACHE, /* dynamic */ PHASE_REQUEST_HEADERS ); @@ -2552,7 +2552,7 @@ void msre_engine_register_default_variables(msre_engine *engine) { 0, 0, NULL, var_reqbody_processor_generate, - VAR_DONT_CACHE, + VAR_DONT_CACHE, /* temp copy */ PHASE_REQUEST_HEADERS ); @@ -2563,7 +2563,7 @@ void msre_engine_register_default_variables(msre_engine *engine) { 0, 0, NULL, var_reqbody_processor_error_generate, - VAR_DONT_CACHE, + VAR_DONT_CACHE, /* dynamic */ PHASE_REQUEST_BODY ); @@ -2574,7 +2574,7 @@ void msre_engine_register_default_variables(msre_engine *engine) { 0, 0, NULL, var_reqbody_processor_error_msg_generate, - VAR_DONT_CACHE, + VAR_DONT_CACHE, /* dynamic */ PHASE_REQUEST_BODY ); @@ -2585,7 +2585,7 @@ void msre_engine_register_default_variables(msre_engine *engine) { 0, 0, NULL, var_request_basename_generate, - VAR_CACHE, + VAR_DONT_CACHE, /* temp copy */ PHASE_REQUEST_HEADERS ); @@ -2695,7 +2695,7 @@ void msre_engine_register_default_variables(msre_engine *engine) { 0, 0, NULL, var_request_uri_generate, - VAR_CACHE, + VAR_DONT_CACHE, /* temp copy */ PHASE_REQUEST_HEADERS ); @@ -2728,7 +2728,7 @@ void msre_engine_register_default_variables(msre_engine *engine) { 0, 0, NULL, var_response_content_length, - VAR_CACHE, + VAR_DONT_CACHE, /* temp copy */ PHASE_RESPONSE_HEADERS ); @@ -2783,7 +2783,7 @@ void msre_engine_register_default_variables(msre_engine *engine) { 0, 0, NULL, var_response_status_generate, - VAR_CACHE, + VAR_DONT_CACHE, /* temp copy */ PHASE_RESPONSE_HEADERS ); @@ -2794,7 +2794,7 @@ void msre_engine_register_default_variables(msre_engine *engine) { 1, 1, NULL, var_rule_generate, - VAR_DONT_CACHE, + VAR_DONT_CACHE, /* dynamic */ PHASE_RESPONSE_HEADERS ); @@ -2805,7 +2805,7 @@ void msre_engine_register_default_variables(msre_engine *engine) { 0, 0, NULL, var_script_gid_generate, - VAR_CACHE, + VAR_DONT_CACHE, /* temp copy */ PHASE_REQUEST_BODY ); @@ -2816,7 +2816,7 @@ void msre_engine_register_default_variables(msre_engine *engine) { 0, 0, NULL, var_script_basename_generate, - VAR_CACHE, + VAR_DONT_CACHE, /* temp copy */ PHASE_REQUEST_BODY ); @@ -2838,7 +2838,7 @@ void msre_engine_register_default_variables(msre_engine *engine) { 0, 0, NULL, var_script_groupname_generate, - VAR_CACHE, + VAR_DONT_CACHE, /* temp copy */ PHASE_REQUEST_BODY ); @@ -2849,7 +2849,7 @@ void msre_engine_register_default_variables(msre_engine *engine) { 0, 0, NULL, var_script_mode_generate, - VAR_CACHE, + VAR_DONT_CACHE, /* temp copy */ PHASE_REQUEST_BODY ); @@ -2860,7 +2860,7 @@ void msre_engine_register_default_variables(msre_engine *engine) { 0, 0, NULL, var_script_uid_generate, - VAR_CACHE, + VAR_DONT_CACHE, /* temp copy */ PHASE_REQUEST_BODY ); @@ -2871,7 +2871,7 @@ void msre_engine_register_default_variables(msre_engine *engine) { 0, 0, NULL, var_script_username_generate, - VAR_CACHE, + VAR_DONT_CACHE, /* temp copy */ PHASE_REQUEST_BODY ); @@ -2904,7 +2904,7 @@ void msre_engine_register_default_variables(msre_engine *engine) { 0, 0, NULL, var_server_port_generate, - VAR_CACHE, + VAR_DONT_CACHE, /* temp copy */ PHASE_REQUEST_HEADERS ); @@ -2915,7 +2915,7 @@ void msre_engine_register_default_variables(msre_engine *engine) { 1, 1, var_generic_list_validate, var_session_generate, - VAR_DONT_CACHE, + VAR_DONT_CACHE, /* dynamic */ PHASE_REQUEST_HEADERS ); @@ -2926,7 +2926,7 @@ void msre_engine_register_default_variables(msre_engine *engine) { 0, 0, NULL, var_sessionid_generate, - VAR_DONT_CACHE, + VAR_DONT_CACHE, /* dynamic */ PHASE_RESPONSE_HEADERS ); @@ -2948,7 +2948,7 @@ void msre_engine_register_default_variables(msre_engine *engine) { 1, 1, var_generic_list_validate, var_user_generate, - VAR_CACHE, + VAR_DONT_CACHE, /* dynamic */ PHASE_REQUEST_HEADERS ); @@ -2959,7 +2959,7 @@ void msre_engine_register_default_variables(msre_engine *engine) { 0, 0, NULL, var_userid_generate, - VAR_DONT_CACHE, + VAR_DONT_CACHE, /* dynamic */ PHASE_RESPONSE_HEADERS ); @@ -2970,7 +2970,7 @@ void msre_engine_register_default_variables(msre_engine *engine) { 0, 0, NULL, var_time_generate, - VAR_DONT_CACHE, + VAR_DONT_CACHE, /* dynamic */ PHASE_REQUEST_HEADERS ); @@ -2981,7 +2981,7 @@ void msre_engine_register_default_variables(msre_engine *engine) { 0, 0, NULL, var_time_day_generate, - VAR_DONT_CACHE, + VAR_DONT_CACHE, /* dynamic */ PHASE_REQUEST_HEADERS ); @@ -2992,7 +2992,7 @@ void msre_engine_register_default_variables(msre_engine *engine) { 0, 0, NULL, var_time_epoch_generate, - VAR_DONT_CACHE, + VAR_DONT_CACHE, /* dynamic */ PHASE_REQUEST_HEADERS ); @@ -3003,7 +3003,7 @@ void msre_engine_register_default_variables(msre_engine *engine) { 0, 0, NULL, var_time_hour_generate, - VAR_DONT_CACHE, + VAR_DONT_CACHE, /* dynamic */ PHASE_REQUEST_HEADERS ); @@ -3014,7 +3014,7 @@ void msre_engine_register_default_variables(msre_engine *engine) { 0, 0, NULL, var_time_min_generate, - VAR_DONT_CACHE, + VAR_DONT_CACHE, /* dynamic */ PHASE_REQUEST_HEADERS ); @@ -3025,7 +3025,7 @@ void msre_engine_register_default_variables(msre_engine *engine) { 0, 0, NULL, var_time_mon_generate, - VAR_DONT_CACHE, + VAR_DONT_CACHE, /* dynamic */ PHASE_REQUEST_HEADERS ); @@ -3036,7 +3036,7 @@ void msre_engine_register_default_variables(msre_engine *engine) { 0, 0, NULL, var_time_sec_generate, - VAR_DONT_CACHE, + VAR_DONT_CACHE, /* dynamic */ PHASE_REQUEST_HEADERS ); @@ -3047,7 +3047,7 @@ void msre_engine_register_default_variables(msre_engine *engine) { 0, 0, NULL, var_time_wday_generate, - VAR_DONT_CACHE, + VAR_DONT_CACHE, /* dynamic */ PHASE_REQUEST_HEADERS ); @@ -3058,7 +3058,7 @@ void msre_engine_register_default_variables(msre_engine *engine) { 0, 0, NULL, var_time_year_generate, - VAR_DONT_CACHE, + VAR_DONT_CACHE, /* dynamic */ PHASE_REQUEST_HEADERS ); @@ -3069,7 +3069,7 @@ void msre_engine_register_default_variables(msre_engine *engine) { 1, 1, var_generic_list_validate, var_tx_generate, - VAR_DONT_CACHE, + VAR_DONT_CACHE, /* dynamic */ PHASE_REQUEST_HEADERS ); @@ -3091,7 +3091,7 @@ void msre_engine_register_default_variables(msre_engine *engine) { 0, 0, NULL, var_webserver_error_log_generate, - VAR_DONT_CACHE, + VAR_DONT_CACHE, /* dynamic */ PHASE_REQUEST_HEADERS ); @@ -3102,7 +3102,7 @@ void msre_engine_register_default_variables(msre_engine *engine) { 0, 1, var_xml_validate, var_xml_generate, - VAR_CACHE, + VAR_DONT_CACHE, /* dynamic */ PHASE_REQUEST_BODY ); } diff --git a/apache2/t/regression/misc/10-tfn-cache.t b/apache2/t/regression/misc/10-tfn-cache.t index 62ebfb77..80e3e269 100644 --- a/apache2/t/regression/misc/10-tfn-cache.t +++ b/apache2/t/regression/misc/10-tfn-cache.t @@ -12,10 +12,10 @@ SecCacheTransformations On "minlen:1,maxlen:0" # This should cache it - SecRule ARGS "WillNotMatch" "phase:1,t:none,t:removeWhiteSpace,t:lowercase,pass,nolog" + SecRule ARGS_GET "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" + SecRule ARGS_GET:test "foobar" "phase:1,t:none,t:removeWhiteSpace,t:lowercase,deny" ), match_log => { debug => [ qr/removeWhiteSpace,lowercase: "foobar" .*cached/, 1 ], @@ -40,10 +40,10 @@ 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" + SecRule ARGS_GET "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" + SecRule ARGS_GET:test "foobar" "phase:1,t:none,t:removeWhiteSpace,t:lowercase,deny" ), match_log => { debug => [ qr/removeWhiteSpace: "FooBar" .*partially cached/, 1 ], @@ -67,10 +67,10 @@ SecCacheTransformations On "minlen:1,maxlen:0" # This should cache it - SecRule ARGS "WillNotMatch" "phase:1,t:none,t:removeWhiteSpace,t:lowercase,pass,nolog" + SecRule ARGS_GET "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" + SecRule ARGS_GET:test "foobar" "phase:2,t:none,t:removeWhiteSpace,t:lowercase,deny" ), match_log => { -debug => [ qr/removeWhiteSpace,lowercase: "foobar" .*cached/, 1 ], @@ -94,10 +94,10 @@ SecCacheTransformations On "minlen:1,maxlen:0" # This should cache it - SecRule ARGS "WillNotMatch" "phase:1,t:none,t:removeWhiteSpace,t:lowercase,pass,nolog" + SecRule ARGS_GET "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" + SecRule ARGS_GET:test "foobar" "phase:1,t:none,t:removeWhiteSpace,t:lowercase,deny" ), match_log => { debug => [ qr/removeWhiteSpace,lowercase: "foobar" .*cached/, 1 ], @@ -116,25 +116,32 @@ SecRuleEngine On SecDebugLog $ENV{DEBUG_LOG} SecDebugLogLevel 9 + SecRequestBodyAccess On # 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" + SecRule ARGS "WillNotMatch" "phase:2,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" + # This should see cached versions of *both* ARGS_GET + SecRule ARGS:test "queryval" "phase:2,t:none,t:removeWhiteSpace,t:lowercase,deny,chain" + SecRule ARGS:test "firstval" "t:none,t:removeWhiteSpace,t:lowercase,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 ], + debug => [ qr/removeWhiteSpace,lowercase: "queryval" .*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", + POST => "http://$ENV{SERVER_NAME}:$ENV{SERVER_PORT}/index.html?test=Query+Val", + [ + "Content-Type" => "application/x-www-form-urlencoded", + ], + # Args + "test=First+Val&test=Second+Val", ), }, { @@ -153,8 +160,7 @@ SecResponseBodyLimit 1048576 # We need to make this work no matter what the defaults may change to -# SecCacheTransformations On "minlen:1,maxlen:0" - SecCacheTransformations Off + SecCacheTransformations On "minlen:1,maxlen:0,maxitems:0" # This should cache it in all phases SecRule ARGS "WillNotMatch" "phase:1,t:none,t:removeWhiteSpace,t:lowercase,pass,nolog" @@ -166,7 +172,7 @@ SecRule ARGS "foobar" "phase:4,t:none,t:removeWhiteSpace,t:lowercase,deny" ), match_log => { - debug => [ qr/Adding request argument \(BODY\): name "test", value "foobar"/, 60 ], + debug => [ qr/Adding request argument \(BODY\): name "test", value "Foo Bar"/, 60 ], -error => [ qr/segmentation fault/i, 60 ], }, match_response => { @@ -178,6 +184,6 @@ "Content-Type" => "application/x-www-form-urlencoded", ], # 1000 Args - join("&", map { sprintf "arg%08d=0123456789abcdef+0123456789ABCDEF+0123456789abcdef", $_ } (1 .. 1000))."&test=foobar", + join("&", map { sprintf "arg%08d=0123456789abcdef+0123456789ABCDEF+0123456789abcdef", $_ } (1 .. 1000))."&test=Foo+Bar", ), }, diff --git a/apache2/t/run-regression-tests.pl.in b/apache2/t/run-regression-tests.pl.in index 6ddfbb8a..a3daf6b3 100755 --- a/apache2/t/run-regression-tests.pl.in +++ b/apache2/t/run-regression-tests.pl.in @@ -35,6 +35,7 @@ my $PID_FILE = "$FILES_DIR/httpd.pid"; my $HTTPD = q(@APXS_HTTPD@); my $PASSED = 0; my $TOTAL = 0; +my $BUFSIZ = 32768; my %C = (); my %FILE = (); my $UA_NAME = "ModSecurity Regression Tests/1.2.3"; @@ -49,7 +50,7 @@ if ($HTTPD eq "\@APXS_HTTPD\@") { $SIG{TERM} = $SIG{INT} = \&handle_interrupt; my %opt; -getopts('A:E:D:C:T:H:a:p:dh', \%opt); +getopts('A:E:D:C:T:H:a:p:dvh', \%opt); if ($opt{D}) { $Data::Dumper::Indent = 1; @@ -73,6 +74,7 @@ Usage: $SCRIPT [options] [file [N]] -a file Specify Apache httpd binary (default: httpd) -p port Specify Apache httpd port (default: 8088) -d Enable debugging. + -v Enable verbose debugging. -h This help. EOT @@ -230,7 +232,6 @@ sub runfile { $rc = 1; msg("response $mtype matched: $m"); dbg($resp); - last; } elsif (!$neg and !defined $match) { @@ -245,13 +246,13 @@ sub runfile { # Run any arbitrary perl tests if ($rc == 0 and exists $t{test} and defined $t{test}) { - #dbg("Executing perl test(s)..."); + dbg("Executing perl test(s)...") if ($opt{v}); $rc = eval { &{$t{test}} }; if (! defined $rc) { msg("Error running test: $@"); $rc = -1; } - #dbg("Perl tests returned: $rc"); + dbg("Perl tests returned: $rc") if ($opt{v}); } # Search for all log matches @@ -263,15 +264,11 @@ sub runfile { if ($neg and defined $match) { $rc = 1; msg("$mtype log matched: $m->[0]"); - msg("Log: $FILE{$mtype}{fn}"); - dbg(escape("$FILE{$mtype}{buf}")); last; } elsif (!$neg and !defined $match) { $rc = 1; msg("$mtype log failed to match: $m->[0]"); - msg("Log: $FILE{$mtype}{fn}"); - dbg(escape("$FILE{$mtype}{buf}")); last; } } @@ -287,13 +284,11 @@ sub runfile { if ($neg and defined $match) { $rc = 1; msg("$fn file matched: $m"); - dbg(escape("$FILE{$fn}{buf}")); last; } elsif (!$neg and !defined $match) { $rc = 1; msg("$fn file failed match: $m"); - dbg(escape("$FILE{$fn}{buf}")); last; } } @@ -308,7 +303,13 @@ sub runfile { $pass++; } else { - dbg("Test config: $conf_fn"); + if ($opt{d}) { + dbg("Test Config: $conf_fn"); + dbg("Debug Log: $FILE{debug}{fn}"); + dbg(escape("$FILE{debug}{buf}")) if ($opt{v}); + dbg("Error Log: $FILE{error}{fn}"); + dbg(escape("$FILE{error}{buf}")) if ($opt{v}); + } } msg(sprintf("%s) %s%s: %s%s", $id, $t{type}, (exists($t{comment}) ? " - $t{comment}" : ""), ($rc ? "failed" : "passed"), ((defined($out) && $out ne "")? " ($out)" : ""))); @@ -352,7 +353,7 @@ sub do_raw_request { # Join togeather the request my $r = join("", @_); - dbg($r); + dbg($r) if ($opt{v}); # Write to socket print $sock "$r"; @@ -375,15 +376,13 @@ sub do_request { } if (ref $r eq "HTTP::Request") { -# dbg("REQUEST: ", $r); my $resp = $UA->request($r); - if ($opt{d}) { + if ($opt{d} and $opt{v}) { dbg($resp->request()->as_string()); } return $resp } else { -# dbg("REQUEST:\n", $r); return do_raw_request($r); } @@ -409,14 +408,17 @@ sub match_response { return; } +sub read_log { + my($name, $timeout, $graph) = @_; + return match_log($name, undef, $timeout, $graph); +} + sub match_log { - my($name, $re, $timeout) = @_; + my($name, $re, $timeout, $graph) = @_; my $t0 = gettimeofday; my($fh,$rbuf) = ($FILE{$name}{fd}, \$FILE{$name}{buf}); my $n = length($$rbuf); - msg("Warning: Empty regular expression.") if (!defined $re or $re eq ""); - unless (defined $fh) { msg("Error: File \"$name\" is not opened for matching."); return; @@ -424,13 +426,35 @@ sub match_log { $timeout = 0 unless (defined $timeout); + my $i = 0; do { - $n += $fh->sysread($$rbuf, 1024, $n); -# dbg("Match \"$re\" in $name \"$$rbuf\" ($n)"); + my $nbytes = $fh->sysread($$rbuf, $BUFSIZ, $n); + if (!defined($nbytes)) { + msg("Error: Could not read \"$name\" log: $!"); + last; + } + elsif (!defined($re) and $nbytes == 0) { + last; + } + + # Remove APR pool debugging + $$rbuf =~ s/POOL DEBUG:[^\n]+PALLOC[^\n]+\n//sg; + + $n = length($$rbuf); + + #dbg("Match \"$re\" in $name \"$$rbuf\" ($n)"); return $& if ($$rbuf =~ m/$re/m); # TODO: Use select()/poll() - sleep 0.1; + sleep 0.1 unless ($nbytes == $BUFSIZ); + if ($graph and $opt{v}) { + $i++; + if ($i == 10) { + $i=0; + print STDERR "." + } + } } while (gettimeofday - $t0 < $timeout); + print STDERR "\n" if ($graph and $opt{v}); return; } @@ -524,7 +548,7 @@ sub httpd_start { my $httpd_out; my $httpd_pid = open3(undef, $httpd_out, undef, @p) or quit(1); - my $out = join("\\n", split(/\n/, <$httpd_out>)); + my $out = join("\\n", grep(!/POOL DEBUG/, (<$httpd_out>))); close $httpd_out; waitpid($httpd_pid, 0); @@ -549,7 +573,7 @@ sub httpd_start { } # Look for startup msg - unless (defined match_log("error", qr/resuming normal operations/, 10)) { + unless (defined match_log("error", qr/resuming normal operations/, 60, $opt{d})) { dbg(join(" ", map { quote_shell($_) } @p)); dbg(match_log("error", qr/(^.*ModSecurity: .*)/sm, 10)); msg("Httpd server failed to start."); @@ -571,7 +595,7 @@ sub httpd_stop { my $httpd_out; my $httpd_pid = open3(undef, $httpd_out, undef, @p) or quit(1); - my $out = join("\\n", split(/\n/, <$httpd_out>)); + my $out = join("\\n", grep(!/POOL DEBUG/, (<$httpd_out>))); close $httpd_out; waitpid($httpd_pid, 0); @@ -595,7 +619,7 @@ sub httpd_stop { } # Look for startup msg - unless (defined match_log("error", qr/caught SIG[A-Z]+, shutting down/, 10)) { + unless (defined match_log("error", qr/caught SIG[A-Z]+, shutting down/, 60, $opt{d})) { dbg(join(" ", map { quote_shell($_) } @p)); msg("Httpd server failed to shutdown."); return -1; @@ -617,7 +641,7 @@ sub httpd_reload { my $httpd_out; my $httpd_pid = open3(undef, $httpd_out, undef, @p) or quit(1); - my $out = join("\\n", split(/\n/, <$httpd_out>)); + my $out = join("\\n", grep(!/POOL DEBUG/, (<$httpd_out>))); close $httpd_out; waitpid($httpd_pid, 0); @@ -641,7 +665,7 @@ sub httpd_reload { } # Look for startup msg - unless (defined match_log("error", qr/resuming normal operations/, 10)) { + unless (defined match_log("error", qr/resuming normal operations/, 60, $opt{d})) { dbg(join(" ", map { quote_shell($_) } @p)); msg("Httpd server failed to reload."); return -1;