Debug: indent ACL and expreassion tracing by evaluation depth
[exim.git] / src / src / expand.c
index dfd62e50c7d8963e784d8b5c2f706b71315cbd96..55fb0b875cb4136ee418282aa3742369da412163 100644 (file)
@@ -1966,6 +1966,7 @@ return;          /* Unknown variable name, fail silently */
 
 
 
+
 /*************************************************
 *           Read and expand substrings           *
 *************************************************/
@@ -2098,7 +2099,7 @@ while (i < nsub)
   }
 
 DEBUG(D_expand)
-  debug_printf("expanding: acl: %s  arg: %s%s\n",
+  debug_printf_indent("expanding: acl: %s  arg: %s%s\n",
     sub[0],
     acl_narg>0 ? acl_arg[0] : US"<none>",
     acl_narg>1 ? " +more"   : "");
@@ -2522,7 +2523,7 @@ switch(cond_type)
         {
         num[i] = 0;
         DEBUG(D_expand)
-          debug_printf("empty string cast to zero for numerical comparison\n");
+          debug_printf_indent("empty string cast to zero for numerical comparison\n");
         }
       else
         {
@@ -2831,7 +2832,7 @@ switch(cond_type)
       uschar *save_iterate_item = iterate_item;
       int (*compare)(const uschar *, const uschar *);
 
-      DEBUG(D_expand) debug_printf("condition: %s\n", name);
+      DEBUG(D_expand) debug_printf_indent("condition: %s\n", name);
 
       tempcond = FALSE;
       compare = cond_type == ECOND_INLISTI
@@ -2919,7 +2920,7 @@ switch(cond_type)
     int sep = 0;
     uschar *save_iterate_item = iterate_item;
 
-    DEBUG(D_expand) debug_printf("condition: %s\n", name);
+    DEBUG(D_expand) debug_printf_indent("condition: %s\n", name);
 
     while (isspace(*s)) s++;
     if (*s++ != '{') goto COND_FAILED_CURLY_START;     /* }-for-text-editors */
@@ -2958,7 +2959,7 @@ switch(cond_type)
     list = sub[0];
     while ((iterate_item = string_nextinlist(&list, &sep, NULL, 0)) != NULL)
       {
-      DEBUG(D_expand) debug_printf("%s: $item = \"%s\"\n", name, iterate_item);
+      DEBUG(D_expand) debug_printf_indent("%s: $item = \"%s\"\n", name, iterate_item);
       if (!eval_condition(sub[1], resetok, &tempcond))
         {
         expand_string_message = string_sprintf("%s inside \"%s\" condition",
@@ -2966,7 +2967,7 @@ switch(cond_type)
         iterate_item = save_iterate_item;
         return NULL;
         }
-      DEBUG(D_expand) debug_printf("%s: condition evaluated to %s\n", name,
+      DEBUG(D_expand) debug_printf_indent("%s: condition evaluated to %s\n", name,
         tempcond? "true":"false");
 
       if (yield != NULL) *yield = (tempcond == testfor);
@@ -3023,7 +3024,7 @@ switch(cond_type)
         }
       }
     DEBUG(D_expand)
-      debug_printf("considering %s: %s\n", ourname, len ? t : US"<empty>");
+      debug_printf_indent("considering %s: %s\n", ourname, len ? t : US"<empty>");
     /* logic for the lax case from expand_check_condition(), which also does
     expands, and the logic is both short and stable enough that there should
     be no maintenance burden from replicating it. */
@@ -3050,7 +3051,7 @@ switch(cond_type)
        "value \"%s\"", t);
       return NULL;
       }
-    DEBUG(D_expand) debug_printf("%s: condition evaluated to %s\n", ourname,
+    DEBUG(D_expand) debug_printf_indent("%s: condition evaluated to %s\n", ourname,
         boolvalue? "true":"false");
     if (yield != NULL) *yield = (boolvalue == testfor);
     return s;
@@ -3446,7 +3447,7 @@ hash_source = string_catn(hash_source, &size, &offset, daystamp, 3);
 hash_source = string_cat(hash_source, &size, &offset, address);
 hash_source[offset] = '\0';
 
-DEBUG(D_expand) debug_printf("prvs: hash source is '%s'\n", hash_source);
+DEBUG(D_expand) debug_printf_indent("prvs: hash source is '%s'\n", hash_source);
 
 memset(innerkey, 0x36, 64);
 memset(outerkey, 0x5c, 64);
@@ -3869,8 +3870,9 @@ uschar *save_expand_nstring[EXPAND_MAXN+1];
 int save_expand_nlength[EXPAND_MAXN+1];
 BOOL resetok = TRUE;
 
+expand_level++;
 DEBUG(D_expand)
-  debug_printf("%s: %s\n", skipping ? "   scanning" : "considering", string);
+  debug_printf_indent("/%s: %s\n", skipping ? "   scanning" : "considering", string);
 
 expand_string_forcedfail = FALSE;
 expand_string_message = US"";
@@ -4085,7 +4087,7 @@ while (*s != 0)
        case OK:
        case FAIL:
          DEBUG(D_expand)
-           debug_printf("acl expansion yield: %s\n", user_msg);
+           debug_printf_indent("acl expansion yield: %s\n", user_msg);
          if (user_msg)
             yield = string_cat(yield, &size, &ptr, user_msg);
          continue;
@@ -4116,9 +4118,10 @@ while (*s != 0)
       if (next_s == NULL) goto EXPAND_FAILED;  /* message already set */
 
       DEBUG(D_expand)
-        debug_printf("  condition: %.*s\n     result: %s\n",
-         (int)(next_s - s), s,
-          cond ? "true" : "false");
+       {
+        debug_printf_indent("|__condition: %.*s\n", (int)(next_s - s), s);
+        debug_printf_indent("|_____result: %s\n", cond ? "true" : "false");
+       }
 
       s = next_s;
 
@@ -4575,11 +4578,11 @@ while (*s != 0)
         uschar *hash = string_copyn(expand_nstring[3],expand_nlength[3]);
         uschar *domain = string_copyn(expand_nstring[5],expand_nlength[5]);
 
-        DEBUG(D_expand) debug_printf("prvscheck localpart: %s\n", local_part);
-        DEBUG(D_expand) debug_printf("prvscheck key number: %s\n", key_num);
-        DEBUG(D_expand) debug_printf("prvscheck daystamp: %s\n", daystamp);
-        DEBUG(D_expand) debug_printf("prvscheck hash: %s\n", hash);
-        DEBUG(D_expand) debug_printf("prvscheck domain: %s\n", domain);
+        DEBUG(D_expand) debug_printf_indent("prvscheck localpart: %s\n", local_part);
+        DEBUG(D_expand) debug_printf_indent("prvscheck key number: %s\n", key_num);
+        DEBUG(D_expand) debug_printf_indent("prvscheck daystamp: %s\n", daystamp);
+        DEBUG(D_expand) debug_printf_indent("prvscheck hash: %s\n", hash);
+        DEBUG(D_expand) debug_printf_indent("prvscheck domain: %s\n", domain);
 
         /* Set up expansion variables */
         prvscheck_address = string_cat (NULL, &mysize, &myptr, local_part);
@@ -4607,8 +4610,8 @@ while (*s != 0)
           goto EXPAND_FAILED;
           }
 
-        DEBUG(D_expand) debug_printf("prvscheck: received hash is %s\n", hash);
-        DEBUG(D_expand) debug_printf("prvscheck:      own hash is %s\n", p);
+        DEBUG(D_expand) debug_printf_indent("prvscheck: received hash is %s\n", hash);
+        DEBUG(D_expand) debug_printf_indent("prvscheck:      own hash is %s\n", p);
 
         if (Ustrcmp(p,hash) == 0)
           {
@@ -4626,18 +4629,18 @@ while (*s != 0)
           if (iexpire >= inow)
             {
             prvscheck_result = US"1";
-            DEBUG(D_expand) debug_printf("prvscheck: success, $pvrs_result set to 1\n");
+            DEBUG(D_expand) debug_printf_indent("prvscheck: success, $pvrs_result set to 1\n");
             }
             else
             {
             prvscheck_result = NULL;
-            DEBUG(D_expand) debug_printf("prvscheck: signature expired, $pvrs_result unset\n");
+            DEBUG(D_expand) debug_printf_indent("prvscheck: signature expired, $pvrs_result unset\n");
             }
           }
         else
           {
           prvscheck_result = NULL;
-          DEBUG(D_expand) debug_printf("prvscheck: hash failure, $pvrs_result unset\n");
+          DEBUG(D_expand) debug_printf_indent("prvscheck: hash failure, $pvrs_result unset\n");
           }
 
         /* Now expand the final argument. We leave this till now so that
@@ -4800,8 +4803,10 @@ while (*s != 0)
             port = ntohs(service_info->s_port);
             }
 
-         if ((fd = ip_connectedsocket(SOCK_STREAM, server_name, port, port,
-                 timeout, NULL, &expand_string_message)) < 0)
+         fd = ip_connectedsocket(SOCK_STREAM, server_name, port, port,
+                 timeout, NULL, &expand_string_message);
+         callout_address = NULL;
+         if (fd < 0)
               goto SOCK_FAIL;
           }
 
@@ -4838,7 +4843,7 @@ while (*s != 0)
             }
           }
 
-        DEBUG(D_expand) debug_printf("connected to socket %s\n", sub_arg[0]);
+        DEBUG(D_expand) debug_printf_indent("connected to socket %s\n", sub_arg[0]);
 
        /* Allow sequencing of test actions */
        if (running_in_test_harness) millisleep(100);
@@ -4848,7 +4853,7 @@ while (*s != 0)
         if (sub_arg[1][0] != 0)
           {
           int len = Ustrlen(sub_arg[1]);
-          DEBUG(D_expand) debug_printf("writing \"%s\" to socket\n",
+          DEBUG(D_expand) debug_printf_indent("writing \"%s\" to socket\n",
             sub_arg[1]);
           if (write(fd, sub_arg[1], len) != len)
             {
@@ -5800,7 +5805,7 @@ while (*s != 0)
         {
         *outsep = (uschar)sep;      /* Separator as a string */
 
-        DEBUG(D_expand) debug_printf("%s: $item = \"%s\"\n", name, iterate_item);
+        DEBUG(D_expand) debug_printf_indent("%s: $item = \"%s\"\n", name, iterate_item);
 
         if (item_type == EITEM_FILTER)
           {
@@ -5813,7 +5818,7 @@ while (*s != 0)
               expand_string_message, name);
             goto EXPAND_FAILED;
             }
-          DEBUG(D_expand) debug_printf("%s: condition is %s\n", name,
+          DEBUG(D_expand) debug_printf_indent("%s: condition is %s\n", name,
             condresult? "true":"false");
           if (condresult)
             temp = iterate_item;    /* TRUE => include this item */
@@ -5968,7 +5973,7 @@ while (*s != 0)
        uschar * newkeylist = NULL;
        uschar * srcfield;
 
-        DEBUG(D_expand) debug_printf("%s: $item = \"%s\"\n", name, srcitem);
+        DEBUG(D_expand) debug_printf_indent("%s: $item = \"%s\"\n", name, srcitem);
 
        /* extract field for comparisons */
        iterate_item = srcitem;
@@ -5997,7 +6002,7 @@ while (*s != 0)
          /* build and run condition string */
          expr = string_sprintf("%s{%s}{%s}", cmp, srcfield, dstfield);
 
-         DEBUG(D_expand) debug_printf("%s: cond = \"%s\"\n", name, expr);
+         DEBUG(D_expand) debug_printf_indent("%s: cond = \"%s\"\n", name, expr);
          if (!eval_condition(expr, &resetok, &before))
            {
            expand_string_message = string_sprintf("comparison in sort: %s",
@@ -6042,8 +6047,8 @@ while (*s != 0)
        dstlist = newlist;
        dstkeylist = newkeylist;
 
-        DEBUG(D_expand) debug_printf("%s: dstlist = \"%s\"\n", name, dstlist);
-        DEBUG(D_expand) debug_printf("%s: dstkeylist = \"%s\"\n", name, dstkeylist);
+        DEBUG(D_expand) debug_printf_indent("%s: dstlist = \"%s\"\n", name, dstlist);
+        DEBUG(D_expand) debug_printf_indent("%s: dstkeylist = \"%s\"\n", name, dstkeylist);
        }
 
       if (dstlist)
@@ -7092,7 +7097,7 @@ while (*s != 0)
          goto EXPAND_FAILED;
          }
        yield = string_cat(yield, &size, &ptr, s);
-       DEBUG(D_expand) debug_printf("yield: '%s'\n", yield);
+       DEBUG(D_expand) debug_printf_indent("yield: '%s'\n", yield);
         continue;
        }
 
@@ -7486,10 +7491,11 @@ else if (resetok_p) *resetok_p = FALSE;
 
 DEBUG(D_expand)
   {
-  debug_printf("  expanding: %.*s\n     result: %s\n", (int)(s - string), string,
-    yield);
-  if (skipping) debug_printf("   skipping: result is not used\n");
+  debug_printf_indent("|__expanding: %.*s\n", (int)(s - string), string);
+  debug_printf_indent("%s_____result: %s\n", skipping ? "|" : "\\", yield);
+  if (skipping) debug_printf_indent("\\___skipping: result is not used\n");
   }
+expand_level--;
 return yield;
 
 /* This is the failure exit: easiest to program with a goto. We still need
@@ -7511,11 +7517,13 @@ EXPAND_FAILED:
 if (left != NULL) *left = s;
 DEBUG(D_expand)
   {
-  debug_printf("failed to expand: %s\n", string);
-  debug_printf("   error message: %s\n", expand_string_message);
-  if (expand_string_forcedfail) debug_printf("failure was forced\n");
+  debug_printf_indent("|failed to expand: %s\n", string);
+  debug_printf_indent("%s___error message: %s\n",
+    expand_string_forcedfail ? "|" : "\\", expand_string_message);
+  if (expand_string_forcedfail) debug_printf_indent("\\failure was forced\n");
   }
 if (resetok_p) *resetok_p = resetok;
+expand_level--;
 return NULL;
 }
 
@@ -7642,7 +7650,7 @@ if (isspace(*s))
   if (*s == '\0')
     {
       DEBUG(D_expand)
-       debug_printf("treating blank string as number 0\n");
+       debug_printf_indent("treating blank string as number 0\n");
       return 0;
     }
   }
@@ -7776,6 +7784,60 @@ return (  (  Ustrstr(s, "failed to expand") != NULL
 
 
 
+/*************************************************
+* Error-checking for testsuite                   *
+*************************************************/
+typedef struct {
+  const char * filename;
+  int          linenumber;
+  uschar *     region_start;
+  uschar *     region_end;
+  const uschar *var_name;
+  const uschar *var_data;
+} err_ctx;
+
+static void
+assert_variable_notin(uschar * var_name, uschar * var_data, void * ctx)
+{
+err_ctx * e = ctx;
+if (var_data >= e->region_start  &&  var_data < e->region_end)
+  {
+  e->var_name = CUS var_name;
+  e->var_data = CUS var_data;
+  }
+}
+
+void
+assert_no_variables(void * ptr, int len, const char * filename, int linenumber)
+{
+err_ctx e = {filename, linenumber, ptr, US ptr + len, NULL };
+int i;
+var_entry * v;
+
+/* check acl_ variables */
+tree_walk(acl_var_c, assert_variable_notin, &e);
+tree_walk(acl_var_m, assert_variable_notin, &e);
+
+/* check auth<n> variables */
+for (i = 0; i < AUTH_VARS; i++) if (auth_vars[i])
+  assert_variable_notin(US"auth<n>", auth_vars[i], &e);
+
+/* check regex<n> variables */
+for (i = 0; i < REGEX_VARS; i++) if (regex_vars[i])
+  assert_variable_notin(US"regex<n>", regex_vars[i], &e);
+
+/* check known-name variables */
+for (v = var_table; v < var_table + var_table_size; v++)
+  if (v->type == vtype_stringptr)
+    assert_variable_notin(US v->name, *(USS v->value), &e);
+
+if (e.var_name)
+  log_write(0, LOG_MAIN|LOG_PANIC_DIE,
+    "live variable '%s' destroyed by reset_store at %s:%d\n- value '%.64s'",
+    e.var_name, e.filename, e.linenumber, e.var_data);
+}
+
+
 
 /*************************************************
 **************************************************