Debug: indent lookup operations

15 files changed, 110 insertions, 116 deletions

diff --git a/src/src/lookups/cdb.c b/src/src/lookups/cdb.c
index 7c738eb7e..13fe8b7d2 100644
--- a/src/src/lookups/cdb.c
+++ b/src/src/lookups/cdb.c
@@ -210,13 +210,12 @@ cdb_open(uschar *filename,
 
     /* Now return the state struct */
     return(cdbp);
-  } else {
+  } else
     /* If we got here the map failed.  Basically we can ignore
      * this since we fall back to slower methods....
      * However lets debug log it...
      */
-    DEBUG(D_lookup) debug_printf("cdb mmap failed - %d\n", errno);
-  }
+    DEBUG(D_lookup) debug_printf_indent("cdb mmap failed - %d\n", errno);
 #endif /* HAVE_MMAP */
 
   /* In this case we have either not got MMAP allowed, or it failed */
@@ -318,7 +317,7 @@ if ((hash_offset + (hash_offlen * CDB_HASH_ENTRY)) > cdbp->filelen)
   {
   *errmsg = string_sprintf("cdb: corrupt cdb file %s (too short)",
 		      filename);
-  DEBUG(D_lookup) debug_printf("%s\n", *errmsg);
+  DEBUG(D_lookup) debug_printf_indent("%s\n", *errmsg);
   return DEFER;
   }
 
diff --git a/src/src/lookups/dbmdb.c b/src/src/lookups/dbmdb.c
index 9e3d68e33..bdc002d4e 100644
--- a/src/src/lookups/dbmdb.c
+++ b/src/src/lookups/dbmdb.c
@@ -199,7 +199,7 @@ if (key_p == key_buffer)
 empty element to put one in. Boundary: key length 1, is a NULL */
 key_item_len = key_p - key_buffer - 1;
 
-DEBUG(D_lookup) debug_printf("NUL-joined key length: %d\n", key_item_len);
+DEBUG(D_lookup) debug_printf_indent("NUL-joined key length: %d\n", key_item_len);
 
 /* beware that dbmdb_find() adds 1 to length to get back terminating NUL, so
 because we've calculated the real length, we need to subtract one more here */
diff --git a/src/src/lookups/dnsdb.c b/src/src/lookups/dnsdb.c
index aea2eba72..70203fa6d 100644
--- a/src/src/lookups/dnsdb.c
+++ b/src/src/lookups/dnsdb.c
@@ -332,7 +332,7 @@ while ((domain = string_nextinlist(&keystring, &sep, NULL, 0)))
 
   do
     {
-    DEBUG(D_lookup) debug_printf("dnsdb key: %s\n", domain);
+    DEBUG(D_lookup) debug_printf_indent("dnsdb key: %s\n", domain);
 
     /* Do the lookup and sort out the result. There are four special types that
     are handled specially: T_CSA, T_ZNS, T_ADDRESSES and T_MXH.
diff --git a/src/src/lookups/ibase.c b/src/src/lookups/ibase.c
index 5ae966611..eab3c6ad8 100644
--- a/src/src/lookups/ibase.c
+++ b/src/src/lookups/ibase.c
@@ -51,7 +51,7 @@ static void ibase_tidy(void)
 
     while ((cn = ibase_connections) != NULL) {
         ibase_connections = cn->next;
-        DEBUG(D_lookup) debug_printf("close Interbase connection: %s\n",
+        DEBUG(D_lookup) debug_printf_indent("close Interbase connection: %s\n",
                                      cn->server);
         isc_commit_transaction(status, &cn->transh);
         isc_detach_database(status, &cn->dbh);
@@ -170,10 +170,8 @@ if (cn)
     isc_detach_database(status, &cn->dbh);
     }
   else
-    {
-    DEBUG(D_lookup) debug_printf("Interbase using cached connection for %s\n",
+    DEBUG(D_lookup) debug_printf_indent("Interbase using cached connection for %s\n",
 		     server_copy);
-    }
   }
 else
   {
@@ -210,7 +208,7 @@ if (cn->dbh == NULL || cn->transh == NULL)
   dpb_length = dpb - buffer;
 
   DEBUG(D_lookup)
-      debug_printf("new Interbase connection: database=%s user=%s\n",
+      debug_printf_indent("new Interbase connection: database=%s user=%s\n",
 		   sdata[0], sdata[1]);
 
   /* Connect to the database */
@@ -432,7 +430,7 @@ if (result)
   }
 else
   {
-  DEBUG(D_lookup) debug_printf("%s\n", *errmsg);
+  DEBUG(D_lookup) debug_printf_indent("%s\n", *errmsg);
   return yield;           /* FAIL or DEFER */
   }
 }
@@ -460,7 +458,7 @@ ibase_find(void *handle, uschar * filename, uschar * query, int length,
     /* Keep picky compilers happy */
     do_cache = do_cache;
 
-    DEBUG(D_lookup) debug_printf("Interbase query: %s\n", query);
+    DEBUG(D_lookup) debug_printf_indent("Interbase query: %s\n", query);
 
     while ((server =
             string_nextinlist(&list, &sep, buffer,
diff --git a/src/src/lookups/json.c b/src/src/lookups/json.c
index 0b28b731e..a02b7b9bd 100644
--- a/src/src/lookups/json.c
+++ b/src/src/lookups/json.c
@@ -108,7 +108,7 @@ for (int k = 1;  (key = string_nextinlist(&keystring, &sep, NULL, 0)); k++)
 	: json_object_get(j, CCS key)
      ) )
     {
-    DEBUG(D_lookup) debug_printf("%s, for key %d: '%s'\n",
+    DEBUG(D_lookup) debug_printf_indent("%s, for key %d: '%s'\n",
       numeric
       ? US"bad index, or not json array"
       : US"no such key, or not json object",
diff --git a/src/src/lookups/ldap.c b/src/src/lookups/ldap.c
index 08f68b75e..97ee188d2 100644
--- a/src/src/lookups/ldap.c
+++ b/src/src/lookups/ldap.c
@@ -163,8 +163,8 @@ int    rescount = 0;
 BOOL   attribute_found = FALSE;
 BOOL   ldapi = FALSE;
 
-DEBUG(D_lookup)
-  debug_printf("perform_ldap_search: ldap%s URL = \"%s\" server=%s port=%d "
+DEBUG(D_lookup) debug_printf_indent("perform_ldap_search:"
+    " ldap%s URL = \"%s\" server=%s port=%d "
     "sizelimit=%d timelimit=%d tcplimit=%d\n",
     search_type == SEARCH_LDAP_MULTIPLE ? "m" :
     search_type == SEARCH_LDAP_DN       ? "dn" :
@@ -207,7 +207,7 @@ else
   port = ludp->lud_port;
   }
 
-DEBUG(D_lookup) debug_printf("after ldap_url_parse: host=%s port=%d\n",
+DEBUG(D_lookup) debug_printf_indent("after ldap_url_parse: host=%s port=%d\n",
   host, port);
 
 if (port == 0) port = LDAP_PORT;      /* Default if none given */
@@ -334,7 +334,7 @@ if (!lcp)
 
   /* Call ldap_initialize() and check the result */
 
-  DEBUG(D_lookup) debug_printf("ldap_initialize with URL %s\n", init_url);
+  DEBUG(D_lookup) debug_printf_indent("ldap_initialize with URL %s\n", init_url);
   if ((rc = ldap_initialize(&ld, CS init_url)) != LDAP_SUCCESS)
     {
     *errmsg = string_sprintf("ldap_initialize: (error %d) URL \"%s\"\n",
@@ -409,7 +409,7 @@ if (!lcp)
   ldap_set_option(ld, LDAP_OPT_PROTOCOL_VERSION, (void *)&eldap_version);
 #endif
 
-  DEBUG(D_lookup) debug_printf("initialized for LDAP (v%d) server %s%s\n",
+  DEBUG(D_lookup) debug_printf_indent("initialized for LDAP (v%d) server %s%s\n",
     eldap_version, host, porttext);
 
   /* If not using ldapi and TLS is available, set appropriate TLS options: hard
@@ -429,9 +429,9 @@ if (!lcp)
 	: Ustrcmp(eldap_require_cert, "try")    == 0 ? LDAP_OPT_X_TLS_TRY
 	: LDAP_OPT_X_TLS_NEVER;
 
-      DEBUG(D_lookup)
-        debug_printf("Require certificate overrides LDAP_OPT_X_TLS option (%d)\n",
-                     tls_option);
+      DEBUG(D_lookup) debug_printf_indent(
+	"Require certificate overrides LDAP_OPT_X_TLS option (%d)\n",
+	tls_option);
       }
     else
 # endif  /* LDAP_OPT_X_TLS_REQUIRE_CERT */
@@ -439,13 +439,13 @@ if (!lcp)
       {
       tls_option = LDAP_OPT_X_TLS_HARD;
       DEBUG(D_lookup)
-        debug_printf("LDAP_OPT_X_TLS_HARD set due to ldaps:// URI\n");
+        debug_printf_indent("LDAP_OPT_X_TLS_HARD set due to ldaps:// URI\n");
       }
     else
       {
       tls_option = LDAP_OPT_X_TLS_TRY;
       DEBUG(D_lookup)
-        debug_printf("LDAP_OPT_X_TLS_TRY set due to ldap:// URI\n");
+        debug_printf_indent("LDAP_OPT_X_TLS_TRY set due to ldap:// URI\n");
       }
     ldap_set_option(ld, LDAP_OPT_X_TLS, (void *)&tls_option);
     }
@@ -488,14 +488,14 @@ if (!lcp)
     rc = ldap_set_option(ldsetctx, LDAP_OPT_X_TLS_REQUIRE_CERT, &cert_option);
     if (rc)
       DEBUG(D_lookup)
-        debug_printf("Unable to set TLS require cert_option(%d) globally: %s\n",
+        debug_printf_indent("Unable to set TLS require cert_option(%d) globally: %s\n",
           cert_option, ldap_err2string(rc));
     }
 #endif
 #ifdef LDAP_OPT_X_TLS_NEWCTX
   if ((rc = ldap_set_option(ldsetctx, LDAP_OPT_X_TLS_NEWCTX, &am_server)))
     DEBUG(D_lookup)
-      debug_printf("Unable to reload TLS context %d: %s\n",
+      debug_printf_indent("Unable to reload TLS context %d: %s\n",
                    rc, ldap_err2string(rc));
   #endif
 
@@ -517,7 +517,7 @@ if (!lcp)
 
 else
   DEBUG(D_lookup)
-    debug_printf("re-using cached connection to LDAP server %s%s\n",
+    debug_printf_indent("re-using cached connection to LDAP server %s%s\n",
       host, porttext);
 
 /* Bind with the user/password supplied, or an anonymous bind if these values
@@ -532,7 +532,7 @@ if (  !lcp->bound
    || lcp->password && password && Ustrcmp(lcp->password, password) != 0
    )
   {
-  DEBUG(D_lookup) debug_printf("%sbinding with user=%s password=%s\n",
+  DEBUG(D_lookup) debug_printf_indent("%sbinding with user=%s password=%s\n",
     lcp->bound ? "re-" : "", user, password);
 
   if (eldap_start_tls && !lcp->is_start_tls_called && !ldapi)
@@ -551,7 +551,7 @@ if (  !lcp->bound
       }
     lcp->is_start_tls_called = TRUE;
 #else
-    DEBUG(D_lookup) debug_printf("TLS initiation not supported with this Exim"
+    DEBUG(D_lookup) debug_printf_indent("TLS initiation not supported with this Exim"
       " and your LDAP library.\n");
 #endif
     }
@@ -580,7 +580,7 @@ if (  !lcp->bound
   if (search_type == SEARCH_LDAP_AUTH && rc == LDAP_INVALID_CREDENTIALS)
     {
     DEBUG(D_lookup)
-      debug_printf("Invalid credentials: ldapauth returns FAIL\n");
+      debug_printf_indent("Invalid credentials: ldapauth returns FAIL\n");
     error_yield = FAIL;
     goto RETURN_ERROR_NOMSG;
     }
@@ -609,7 +609,7 @@ if (  !lcp->bound
 
 if (search_type == SEARCH_LDAP_AUTH)
   {
-  DEBUG(D_lookup) debug_printf("Bind succeeded: ldapauth returns OK\n");
+  DEBUG(D_lookup) debug_printf_indent("Bind succeeded: ldapauth returns OK\n");
   goto RETURN_OK;
   }
 
@@ -641,7 +641,7 @@ ldap_set_option(lcp->ld, LDAP_OPT_REFERRALS, referrals);
 
 /* Start the search on the server. */
 
-DEBUG(D_lookup) debug_printf("Start search\n");
+DEBUG(D_lookup) debug_printf_indent("Start search\n");
 
 msgid = ldap_search(lcp->ld, ludp->lud_dn, ludp->lud_scope, ludp->lud_filter,
   ludp->lud_attrs, 0);
@@ -673,7 +673,7 @@ while ((rc = ldap_result(lcp->ld, msgid, 0, timeoutptr, &result)) ==
                     then we get two entries, one for A and one for B.
                     Here we just count the values per entry */
 
-  DEBUG(D_lookup) debug_printf("LDAP result loop\n");
+  DEBUG(D_lookup) debug_printf_indent("LDAP result loop\n");
 
   for(e = ldap_first_entry(lcp->ld, result), valuecount = 0;
       e;
@@ -682,7 +682,7 @@ while ((rc = ldap_result(lcp->ld, msgid, 0, timeoutptr, &result)) ==
     uschar *new_dn;
     BOOL insert_space = FALSE;
 
-    DEBUG(D_lookup) debug_printf("LDAP entry loop\n");
+    DEBUG(D_lookup) debug_printf_indent("LDAP entry loop\n");
 
     rescount++;   /* Count results */
 
@@ -731,7 +731,7 @@ while ((rc = ldap_result(lcp->ld, msgid, 0, timeoutptr, &result)) ==
     else for (uschar * attr = US ldap_first_attribute(lcp->ld, e, &ber);
               attr; attr = US ldap_next_attribute(lcp->ld, e, ber))
       {
-      DEBUG(D_lookup) debug_printf("LDAP attr loop\n");
+      DEBUG(D_lookup) debug_printf_indent("LDAP attr loop\n");
 
       /* In case of attrs_requested == 1 we just count the values, in all other cases
       (0, >1) we count the values per attribute */
@@ -759,7 +759,7 @@ while ((rc = ldap_result(lcp->ld, msgid, 0, timeoutptr, &result)) ==
             int len = Ustrlen(value);
             ++valuecount;
 
-            DEBUG(D_lookup) debug_printf("LDAP value loop %s:%s\n", attr, value);
+            DEBUG(D_lookup) debug_printf_indent("LDAP value loop %s:%s\n", attr, value);
 
             /* In case we requested one attribute only but got several times
             into that attr loop, we need to append the additional values.
@@ -852,7 +852,7 @@ if (dn)
 #endif
   }
 
-DEBUG(D_lookup) debug_printf("search ended by ldap_result yielding %d\n",rc);
+DEBUG(D_lookup) debug_printf_indent("search ended by ldap_result yielding %d\n",rc);
 
 if (rc == 0)
   {
@@ -874,7 +874,7 @@ methods of handling error codes and generating error messages. */
 if (rc == -1 || !result)
   {
   int err;
-  DEBUG(D_lookup) debug_printf("ldap_result failed\n");
+  DEBUG(D_lookup) debug_printf_indent("ldap_result failed\n");
 
 #if defined LDAP_LIB_SOLARIS || defined LDAP_LIB_OPENLDAP2
     ldap_get_option(lcp->ld, LDAP_OPT_ERROR_NUMBER, &err);
@@ -917,7 +917,7 @@ We need to parse the message to find out exactly what's happened. */
   ldap_rc = rc;
   ldap_parse_rc = ldap_parse_result(lcp->ld, result, &rc, CSS &matched,
     CSS &error2, NULL, NULL, 0);
-  DEBUG(D_lookup) debug_printf("ldap_parse_result: %d\n", ldap_parse_rc);
+  DEBUG(D_lookup) debug_printf_indent("ldap_parse_result: %d\n", ldap_parse_rc);
   if (ldap_parse_rc < 0 &&
       (ldap_parse_rc != LDAP_NO_RESULTS_RETURNED
       #ifdef LDAP_RES_SEARCH_REFERENCE
@@ -959,7 +959,7 @@ We need to parse the message to find out exactly what's happened. */
       the lookup, so return DEFER (which is the default in error_yield).
 */
 
-DEBUG(D_lookup) debug_printf("ldap_parse_result yielded %d: %s\n",
+DEBUG(D_lookup) debug_printf_indent("ldap_parse_result yielded %d: %s\n",
   rc, ldap_err2string(rc));
 
 if (rc != LDAP_SUCCESS && rc != LDAP_SIZELIMIT_EXCEEDED
@@ -985,7 +985,7 @@ if (rc != LDAP_SUCCESS && rc != LDAP_SIZELIMIT_EXCEEDED
 #endif
 
     {
-    DEBUG(D_lookup) debug_printf("lookup failure forced\n");
+    DEBUG(D_lookup) debug_printf_indent("lookup failure forced\n");
     error_yield = FAIL;
     }
   goto RETURN_ERROR;
@@ -1021,7 +1021,7 @@ if (!attribute_found)
 
 /* Otherwise, it's all worked */
 
-DEBUG(D_lookup) debug_printf("LDAP search: returning: %s\n", data->s);
+DEBUG(D_lookup) debug_printf_indent("LDAP search: returning: %s\n", data->s);
 *res = data->s;
 
 RETURN_OK:
@@ -1035,7 +1035,7 @@ RETURN_ERROR_BREAK:
 *defer_break = TRUE;
 
 RETURN_ERROR:
-DEBUG(D_lookup) debug_printf("%s\n", *errmsg);
+DEBUG(D_lookup) debug_printf_indent("%s\n", *errmsg);
 
 RETURN_ERROR_NOMSG:
 if (result) ldap_msgfree(result);
@@ -1144,7 +1144,7 @@ while (strncmpic(url, US"ldap", 4) != 0)
         {
         *errmsg = string_sprintf("LDAP_OP_DEREF not defined in this LDAP "
           "library - cannot use \"dereference\"");
-        DEBUG(D_lookup) debug_printf("%s\n", *errmsg);
+        DEBUG(D_lookup) debug_printf_indent("%s\n", *errmsg);
         return DEFER;
         }
       #endif
@@ -1156,9 +1156,7 @@ while (strncmpic(url, US"ldap", 4) != 0)
         else if (strcmpic(value, US"nofollow") == 0) referrals = LDAP_OPT_OFF;
         else
           {
-          *errmsg = string_sprintf("LDAP option REFERRALS is not \"follow\" "
-            "or \"nofollow\"");
-          DEBUG(D_lookup) debug_printf("%s\n", *errmsg);
+          DEBUG(D_lookup) debug_printf_indent("%s\n", *errmsg);
           return DEFER;
           }
         }
@@ -1167,7 +1165,7 @@ while (strncmpic(url, US"ldap", 4) != 0)
         {
         *errmsg = string_sprintf("LDAP_OP_REFERRALS not defined in this LDAP "
           "library - cannot use \"referrals\"");
-        DEBUG(D_lookup) debug_printf("%s\n", *errmsg);
+        DEBUG(D_lookup) debug_printf_indent("%s\n", *errmsg);
         return DEFER;
         }
       #endif
@@ -1177,7 +1175,7 @@ while (strncmpic(url, US"ldap", 4) != 0)
         *errmsg =
           string_sprintf("unknown parameter \"%.*s\" precedes LDAP URL",
             namelen, name);
-        DEBUG(D_lookup) debug_printf("LDAP query error: %s\n", *errmsg);
+        DEBUG(D_lookup) debug_printf_indent("LDAP query error: %s\n", *errmsg);
         return DEFER;
         }
       while (isspace(*url)) url++;
@@ -1185,7 +1183,7 @@ while (strncmpic(url, US"ldap", 4) != 0)
       }
     }
   *errmsg = US"malformed parameter setting precedes LDAP URL";
-  DEBUG(D_lookup) debug_printf("LDAP query error: %s\n", *errmsg);
+  DEBUG(D_lookup) debug_printf_indent("LDAP query error: %s\n", *errmsg);
   return DEFER;
   }
 
@@ -1216,7 +1214,7 @@ if (user != NULL)
   }
 
 DEBUG(D_lookup)
-  debug_printf("LDAP parameters: user=%s pass=%s size=%d time=%d connect=%d "
+  debug_printf_indent("LDAP parameters: user=%s pass=%s size=%d time=%d connect=%d "
     "dereference=%d referrals=%s\n", user, password, sizelimit, timelimit,
     tcplimit, dereference, (referrals == LDAP_OPT_ON)? "on" : "off");
 
@@ -1233,7 +1231,7 @@ if (search_type == SEARCH_LDAP_AUTH)
     }
   if (password[0] == 0)
     {
-    DEBUG(D_lookup) debug_printf("Empty password: ldapauth returns FAIL\n");
+    DEBUG(D_lookup) debug_printf_indent("Empty password: ldapauth returns FAIL\n");
     return FAIL;
     }
   }
@@ -1246,7 +1244,7 @@ if (Ustrncmp(p, "://", 3) != 0)
   {
   *errmsg = string_sprintf("LDAP URL does not start with \"ldap://\", "
     "\"ldaps://\", or \"ldapi://\" (it starts with \"%.16s...\")", url);
-  DEBUG(D_lookup) debug_printf("LDAP query error: %s\n", *errmsg);
+  DEBUG(D_lookup) debug_printf_indent("LDAP query error: %s\n", *errmsg);
   return DEFER;
   }
 
@@ -1358,7 +1356,7 @@ eldap_dn = NULL;
 
 while ((lcp = ldap_connections) != NULL)
   {
-  DEBUG(D_lookup) debug_printf("unbind LDAP connection to %s:%d\n", lcp->host,
+  DEBUG(D_lookup) debug_printf_indent("unbind LDAP connection to %s:%d\n", lcp->host,
     lcp->port);
   if(lcp->bound == TRUE)
     ldap_unbind(lcp->ld);
diff --git a/src/src/lookups/lf_sqlperform.c b/src/src/lookups/lf_sqlperform.c
index 99663073b..cc894e0ed 100644
--- a/src/src/lookups/lf_sqlperform.c
+++ b/src/src/lookups/lf_sqlperform.c
@@ -45,7 +45,7 @@ const uschar *serverlist;
 uschar buffer[512];
 BOOL defer_break = FALSE;
 
-DEBUG(D_lookup) debug_printf("%s query: %s\n", name, query);
+DEBUG(D_lookup) debug_printf_indent("%s query: %s\n", name, query);
 
 /* Handle queries that do not have server information at the start. */
 
diff --git a/src/src/lookups/lmdb.c b/src/src/lookups/lmdb.c
index efaa71f89..931ea5bbe 100644
--- a/src/src/lookups/lmdb.c
+++ b/src/src/lookups/lmdb.c
@@ -85,24 +85,24 @@ Lmdbstrct * lmdb_p = handle;
 dbkey.mv_data = CS keystring;
 dbkey.mv_size = length;
 
-DEBUG(D_lookup) debug_printf("LMDB: lookup key: %s\n", CS keystring);
+DEBUG(D_lookup) debug_printf_indent("LMDB: lookup key: %s\n", CS keystring);
 
 if ((ret = mdb_get(lmdb_p->txn, lmdb_p->db_dbi, &dbkey, &data)) == 0)
   {
   *result = string_copyn(US data.mv_data, data.mv_size);
-  DEBUG(D_lookup) debug_printf("LMDB: lookup result: %s\n", *result);
+  DEBUG(D_lookup) debug_printf_indent("LMDB: lookup result: %s\n", *result);
   return OK;
   }
 else if (ret == MDB_NOTFOUND)
   {
   *errmsg = US"LMDB: lookup, no data found";
-  DEBUG(D_lookup) debug_printf("%s\n", *errmsg);
+  DEBUG(D_lookup) debug_printf_indent("%s\n", *errmsg);
   return FAIL;
   }
 else
   {
   *errmsg = string_sprintf("LMDB: lookup error: %s", mdb_strerror(ret));
-  DEBUG(D_lookup) debug_printf("%s\n", *errmsg);
+  DEBUG(D_lookup) debug_printf_indent("%s\n", *errmsg);
   return DEFER;
   }
 }
diff --git a/src/src/lookups/mysql.c b/src/src/lookups/mysql.c
index ba8ecba11..1984e30b2 100644
--- a/src/src/lookups/mysql.c
+++ b/src/src/lookups/mysql.c
@@ -101,7 +101,7 @@ mysql_connection *cn;
 while ((cn = mysql_connections) != NULL)
   {
   mysql_connections = cn->next;
-  DEBUG(D_lookup) debug_printf("close MYSQL connection: %s\n", cn->server);
+  DEBUG(D_lookup) debug_printf_indent("close MYSQL connection: %s\n", cn->server);
   mysql_close(cn->handle);
   }
 }
@@ -227,7 +227,7 @@ if (!cn)
   if (sdata[1][0] == 0) sdata[1] = NULL;
 
   DEBUG(D_lookup)
-    debug_printf("MYSQL new connection: host=%s port=%d socket=%s "
+    debug_printf_indent("MYSQL new connection: host=%s port=%d socket=%s "
       "database=%s user=%s\n", sdata[0], port, socket, sdata[1], sdata[2]);
 
   /* Get store for a new handle, initialize it, and connect to the server */
@@ -260,7 +260,7 @@ if (!cn)
 else
   {
   DEBUG(D_lookup)
-    debug_printf("MYSQL using cached connection for %s\n", server_copy);
+    debug_printf_indent("MYSQL using cached connection for %s\n", server_copy);
   }
 
 /* Run the query */
@@ -285,7 +285,7 @@ if (!(mysql_result = mysql_use_result(mysql_handle)))
   {
   if ( mysql_field_count(mysql_handle) == 0 )
     {
-    DEBUG(D_lookup) debug_printf("MYSQL: query was not one that returns data\n");
+    DEBUG(D_lookup) debug_printf_indent("MYSQL: query was not one that returns data\n");
     result = string_cat(result,
 	       string_sprintf("%d", mysql_affected_rows(mysql_handle)));
     *do_cache = 0;
@@ -331,7 +331,7 @@ while((i = mysql_next_result(mysql_handle)) >= 0)
   {
   if(i == 0)	/* Just ignore more results */
     {
-    DEBUG(D_lookup) debug_printf("MYSQL: got unexpected more results\n");
+    DEBUG(D_lookup) debug_printf_indent("MYSQL: got unexpected more results\n");
     continue;
     }
 
@@ -371,7 +371,7 @@ if (result)
   }
 else
   {
-  DEBUG(D_lookup) debug_printf("%s\n", *errmsg);
+  DEBUG(D_lookup) debug_printf_indent("%s\n", *errmsg);
   return yield;      /* FAIL or DEFER */
   }
 }
diff --git a/src/src/lookups/oracle.c b/src/src/lookups/oracle.c
index d57314580..d106c519f 100644
--- a/src/src/lookups/oracle.c
+++ b/src/src/lookups/oracle.c
@@ -216,7 +216,7 @@ oracle_connection *cn;
 while ((cn = oracle_connections) != NULL)
   {
   oracle_connections = cn->next;
-  DEBUG(D_lookup) debug_printf("close ORACLE connection: %s\n", cn->server);
+  DEBUG(D_lookup) debug_printf_indent("close ORACLE connection: %s\n", cn->server);
   ologof(cn->handle);
   }
 }
@@ -300,7 +300,7 @@ for (cn = oracle_connections; cn; cn = cn->next)
 
 if (!cn)
   {
-  DEBUG(D_lookup) debug_printf("ORACLE new connection: host=%s database=%s "
+  DEBUG(D_lookup) debug_printf_indent("ORACLE new connection: host=%s database=%s "
     "user=%s\n", sdata[0], sdata[1], sdata[2]);
 
   /* Get store for a new connection, initialize it, and connect to the server */
@@ -343,7 +343,7 @@ to obliterate the password because it is in a nextinlist temporary buffer. */
 else
   {
   DEBUG(D_lookup)
-    debug_printf("ORACLE using cached connection for %s\n", server_copy);
+    debug_printf_indent("ORACLE using cached connection for %s\n", server_copy);
   }
 
 /* We have a connection. Open a cursor and run the query */
@@ -486,7 +486,7 @@ if (result)
   }
 else
   {
-  DEBUG(D_lookup) debug_printf("%s\n", *errmsg);
+  DEBUG(D_lookup) debug_printf_indent("%s\n", *errmsg);
   return yield;      /* FAIL or DEFER */
   }
 }
@@ -513,7 +513,7 @@ uschar buffer[512];
 
 do_cache = do_cache;   /* Placate picky compilers */
 
-DEBUG(D_lookup) debug_printf("ORACLE query: %s\n", query);
+DEBUG(D_lookup) debug_printf_indent("ORACLE query: %s\n", query);
 
 while ((server = string_nextinlist(&list, &sep, buffer, sizeof(buffer))) != NULL)
   {
diff --git a/src/src/lookups/pgsql.c b/src/src/lookups/pgsql.c
index cc12e40d7..cf1e1743e 100644
--- a/src/src/lookups/pgsql.c
+++ b/src/src/lookups/pgsql.c
@@ -53,7 +53,7 @@ pgsql_connection *cn;
 while ((cn = pgsql_connections) != NULL)
   {
   pgsql_connections = cn->next;
-  DEBUG(D_lookup) debug_printf("close PGSQL connection: %s\n", cn->server);
+  DEBUG(D_lookup) debug_printf_indent("close PGSQL connection: %s\n", cn->server);
   PQfinish(cn->handle);
   }
 }
@@ -77,7 +77,7 @@ static void
 notice_processor(void *arg, const char *message)
 {
 arg = arg;   /* Keep compiler happy */
-DEBUG(D_lookup) debug_printf("PGSQL: %s\n", message);
+DEBUG(D_lookup) debug_printf_indent("PGSQL: %s\n", message);
 }
 
 
@@ -181,7 +181,7 @@ if (!cn)
     last_slash = Ustrrchr(server, '/');
     last_dot = Ustrrchr(server, '.');
 
-    DEBUG(D_lookup) debug_printf("PGSQL new connection: socket=%s "
+    DEBUG(D_lookup) debug_printf_indent("PGSQL new connection: socket=%s "
       "database=%s user=%s\n", server, sdata[0], sdata[1]);
 
     /* A valid socket name looks like this: /var/run/postgresql/.s.PGSQL.5432
@@ -221,7 +221,7 @@ if (!cn)
       return DEFER;
       }
 
-    DEBUG(D_lookup) debug_printf("PGSQL new connection: host=%s port=%s "
+    DEBUG(D_lookup) debug_printf_indent("PGSQL new connection: host=%s port=%s "
       "database=%s user=%s\n", server, port, sdata[0], sdata[1]);
     }
 
@@ -270,7 +270,7 @@ if (!cn)
 
 else
   {
-  DEBUG(D_lookup) debug_printf("PGSQL using cached connection for %s\n",
+  DEBUG(D_lookup) debug_printf_indent("PGSQL using cached connection for %s\n",
     server_copy);
   }
 
@@ -288,7 +288,7 @@ switch(PQresultStatus(pg_result))
 
     result = string_cat(result, US PQcmdTuples(pg_result));
     *do_cache = 0;
-    DEBUG(D_lookup) debug_printf("PGSQL: command does not return any data "
+    DEBUG(D_lookup) debug_printf_indent("PGSQL: command does not return any data "
       "but was successful. Rows affected: %s\n", string_from_gstring(result));
     break;
 
@@ -362,7 +362,7 @@ if (result)
   }
 else
   {
-  DEBUG(D_lookup) debug_printf("%s\n", *errmsg);
+  DEBUG(D_lookup) debug_printf_indent("%s\n", *errmsg);
   return yield;      /* FAIL or DEFER */
   }
 }
diff --git a/src/src/lookups/redis.c b/src/src/lookups/redis.c
index e84f76675..6de675787 100644
--- a/src/src/lookups/redis.c
+++ b/src/src/lookups/redis.c
@@ -47,7 +47,7 @@ redis_connection *cn;
 while ((cn = redis_connections))
   {
   redis_connections = cn->next;
-  DEBUG(D_lookup) debug_printf("close REDIS connection: %s\n", cn->server);
+  DEBUG(D_lookup) debug_printf_indent("close REDIS connection: %s\n", cn->server);
   redisFree(cn->handle);
   }
 }
@@ -154,7 +154,7 @@ if (!cn)
     }
 
   DEBUG(D_lookup)
-    debug_printf("REDIS new connection: host=%s port=%d socket=%s database=%s\n",
+    debug_printf_indent("REDIS new connection: host=%s port=%d socket=%s database=%s\n",
       sdata[0], port, socket, sdata[1]);
 
   /* Get store for a new handle, initialize it, and connect to the server */
@@ -178,7 +178,7 @@ if (!cn)
 else
   {
   DEBUG(D_lookup)
-    debug_printf("REDIS using cached connection for %s\n", server_copy);
+    debug_printf_indent("REDIS using cached connection for %s\n", server_copy);
 }
 
 /* Authenticate if there is a password */
@@ -199,7 +199,7 @@ if(sdata[1])
     *defer_break = FALSE;
     goto REDIS_EXIT;
     }
-  DEBUG(D_lookup) debug_printf("REDIS: Selecting database=%s\n", sdata[1]);
+  DEBUG(D_lookup) debug_printf_indent("REDIS: Selecting database=%s\n", sdata[1]);
   }
 
 /* split string on whitespace into argv */
@@ -220,7 +220,7 @@ if(sdata[1])
 	g = string_catn(g, s, 1);
     argv[i] = string_from_gstring(g);
 
-    DEBUG(D_lookup) debug_printf("REDIS: argv[%d] '%s'\n", i, argv[i]);
+    DEBUG(D_lookup) debug_printf_indent("REDIS: argv[%d] '%s'\n", i, argv[i]);
     while (isspace(*s)) s++;
     }
 
@@ -245,7 +245,7 @@ switch (redis_reply->type)
     if (Ustrncmp(redis_reply->str, "MOVED", 5) == 0)
       {
       DEBUG(D_lookup)
-        debug_printf("REDIS: cluster redirect %s\n", redis_reply->str);
+        debug_printf_indent("REDIS: cluster redirect %s\n", redis_reply->str);
       /* follow redirect
       This is cheating, we simply set defer_break = FALSE to move on to
       the next server in the redis_servers list */
@@ -260,7 +260,7 @@ switch (redis_reply->type)
 
   case REDIS_REPLY_NIL:
     DEBUG(D_lookup)
-      debug_printf("REDIS: query was not one that returned any data\n");
+      debug_printf_indent("REDIS: query was not one that returned any data\n");
     result = string_catn(result, US"", 1);
     *do_cache = 0;
     goto REDIS_EXIT;
@@ -313,18 +313,18 @@ switch (redis_reply->type)
 		break;
 	      case REDIS_REPLY_ARRAY:
 		DEBUG(D_lookup)
-		  debug_printf("REDIS: result has nesting of arrays which"
+		  debug_printf_indent("REDIS: result has nesting of arrays which"
 		    " is not supported. Ignoring!\n");
 		break;
 	      default:
-		DEBUG(D_lookup) debug_printf(
+		DEBUG(D_lookup) debug_printf_indent(
 			  "REDIS: result has unsupported type. Ignoring!\n");
 		break;
 	      }
 	    }
 	    break;
 	  default:
-	    DEBUG(D_lookup) debug_printf("REDIS: query returned unsupported type\n");
+	    DEBUG(D_lookup) debug_printf_indent("REDIS: query returned unsupported type\n");
 	    break;
 	  }
 	}
@@ -356,7 +356,7 @@ if (result)
   }
 else
   {
-  DEBUG(D_lookup) debug_printf("%s\n", *errmsg);
+  DEBUG(D_lookup) debug_printf_indent("%s\n", *errmsg);
   /* NOTE: Required to close connection since it needs to be reopened */
   return yield;      /* FAIL or DEFER */
   }
diff --git a/src/src/lookups/sqlite.c b/src/src/lookups/sqlite.c
index 4bf616052..5da2de814 100644
--- a/src/src/lookups/sqlite.c
+++ b/src/src/lookups/sqlite.c
@@ -27,7 +27,7 @@ ret = sqlite3_open(CS filename, &db);
 if (ret != 0)
   {
   *errmsg = (void *)sqlite3_errmsg(db);
-  debug_printf("Error opening database: %s\n", *errmsg);
+  debug_printf_indent("Error opening database: %s\n", *errmsg);
   }
 
 sqlite3_busy_timeout(db, 1000 * sqlite_lock_timeout);
@@ -79,7 +79,7 @@ gstring * res = NULL;
 ret = sqlite3_exec(handle, CS query, sqlite_callback, &res, (char **)errmsg);
 if (ret != SQLITE_OK)
   {
-  debug_printf("sqlite3_exec failed: %s\n", *errmsg);
+  debug_printf_indent("sqlite3_exec failed: %s\n", *errmsg);
   return FAIL;
   }
 
diff --git a/src/src/lookups/testdb.c b/src/src/lookups/testdb.c
index 401f7c8bf..3f19e80f6 100644
--- a/src/src/lookups/testdb.c
+++ b/src/src/lookups/testdb.c
@@ -47,13 +47,13 @@ length = length;
 if (Ustrcmp(query, "fail") == 0)
   {
   *errmsg = US"testdb lookup forced FAIL";
-  DEBUG(D_lookup) debug_printf("%s\n", *errmsg);
+  DEBUG(D_lookup) debug_printf_indent("%s\n", *errmsg);
   return FAIL;
   }
 if (Ustrcmp(query, "defer") == 0)
   {
   *errmsg = US"testdb lookup forced DEFER";
-  DEBUG(D_lookup) debug_printf("%s\n", *errmsg);
+  DEBUG(D_lookup) debug_printf_indent("%s\n", *errmsg);
   return DEFER;
   }
 
diff --git a/src/src/search.c b/src/src/search.c
index 11bfcd4df..ebdf8a165 100644
--- a/src/src/search.c
+++ b/src/src/search.c
@@ -251,7 +251,7 @@ search_tidyup(void)
 {
 int old_pool = store_pool;
 
-DEBUG(D_lookup) debug_printf("search_tidyup called\n");
+DEBUG(D_lookup) debug_printf_indent("search_tidyup called\n");
 
 /* Close individually each cached open file. */
 
@@ -341,8 +341,8 @@ int old_pool = store_pool;
 store_pool = POOL_SEARCH;
 if (search_reset_point == NULL) search_reset_point = store_get(0);
 
-DEBUG(D_lookup) debug_printf("search_open: %s \"%s\"\n", lk->name,
-  (filename == NULL)? US"NULL" : filename);
+DEBUG(D_lookup) debug_printf_indent("search_open: %s \"%s\"\n", lk->name,
+  filename ? filename : US"NULL");
 
 /* See if we already have this open for this type of search, and if so,
 pass back the tree block as the handle. The key for the tree node is the search
@@ -357,11 +357,11 @@ if ((t = tree_search(search_tree, keybuffer)) != NULL)
   c = (search_cache *)(t->data.ptr);
   if (c->handle != NULL)
     {
-    DEBUG(D_lookup) debug_printf("  cached open\n");
+    DEBUG(D_lookup) debug_printf_indent("  cached open\n");
     store_pool = old_pool;
     return t;
     }
-  DEBUG(D_lookup) debug_printf("  cached closed\n");
+  DEBUG(D_lookup) debug_printf_indent("  cached closed\n");
   }
 
 /* Otherwise, we need to open the file or database - each search type has its
@@ -378,7 +378,7 @@ if (lk->type == lookup_absfile && open_filecount >= lookup_open_max)
   else
     {
     search_cache *c = (search_cache *)(open_bot->data.ptr);
-    DEBUG(D_lookup) debug_printf("Too many lookup files open\n  closing %s\n",
+    DEBUG(D_lookup) debug_printf_indent("Too many lookup files open\n  closing %s\n",
       open_bot->name);
     open_bot = c->up;
     if (open_bot != NULL)
@@ -476,7 +476,7 @@ the callers don't have to test for NULL, set an empty string. */
 search_error_message = US"";
 f.search_find_defer = FALSE;
 
-DEBUG(D_lookup) debug_printf("internal_search_find: file=\"%s\"\n  "
+DEBUG(D_lookup) debug_printf_indent("internal_search_find: file=\"%s\"\n  "
   "type=%s key=\"%s\"\n", filename,
   lookup_list[search_type]->name, keystring);
 
@@ -496,7 +496,7 @@ if (  (t = tree_search(c->item_cache, keystring))
    )
   { /* Data was in the cache already; set the pointer from the tree node */
   data = e->ptr;
-  DEBUG(D_lookup) debug_printf("cached data used for lookup of %s%s%s\n",
+  DEBUG(D_lookup) debug_printf_indent("cached data used for lookup of %s%s%s\n",
     keystring,
     filename ? US"\n  in " : US"", filename ? filename : US"");
   }
@@ -507,8 +507,8 @@ else
 
   DEBUG(D_lookup)
     {
-    if (t) debug_printf("cached data found but past valid time; ");
-    debug_printf("%s lookup required for %s%s%s\n",
+    if (t) debug_printf_indent("cached data found but past valid time; ");
+    debug_printf_indent("%s lookup required for %s%s%s\n",
       filename ? US"file" : US"database",
       keystring,
       filename ? US"\n  in " : US"", filename ? filename : US"");
@@ -554,7 +554,7 @@ else
 
   else
     {
-    DEBUG(D_lookup) debug_printf("lookup forced cache cleanup\n");
+    DEBUG(D_lookup) debug_printf_indent("lookup forced cache cleanup\n");
     c->item_cache = NULL;
     }
   }
@@ -562,10 +562,10 @@ else
 DEBUG(D_lookup)
   {
   if (data)
-    debug_printf("lookup yielded: %s\n", data);
+    debug_printf_indent("lookup yielded: %s\n", data);
   else if (f.search_find_defer)
-    debug_printf("lookup deferred: %s\n", search_error_message);
-  else debug_printf("lookup failed\n");
+    debug_printf_indent("lookup deferred: %s\n", search_error_message);
+  else debug_printf_indent("lookup failed\n");
   }
 
 /* Return it in new dynamic store in the regular pool */
@@ -614,7 +614,7 @@ uschar *yield;
 DEBUG(D_lookup)
   {
   if (partial < 0) affixlen = 99;   /* So that "NULL" prints */
-  debug_printf("search_find: file=\"%s\"\n  key=\"%s\" "
+  debug_printf_indent("search_find: file=\"%s\"\n  key=\"%s\" "
     "partial=%d affix=%.*s starflags=%x\n",
     (filename == NULL)? US"NULL" : filename,
     keystring, partial, affixlen, affix, starflags);
@@ -653,13 +653,12 @@ if (open_top != (tree_node *)handle &&
 
 DEBUG(D_lookup)
   {
-  tree_node *t = open_top;
-  debug_printf("LRU list:\n");
-  while (t != NULL)
+  debug_printf_indent("LRU list:\n");
+  for (tree_node *t = open_top; t; )
     {
     search_cache *c = (search_cache *)(t->data.ptr);
-    debug_printf("  %s\n", t->name);
-    if (t == open_bot) debug_printf("  End\n");
+    debug_printf_indent("  %s\n", t->name);
+    if (t == open_bot) debug_printf_indent("  End\n");
     t = c->down;
     }
   }
@@ -689,7 +688,7 @@ else if (partial >= 0)
     keystring2 = store_get(len + affixlen + 1);
     Ustrncpy(keystring2, affix, affixlen);
     Ustrcpy(keystring2 + affixlen, keystring);
-    DEBUG(D_lookup) debug_printf("trying partial match %s\n", keystring2);
+    DEBUG(D_lookup) debug_printf_indent("trying partial match %s\n", keystring2);
     yield = internal_search_find(handle, filename, keystring2);
     if (f.search_find_defer) return NULL;
     }
@@ -727,7 +726,7 @@ else if (partial >= 0)
         if (affixlen > 0) Ustrncpy(keystring3, affix, affixlen);
         }
 
-      DEBUG(D_lookup) debug_printf("trying partial match %s\n", keystring3);
+      DEBUG(D_lookup) debug_printf_indent("trying partial match %s\n", keystring3);
       yield = internal_search_find(handle, filename, keystring3);
       if (f.search_find_defer) return NULL;
       if (yield != NULL)
@@ -768,7 +767,7 @@ if (yield == NULL && (starflags & SEARCH_STARAT) != 0)
     savechar = *(--atat);
     *atat = '*';
 
-    DEBUG(D_lookup) debug_printf("trying default match %s\n", atat);
+    DEBUG(D_lookup) debug_printf_indent("trying default match %s\n", atat);
     yield = internal_search_find(handle, filename, atat);
     *atat = savechar;
     if (f.search_find_defer) return NULL;
@@ -791,7 +790,7 @@ and the second is empty. */
 
 if (yield == NULL && (starflags & (SEARCH_STAR|SEARCH_STARAT)) != 0)
   {
-  DEBUG(D_lookup) debug_printf("trying to match *\n");
+  DEBUG(D_lookup) debug_printf_indent("trying to match *\n");
   yield = internal_search_find(handle, filename, US"*");
   if (yield != NULL && expand_setup != NULL && *expand_setup >= 0)
     {