Working on cache enhancements. See trac #14.

apache2/Makefile

@@ -28,9 +28,9 @@ APXS      = apxs
 APACHECTL = apachectl
 
 INCLUDES = -I /usr/include/libxml2
-DEFS = -DWITH_LIBXML2
+#DEFS = -DWITH_LIBXML2
 #DEFS = -DWITH_LIBXML2 -DDEBUG_CONF
-#DEFS = -DWITH_LIBXML2 -DCACHE_DEBUG
+DEFS = -DWITH_LIBXML2 -DCACHE_DEBUG
 #LIBS = -Lmy/lib/dir -lmylib
 
 CFLAGS = -O2 -g -Wuninitialized -Wall -Wmissing-prototypes -Wshadow -Wunused-variable -Wunused-value -Wchar-subscripts -Wsign-compare

apache2/apache2_config.c

@@ -93,6 +93,9 @@ void *create_directory_config(apr_pool_t *mp, char *path) {
     /* Geo Lookups */
     dcfg->geo = NOT_SET_P;
 
+    /* Cache */
+    dcfg->cache_trans = NOT_SET;
+
     return dcfg;
 }
 
@@ -390,6 +393,10 @@ void *merge_directory_configs(apr_pool_t *mp, void *_parent, void *_child) {
     merged->geo = (child->geo == NOT_SET_P
         ? parent->geo : child->geo);
 
+    /* Cache */
+    merged->cache_trans = (child->cache_trans == NOT_SET
+        ? parent->cache_trans : child->cache_trans);
+
     return merged;
 }
 
@@ -462,6 +469,9 @@ void init_directory_config(directory_config *dcfg) {
 
     /* Geo Lookup */
     if (dcfg->geo == NOT_SET_P) dcfg->geo = NULL;
+
+    /* Cache */
+    if (dcfg->cache_trans == NOT_SET_P) dcfg->cache_trans = MODSEC_CACHE_ENABLED;
 }
 
 /**
@@ -1233,6 +1243,25 @@ static const char *cmd_geo_lookups_db(cmd_parms *cmd, void *_dcfg,
 }
 
 
+/* -- Cache -- */
+
+static const char *cmd_cache_transformations(cmd_parms *cmd, void *_dcfg, const char *p1, const char *p2) {
+    directory_config *dcfg = (directory_config *)_dcfg;
+    if (dcfg == NULL) return NULL;
+
+    // TODO: p2 is options
+
+    if (strcasecmp(p1, "on") == 0)
+        dcfg->cache_trans = MODSEC_CACHE_ENABLED;
+    else if (strcasecmp(p1, "off") == 0)
+        dcfg->cache_trans = MODSEC_CACHE_DISABLED;
+    else
+        return apr_psprintf(cmd->pool, "ModSecurity: Invalid value for SecCacheTransformations: %s", p1);
+
+    return NULL;
+}
+
+
 /* -- Configuration directives definitions -- */
 
 #define CMD_SCOPE_MAIN  (RSRC_CONF)
@@ -1587,5 +1616,13 @@ const command_rec module_directives[] = {
         "database for geographical lookups module."
     ),
 
+    AP_INIT_TAKE12 (
+        "SecCacheTransformations",
+        cmd_cache_transformations,
+        NULL,
+        CMD_SCOPE_ANY,
+        "whether or not to cache transformations. Defaults to true."
+    ),
+
     { NULL }
 };

apache2/modsecurity.h

@@ -145,6 +145,9 @@ extern DSOLOCAL const command_rec module_directives[];
 #define MODSEC_DETECTION_ONLY           1
 #define MODSEC_ENABLED                  2
 
+#define MODSEC_CACHE_DISABLED           0
+#define MODSEC_CACHE_ENABLED            1
+
 #define MODSEC_OFFLINE                  0
 #define MODSEC_ONLINE                   1
 
@@ -414,6 +417,9 @@ struct directory_config {
 
     /* Geo Lookup */
     geo_db              *geo;
+
+    /* Cache */
+    int                  cache_trans;
 };
 
 struct error_message {

apache2/re.c

@@ -705,7 +705,7 @@ apr_status_t msre_ruleset_process_phase(msre_ruleset *ruleset, modsec_rec *msr)
             if (rule->actionset != NULL && rule->actionset->rev != NULL) {
                 rev = apr_psprintf(p, " [rev \"%s\"]", rule->actionset->rev);
             }
-            msr_log(msr, 4, "Recipe: Invoking rule %x%s%s%s.",
+            msr_log(msr, 4, "Recipe: Invoking rule %x;%s%s%s.",
                     rule, (fn ? fn : ""), (id ? id : ""), (rev ? rev : ""));
         }
 
@@ -1354,34 +1354,60 @@ apr_status_t msre_rule_process(msre_rule *rule, modsec_rec *msr) {
     te = (apr_table_entry_t *)arr->elts;
     for (i = 0; i < arr->nelts; i++) {
         int changed;
+        int usecache = 0;
+        apr_table_t **carr = NULL;
+        apr_table_t *cachetab = NULL;
        
         /* Take one target. */ 
         msre_var *var = (msre_var *)te[i].val;
 
+        /* Is this var cacheable? */
+        if (msr->txcfg->cache_trans != MODSEC_CACHE_DISABLED) {
+            msr_log(msr, 9, "CACHE: Enabled");
+            if (var->metadata->is_cacheable == VAR_CACHE) {
+                usecache = 1;
+
+                /* Fetch cache table for this target */
+                carr = (apr_table_t **)apr_hash_get(msr->tcache, var->name, APR_HASH_KEY_STRING);
+                if (carr != NULL) {
+                    cachetab = carr[msr->phase];
+                }
+                else {
+                    /* Create an array of cache tables (one table per phase) */
+                    carr = (apr_table_t **)apr_pcalloc(msr->mp, (sizeof(apr_table_t *) * (PHASE_LAST + 1)));
+                    if (carr == NULL) return -1;
+                    memset(carr, 0, (sizeof(apr_table_t *) * (PHASE_LAST + 1)));
+                    apr_hash_set(msr->tcache, var->name, APR_HASH_KEY_STRING, carr);
+                }
+
+                /* 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 {
+                msr_log(msr, 9, "CACHE: %s transformations are not cacheable", var->name);
+            }
+        }
+        else {
+            msr_log(msr, 9, "CACHE: Disabled");
+        }
+
+
         /* Transform target. */
         {
             const apr_array_header_t *tarr;
             const apr_table_entry_t *telts;
-            msre_cache_rec **carr = NULL;
+            const char *tfnspath = NULL;
-            msre_cache_rec *crec = NULL;
-            char *tfnsvar = NULL;
             char *tfnskey = NULL;
             int tfnscount = 0;
-            int usecache = 0;
+            int last_cached_tfn = 0;
-            apr_table_t *normtab;
+            msre_cache_rec *crec = NULL;
+            msre_cache_rec *last_crec = NULL;
             int k;
             msre_action *action;
             msre_tfn_metadata *metadata;
-
+            apr_table_t *normtab;
-            /* Is this var cacheable? */
-            if (var->metadata->is_cacheable == VAR_CACHE) {
-                usecache = 1;
-                tfnsvar = apr_psprintf(msr->mp, "%lx;%s", (unsigned long)var, var->name);
-                tfnskey = tfnsvar;
-            }
-            else {
-                msr_log(msr, 9, "CACHE: %s transformations are not cacheable", var->name);
-            }
 
             normtab = apr_table_make(mptmp, 10);
             if (normtab == NULL) return -1;
@@ -1394,8 +1420,10 @@ apr_status_t msre_rule_process(msre_rule *rule, modsec_rec *msr) {
                 if (strcmp(telts[k].key, "t") == 0) {
                     if (strcmp(action->param, "none") == 0) {
                         apr_table_clear(normtab);
-                        tfnskey = tfnsvar;
+                        tfnspath = NULL;
+                        tfnskey = NULL;
                         tfnscount = 0;
+                        last_cached_tfn = 0;
                         continue;
                     }
 
@@ -1403,55 +1431,51 @@ apr_status_t msre_rule_process(msre_rule *rule, modsec_rec *msr) {
                         apr_table_unset(normtab, action->param);
                     } else {
                         apr_table_addn(normtab, action->param, (void *)action);
-                        tfnskey = apr_psprintf(msr->mp, "%s,%s", tfnskey, action->param);
+
+                        /* check cache, saving the 'most complete' */
+                        crec = (msre_cache_rec *)apr_table_get(cachetab, tfnskey);
+                        if (crec != NULL) {
+                            last_crec = crec;
+                            last_cached_tfn = tfnscount;
+                        }
+
                         tfnscount++;
                     }
                 }
             }
 
-            /* Perform transformations. */
+            /* If the last cached tfn is the last in the list
-
+             * then we can stop here and just execute the action immediatly
-            /* Try to fetch the full multi-transformation from cache */
+             */
-            if (usecache && tfnscount > 1 && !multi_match) {
+            if (usecache && !multi_match && (crec != NULL) && (crec == last_crec)) {
-                crec = NULL;
+                crec->hits++;
-                msr_log(msr, 9, "CACHE: Fetching %s (multi)", tfnskey);
+                if (crec->changed) {
-                carr = (msre_cache_rec **)apr_hash_get(msr->tcache, tfnskey, APR_HASH_KEY_STRING);
+                    var->value = apr_pmemdup(msr->mp, crec->val, crec->val_len);
-                if (carr != NULL) {
+                    var->value_len = crec->val_len;
-                    crec = carr[msr->phase];
                 }
 
-                /* Cache Miss - Reset the key to perform transformations */
+                msr_log(msr, 9, "T (%i) %s: \"%s\" [cached hits=%d]", crec->changed, crec->path, log_escape_nq_ex(mptmp, var->value, var->value_len), crec->hits);
-                if (crec == NULL) {
+
-                    tfnskey = tfnsvar;
+                rc = execute_operator(var, rule, msr, acting_actionset, mptmp);
+
+                if (rc < 0) {
+                    return -1;
                 }
-                /* Cache Hit - Use cache value and execute immediatly */
+                if (rc == RULE_MATCH) {
-                else {
+                    /* Return straight away if the transaction
-                    crec->hits++;
+                     * was intercepted - no need to process the remaining
-                    if (crec->changed) {
+                     * targets.
-                        var->value = apr_pmemdup(msr->mp, crec->val, crec->val_len);
+                     */
-                        var->value_len = crec->val_len;
+                    if (msr->was_intercepted) {
+                        return RULE_MATCH;
                     }
-
-                    msr_log(msr, 9, "T (%i) %s: \"%s\" [cached hits=%d]", crec->changed, (tfnskey + strlen(tfnsvar) + 1), log_escape_nq_ex(mptmp, var->value, var->value_len), crec->hits);
-
-                    rc = execute_operator(var, rule, msr, acting_actionset, mptmp);
-
-                    if (rc < 0) {
-                        return -1;
-                    }
-                    if (rc == RULE_MATCH) {
-                        /* Return straight away if the transaction
-                        * was intercepted - no need to process the remaining
-                        * targets.
-                        */
-                        if (msr->was_intercepted) {
-                            return RULE_MATCH;
-                        }
-                    }
-                    continue; /* next target */
                 }
+                continue; /* next target */
             }
 
+
+            /* Perform transformations. */
+
             tarr = apr_table_elts(normtab);
 
             /* Make a copy of the variable value so that
@@ -1464,10 +1488,20 @@ apr_status_t msre_rule_process(msre_rule *rule, modsec_rec *msr) {
 
             /* Execute transformations in a loop. */
 
-            tfnskey = tfnsvar;
+            /* Start after the last known cached transformation if we can */
+            if (!multi_match && (last_crec != NULL)) {
+                k = last_cached_tfn + 1;
+                tfnspath = last_crec->path;
+                msr_log(msr, 9, "CACHE: starting after '%s'", tfnspath);
+            }
+            else {
+                tfnspath = NULL;
+                k = 0;
+            }
+
             changed = 1;
             telts = (const apr_table_entry_t*)tarr->elts;
-            for (k = 0; k < tarr->nelts; k++) {
+            for (; k < tarr->nelts; k++) {
                 char *rval = NULL;
                 long int rval_length = -1;
 
@@ -1505,15 +1539,12 @@ apr_status_t msre_rule_process(msre_rule *rule, modsec_rec *msr) {
                 /* Try to use the cache */
                 if (usecache) {
                     /* Generate the cache key */
-                    tfnskey = apr_psprintf(msr->mp, "%s,%s", tfnskey, action->param);
+                    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 */
-                    msr_log(msr, 9, "CACHE: Fetching %s", tfnskey);
+                    msr_log(msr, 9, "CACHE: Fetching %s %s ", var->name, tfnskey);
-                    crec = NULL;
+                    crec = (msre_cache_rec *)apr_table_get(cachetab, tfnskey);
-                    carr = (msre_cache_rec **)apr_hash_get(msr->tcache, tfnskey, APR_HASH_KEY_STRING);
-                    if (carr != NULL) {
-                        crec = carr[msr->phase];
-                    }
                     if (crec != NULL) {
                         crec->hits++;
 
@@ -1541,21 +1572,17 @@ apr_status_t msre_rule_process(msre_rule *rule, modsec_rec *msr) {
                 /* Cache the transformation */
                 if (usecache) {
                     /* ENH1: Add flag to vars to tell which ones can change across phases store the rest in a global cache */
-                    if (carr == NULL) {
+                    crec = (msre_cache_rec *)apr_pcalloc(msr->mp, sizeof(msre_cache_rec));
-                        carr = (msre_cache_rec **)apr_pcalloc(msr->mp, (sizeof(msre_cache_rec *) * (PHASE_LAST + 1)));
-                        if (carr == NULL) return -1;
-                        memset(carr, 0, (sizeof(msre_cache_rec *) * (PHASE_LAST + 1)));
-                        apr_hash_set(msr->tcache, tfnskey, APR_HASH_KEY_STRING, carr);
-                    }
-                    crec = carr[msr->phase] = (msre_cache_rec *)apr_pcalloc(msr->mp, sizeof(msre_cache_rec));
                     if (crec == NULL) return -1;
 
                     crec->hits = 0;
                     crec->changed = changed;
-                    crec->key = tfnskey;
+                    crec->num = k + 1;
+                    crec->path = tfnspath;
                     crec->val = changed ? apr_pmemdup(msr->mp, rval, rval_length) : NULL;
                     crec->val_len = changed ? rval_length : -1;
                     msr_log(msr, 9, "CACHE: Caching %s=\"%.*s\"", tfnskey, crec->val_len, crec->val);
+                    apr_table_setn(cachetab, tfnskey, (void *)crec);
                 }
 
                 if (msr->txcfg->debuglog_level >= 9) {
@@ -1598,22 +1625,31 @@ apr_status_t msre_rule_process(msre_rule *rule, modsec_rec *msr) {
     if (msr->txcfg->debuglog_level >= 9) {
         apr_hash_index_t *hi;
         void *dummy;
-        msre_cache_rec **rec;
+        apr_table_t **tab;
+        const apr_array_header_t *ctarr;
+        const apr_table_entry_t *ctelts;
+        msre_cache_rec *rec;
         int hn = 0;
-        int ri;
+        int ti, ri;
+
         for (hi = apr_hash_first(msr->mp, msr->tcache); hi; hi = apr_hash_next(hi)) {
             hn++;
             apr_hash_this(hi, NULL, NULL, &dummy);
-            rec = (msre_cache_rec **)dummy;
+            tab = (apr_table_t **)dummy;
-            if (rec == NULL) continue;
+            if (tab == NULL) continue;
 
-            for (ri = PHASE_FIRST; ri <= PHASE_LAST; ri++) {
+            for (ti = PHASE_FIRST; ti <= PHASE_LAST; ti++) {
-                if (rec[ri] == NULL) continue;
+                if (tab[ti] == NULL) continue;
-                if (rec[ri]->changed) {
+                ctarr = apr_table_elts(tab[ti]);
-                    msr_log(msr, 9, "CACHE: %5d) phase=%d hits=%d %s=\"%s\"", hn, msr->phase, rec[ri]->hits, rec[ri]->key, log_escape_nq_ex(mptmp, rec[ri]->val, rec[ri]->val_len));
+                ctelts = (const apr_table_entry_t*)ctarr->elts;
-                }
+                for (ri = 0; ri < ctarr->nelts; ri++) {
-                else {
+                    rec = (msre_cache_rec *)ctelts[ri].val;
-                    msr_log(msr, 9, "CACHE: %5d) phase=%d hits=%d %s=<no change>", hn, msr->phase, rec[ri]->hits, rec[ri]->key);
+                    if (rec->changed) {
+                        msr_log(msr, 9, "CACHE: %5d) phase=%d hits=%d %x;%s=\"%s\"", hn, msr->phase, rec->hits, rec->num, rec->path, log_escape_nq_ex(mptmp, rec->val, rec->val_len));
+                    }
+                    else {
+                        msr_log(msr, 9, "CACHE: %5d) phase=%d hits=%d %x;%s=<no change>", hn, msr->phase, rec->hits, rec->num, rec->path);
+                    }
                 }
             }
         }

apache2/re.h

@@ -309,7 +309,8 @@ char DSOLOCAL *msre_format_metadata(modsec_rec *msr, msre_actionset *actionset);
 struct msre_cache_rec {
     int                      hits;
     int                      changed;
-    const char              *key;
+    int                      num;
+    const char              *path;
     const char              *val;
     apr_size_t               val_len;
 };

apache2/re_variables.c

@@ -1895,7 +1895,7 @@ void msre_engine_register_default_variables(msre_engine *engine) {
         1, 1,
         var_generic_list_validate,
         var_tx_generate,
-        VAR_CACHE,
+        VAR_DONT_CACHE,
         PHASE_REQUEST_HEADERS
     );