From: Jeremy Harris <jgh146exb@wizmail.org>
Date: Sat, 16 May 2020 18:30:37 +0000 (+0100)
Subject: Lookups: cache=no_rd option.  Bug 1751
X-Git-Tag: exim-4.95-RC0~347^2~5
X-Git-Url: https://git.exim.org/exim.git/commitdiff_plain/3db72f4b639a64cacf152e4f7718a18581426b10

Lookups: cache=no_rd option.  Bug 1751
---

diff --git a/doc/doc-docbook/spec.xfpt b/doc/doc-docbook/spec.xfpt
index b4d4232e0..a1f361339 100644
--- a/doc/doc-docbook/spec.xfpt
+++ b/doc/doc-docbook/spec.xfpt
@@ -6668,6 +6668,18 @@ If the value of &$sender_host_address$& is 192.168.5.6, expansion of the
 first &%domains%& setting above generates the second setting, which therefore
 causes a second lookup to occur.
 
+.new
+The lookup type may optionally be followed by a comma
+and a comma-separated list of options.
+Each option is a &"name=value"& pair.
+Whether an option is meaningful depands on the lookup type.
+
+All lookups support the option &"cache=no_rd"&.
+If this is given then the cache that Exim manages for lookup results
+is not checked before diong the lookup.
+The result of the lookup is still written to the cache.
+.wen
+
 The rest of this chapter describes the different lookup types that are
 available. Any of them can be used in any part of the configuration where a
 lookup is permitted.
@@ -6685,6 +6697,13 @@ lookup to succeed. The lookup type determines how the file is searched.
 .new
 .cindex "tainted data" "single-key lookups"
 The file string may not be tainted
+
+All single-key lookups support the option &"ret=key"&.
+If this is given and the lookup
+(either underlying implementation or cached value)
+returns data, the result is replaced with a non-tainted
+version of the lookup key.
+.cindex "tainted data" "de-tainting"
 .wen
 .next
 .cindex "query-style lookup" "definition of"
diff --git a/doc/doc-txt/NewStuff b/doc/doc-txt/NewStuff
index 82f1c5c18..83b696fe5 100644
--- a/doc/doc-txt/NewStuff
+++ b/doc/doc-txt/NewStuff
@@ -24,6 +24,8 @@ Version 4.95
  5. Option "message_linelength_limit" on the smtp transport to enforce (by
     default) the RFC 998 character limit.
 
+ 6. An option to ignore the cache on a lookup.
+
 
 Version 4.94
 ------------
diff --git a/src/src/search.c b/src/src/search.c
index 94a58897f..d1633a5e1 100644
--- a/src/src/search.c
+++ b/src/src/search.c
@@ -462,6 +462,7 @@ Arguments:
                NULL for query-style searches
   keystring    the keystring for single-key+file lookups, or
                the querystring for query-style lookups
+  cache_rd     FALSE to avoid lookup in cache layer
   opts	       type-specific options
 
 Returns:       a pointer to a dynamic string containing the answer,
@@ -472,7 +473,7 @@ Returns:       a pointer to a dynamic string containing the answer,
 
 static uschar *
 internal_search_find(void * handle, const uschar * filename, uschar * keystring,
-  const uschar * opts)
+  BOOL cache_rd, const uschar * opts)
 {
 tree_node * t = (tree_node *)handle;
 search_cache * c = (search_cache *)(t->data.ptr);
@@ -501,11 +502,13 @@ if (keystring[0] == 0) return NULL;
 store_pool = POOL_SEARCH;
 
 /* Look up the data for the key, unless it is already in the cache for this
-file. No need to check c->item_cache for NULL, tree_search will do so. */
+file. No need to check c->item_cache for NULL, tree_search will do so. Check
+whether we want to use the cache entry last so that we can always replace it. */
 
 if (  (t = tree_search(c->item_cache, keystring))
    && (!(e = t->data.ptr)->expiry || e->expiry > time(NULL))
    && (!opts && !e->opts  ||  opts && e->opts && Ustrcmp(opts, e->opts) == 0)
+   && cache_rd
    )
   { /* Data was in the cache already; set the pointer from the tree node */
   data = e->data.ptr;
@@ -522,7 +525,8 @@ else
     {
     if (t)
       debug_printf_indent("cached data found but %s; ",
-	e->expiry && e->expiry <= time(NULL) ? "out-of-date" : "wrong opts");
+	e->expiry && e->expiry <= time(NULL) ? "out-of-date"
+	: cache_rd ? "wrong opts" : "no_rd option set");
     debug_printf_indent("%s lookup required for %s%s%s\n",
       filename ? US"file" : US"database",
       keystring,
@@ -541,14 +545,19 @@ else
   or points to a bit of dynamic store. Cache the result of the lookup if
   caching is permitted. Lookups can disable caching, when they did something
   that changes their data. The mysql and pgsql lookups do this when an
-  UPDATE/INSERT query was executed. */
+  UPDATE/INSERT query was executed.  Lookups can also set a TTL for the
+  cache entry; the dnsdb lookup does.
+  Finally, the caller can request no caching by setting an option. */
 
   else if (do_cache)
     {
+    DEBUG(D_lookup) debug_printf_indent("%s cache entry\n",
+      t ? "replacing old" : "creating new");
     if (!t)	/* No existing entry.  Create new one. */
       {
       int len = keylength + 1;
-      e = store_get(sizeof(expiring_data) + sizeof(tree_node) + len, is_tainted(keystring));
+      e = store_get(sizeof(expiring_data) + sizeof(tree_node) + len,
+		    is_tainted(keystring));
       t = (tree_node *)(e+1);
       memcpy(t->name, keystring, len);
       t->data.ptr = e;
@@ -621,9 +630,9 @@ search_find(void * handle, const uschar * filename, uschar * keystring,
   int partial, const uschar * affix, int affixlen, int starflags,
   int * expand_setup, const uschar * opts)
 {
-tree_node *t = (tree_node *)handle;
-BOOL set_null_wild = FALSE;
-uschar *yield;
+tree_node * t = (tree_node *)handle;
+BOOL set_null_wild = FALSE, cache_rd = TRUE, ret_key = FALSE;
+uschar * yield;
 
 DEBUG(D_lookup)
   {
@@ -636,6 +645,23 @@ DEBUG(D_lookup)
 
   }
 
+/* Parse global lookup options. Also, create a new options list with
+the global options dropped so that the cache-modifiers are not
+used in the cache key. */
+
+if (opts)
+  {
+  int sep = ',';
+  gstring * g = NULL;
+
+  for (uschar * ele; ele = string_nextinlist(&opts, &sep, NULL, 0); )
+    if (Ustrcmp(ele, "ret=key") == 0) ret_key = TRUE;
+    else if (Ustrcmp(ele, "cache=no_rd") == 0) cache_rd = FALSE;
+    else g = string_append_listele(g, ',', ele);
+
+  opts = string_from_gstring(g);
+  }
+
 /* Arrange to put this database at the top of the LRU chain if it is a type
 that opens real files. */
 
@@ -683,7 +709,7 @@ DEBUG(D_lookup)
 /* First of all, try to match the key string verbatim. If matched a complete
 entry but could have been partial, flag to set up variables. */
 
-yield = internal_search_find(handle, filename, keystring, opts);
+yield = internal_search_find(handle, filename, keystring, cache_rd, opts);
 if (f.search_find_defer) return NULL;
 
 if (yield) { if (partial >= 0) set_null_wild = TRUE; }
@@ -708,7 +734,7 @@ else if (partial >= 0)
     Ustrncpy(keystring2, affix, affixlen);
     Ustrcpy(keystring2 + affixlen, keystring);
     DEBUG(D_lookup) debug_printf_indent("trying partial match %s\n", keystring2);
-    yield = internal_search_find(handle, filename, keystring2, opts);
+    yield = internal_search_find(handle, filename, keystring2, cache_rd, opts);
     if (f.search_find_defer) return NULL;
     }
 
@@ -746,7 +772,8 @@ else if (partial >= 0)
         }
 
       DEBUG(D_lookup) debug_printf_indent("trying partial match %s\n", keystring3);
-      yield = internal_search_find(handle, filename, keystring3, opts);
+      yield = internal_search_find(handle, filename, keystring3,
+		cache_rd, opts);
       if (f.search_find_defer) return NULL;
       if (yield)
         {
@@ -787,7 +814,7 @@ if (!yield  &&  starflags & SEARCH_STARAT)
     *atat = '*';
 
     DEBUG(D_lookup) debug_printf_indent("trying default match %s\n", atat);
-    yield = internal_search_find(handle, filename, atat, opts);
+    yield = internal_search_find(handle, filename, atat, cache_rd, opts);
     *atat = savechar;
     if (f.search_find_defer) return NULL;
 
@@ -810,7 +837,7 @@ and the second is empty. */
 if (!yield  &&  starflags & (SEARCH_STAR|SEARCH_STARAT))
   {
   DEBUG(D_lookup) debug_printf_indent("trying to match *\n");
-  yield = internal_search_find(handle, filename, US"*", opts);
+  yield = internal_search_find(handle, filename, US"*", cache_rd, opts);
   if (yield && expand_setup && *expand_setup >= 0)
     {
     *expand_setup += 1;
@@ -843,14 +870,8 @@ if (set_null_wild && expand_setup && *expand_setup >= 0)
 than the result.  Return a de-tainted version of the key on the grounds that
 it have been validated by the lookup. */
 
-if (yield && opts)
-  {
-  int sep = ',';
-  uschar * ele;
-  while ((ele = string_nextinlist(&opts, &sep, NULL, 0)))
-    if (Ustrcmp(ele, "ret=key") == 0)
-      { yield = string_copy_taint(keystring, FALSE); break; }
-  }
+if (yield && ret_key)
+  yield = string_copy_taint(keystring, FALSE);
 
 return yield;
 }
diff --git a/test/scripts/2500-dsearch/2500 b/test/scripts/2500-dsearch/2500
index 381ef2563..8677b7166 100644
--- a/test/scripts/2500-dsearch/2500
+++ b/test/scripts/2500-dsearch/2500
@@ -1,6 +1,7 @@
 # dsearch lookup
 # This test will fail on a case-insensitive filesystem (e.g. MacOS default)
 exim -be
+dsearch specifics
 ok:         ${lookup{TESTNUM.tst}		dsearch{DIR/aux-fixed}{$value}{FAIL}}
 fail:       ${lookup{TESTNUM.file_not_here}	dsearch{DIR/aux-fixed}{$value}{FAIL}}
 fail:       ${lookup{TESTNUM.tst}		dsearch{DIR/dir_not_here}{$value}{FAIL}}
@@ -16,6 +17,16 @@ fail,dir:   ${lookup{TESTNUM.tst} dsearch,filter=dir    {DIR/aux-fixed}{$value}{
 ok,subdir:  ${lookup{TESTNUM.dir} dsearch,filter=subdir {DIR/aux-fixed}{$value}{FAIL}}
 fail,subdir:${lookup{..}          dsearch,filter=subdir {DIR/aux-fixed}{$value}{FAIL}}
 fail,subdir:${lookup{TESTNUM.tst} dsearch,filter=subdir {DIR/aux-fixed}{$value}{FAIL}}
+
+cachelayer tests
+fail:       ${lookup{test-data}   dsearch               {DIR/}          {$value}{FAIL}}
+createfile: ${run {/bin/cp DIR/aux-fixed/TESTNUM.tst DIR/test-data} {OK}{FAIL}}
+fail,cached:${lookup{test-data}   dsearch               {DIR/}         {$value}{FAIL}}
+ok,no_rd    ${lookup{test-data}   dsearch,cache=no_rd   {DIR/}         {$value}{FAIL}}
+delfile:    ${run {/bin/rm DIR/test-data}                            {OK}{FAIL}}
+ok,cached:  ${lookup{test-data}   dsearch               {DIR/}         {$value}{FAIL}}
+fail,no_rd  ${lookup{test-data}   dsearch,cache=no_rd   {DIR/}         {$value}{FAIL}}
+fail:       ${lookup{test-data}   dsearch               {DIR/}         {$value}{FAIL}}
 ****
 #
 1
diff --git a/test/stderr/0002 b/test/stderr/0002
index 9d6fb5df8..bd2d8067f 100644
--- a/test/stderr/0002
+++ b/test/stderr/0002
@@ -326,6 +326,7 @@ internal_search_find: file="TESTSUITE/aux-fixed/0002.lsearch"
   type=lsearch key="ten-1.test.ex" opts=NULL
 file lookup required for ten-1.test.ex
   in TESTSUITE/aux-fixed/0002.lsearch
+creating new cache entry
 lookup yielded: 
 host in "<
  partial-lsearch;TESTSUITE/aux-fixed/0002.lsearch 
@@ -372,6 +373,7 @@ internal_search_find: file="TESTSUITE/aux-fixed/0002.lsearch"
   type=lsearch key="V4NET.0.0.2" opts=NULL
 file lookup required for V4NET.0.0.2
   in TESTSUITE/aux-fixed/0002.lsearch
+creating new cache entry
 lookup failed
 host in "net-lsearch;TESTSUITE/aux-fixed/0002.lsearch"? no (end of list)
 deny: condition test failed in ACL "connect2"
diff --git a/test/stderr/0085 b/test/stderr/0085
index e27089647..7a30dfe54 100644
--- a/test/stderr/0085
+++ b/test/stderr/0085
@@ -54,6 +54,7 @@ checking local_parts
    type=lsearch key="smart.domain" opts=NULL
  file lookup required for smart.domain
    in TESTSUITE/aux-fixed/0085.data
+ creating new cache entry
  lookup yielded: x : y : abc@d.e.f
 x in "x : y : abc@d.e.f"? yes (matched "x")
 checking senders
@@ -124,6 +125,7 @@ checking local_parts
    type=lsearch key="test.ex" opts=NULL
  file lookup required for test.ex
    in TESTSUITE/aux-fixed/0085.data
+ creating new cache entry
  lookup yielded: x : y : abc@d.e.f
 x in "x : y : abc@d.e.f"? yes (matched "x")
 checking senders
@@ -158,6 +160,7 @@ checking require_files
    type=lsearch key="test.ex.files" opts=NULL
  file lookup required for test.ex.files
    in TESTSUITE/aux-fixed/0085.data
+ creating new cache entry
  lookup yielded: /etc/passwd
 file check: ${lookup{$domain.files}lsearch{TESTSUITE/aux-fixed/0085.data}{$value}}
 expanded file: /etc/passwd
@@ -255,6 +258,7 @@ checking local_parts
    type=lsearch key="smart.domain" opts=NULL
  file lookup required for smart.domain
    in TESTSUITE/aux-fixed/0085.data
+ creating new cache entry
  lookup yielded: x : y : abc@d.e.f
 x in "x : y : abc@d.e.f"? yes (matched "x")
 checking senders
@@ -323,6 +327,7 @@ checking local_parts
    type=lsearch key="test.ex" opts=NULL
  file lookup required for test.ex
    in TESTSUITE/aux-fixed/0085.data
+ creating new cache entry
  lookup yielded: x : y : abc@d.e.f
 x in "x : y : abc@d.e.f"? yes (matched "x")
 checking senders
diff --git a/test/stderr/0123 b/test/stderr/0123
index d393252b5..347d9761b 100644
--- a/test/stderr/0123
+++ b/test/stderr/0123
@@ -27,6 +27,7 @@ rda_interpret (string): '${lookup{$local_part}lsearch{TESTSUITE/aux-fixed/0123.a
    type=lsearch key="x" opts=NULL
  file lookup required for x
    in TESTSUITE/aux-fixed/0123.aliases1
+ creating new cache entry
  lookup failed
 expanded: ''
 file is not a filter file
@@ -47,6 +48,7 @@ rda_interpret (string): '${lookup{$local_part}lsearch{TESTSUITE/aux-fixed/0123.a
    type=lsearch key="x" opts=NULL
  file lookup required for x
    in TESTSUITE/aux-fixed/0123.aliases2
+ creating new cache entry
  lookup failed
 expanded: ''
 file is not a filter file
@@ -69,6 +71,7 @@ rda_interpret (string): '${lookup{$local_part}lsearch{TESTSUITE/aux-fixed/0123.a
    type=lsearch key="x" opts=NULL
  file lookup required for x
    in TESTSUITE/aux-fixed/0123.aliases3
+ creating new cache entry
  lookup failed
 expanded: ''
 file is not a filter file
@@ -91,6 +94,7 @@ rda_interpret (string): '${lookup{$local_part}lsearch{TESTSUITE/aux-fixed/0123.a
    type=lsearch key="x" opts=NULL
  file lookup required for x
    in TESTSUITE/aux-fixed/0123.aliases4
+ creating new cache entry
  lookup failed
 expanded: ''
 file is not a filter file
@@ -113,6 +117,7 @@ rda_interpret (string): '${lookup{$local_part}lsearch{TESTSUITE/aux-fixed/0123.a
    type=lsearch key="x" opts=NULL
  file lookup required for x
    in TESTSUITE/aux-fixed/0123.aliases5
+ creating new cache entry
  lookup failed
 expanded: ''
 file is not a filter file
@@ -135,6 +140,7 @@ rda_interpret (string): '${lookup{$local_part}lsearch{TESTSUITE/aux-fixed/0123.a
    type=lsearch key="x" opts=NULL
  file lookup required for x
    in TESTSUITE/aux-fixed/0123.aliases6
+ creating new cache entry
  lookup failed
 expanded: ''
 file is not a filter file
@@ -165,6 +171,7 @@ rda_interpret (string): '${lookup{$local_part}lsearch{TESTSUITE/aux-fixed/0123.a
    type=lsearch key="y" opts=NULL
  file lookup required for y
    in TESTSUITE/aux-fixed/0123.aliases1
+ creating new cache entry
  lookup failed
 expanded: ''
 file is not a filter file
@@ -188,6 +195,7 @@ rda_interpret (string): '${lookup{$local_part}lsearch{TESTSUITE/aux-fixed/0123.a
    type=lsearch key="y" opts=NULL
  file lookup required for y
    in TESTSUITE/aux-fixed/0123.aliases2
+ creating new cache entry
  lookup failed
 expanded: ''
 file is not a filter file
@@ -211,6 +219,7 @@ rda_interpret (string): '${lookup{$local_part}lsearch{TESTSUITE/aux-fixed/0123.a
    type=lsearch key="y" opts=NULL
  file lookup required for y
    in TESTSUITE/aux-fixed/0123.aliases3
+ creating new cache entry
  lookup failed
 expanded: ''
 file is not a filter file
@@ -234,6 +243,7 @@ rda_interpret (string): '${lookup{$local_part}lsearch{TESTSUITE/aux-fixed/0123.a
    type=lsearch key="y" opts=NULL
  file lookup required for y
    in TESTSUITE/aux-fixed/0123.aliases4
+ creating new cache entry
  lookup failed
 expanded: ''
 file is not a filter file
@@ -257,6 +267,7 @@ rda_interpret (string): '${lookup{$local_part}lsearch{TESTSUITE/aux-fixed/0123.a
    type=lsearch key="y" opts=NULL
  file lookup required for y
    in TESTSUITE/aux-fixed/0123.aliases5
+ creating new cache entry
  lookup failed
 expanded: ''
 file is not a filter file
@@ -280,6 +291,7 @@ rda_interpret (string): '${lookup{$local_part}lsearch{TESTSUITE/aux-fixed/0123.a
    type=lsearch key="y" opts=NULL
  file lookup required for y
    in TESTSUITE/aux-fixed/0123.aliases6
+ creating new cache entry
  lookup failed
 expanded: ''
 file is not a filter file
@@ -310,6 +322,7 @@ rda_interpret (string): '${lookup{$local_part}lsearch{TESTSUITE/aux-fixed/0123.a
    type=lsearch key="z" opts=NULL
  file lookup required for z
    in TESTSUITE/aux-fixed/0123.aliases1
+ creating new cache entry
  lookup failed
 expanded: ''
 file is not a filter file
@@ -333,6 +346,7 @@ rda_interpret (string): '${lookup{$local_part}lsearch{TESTSUITE/aux-fixed/0123.a
    type=lsearch key="z" opts=NULL
  file lookup required for z
    in TESTSUITE/aux-fixed/0123.aliases2
+ creating new cache entry
  lookup failed
 expanded: ''
 file is not a filter file
@@ -356,6 +370,7 @@ rda_interpret (string): '${lookup{$local_part}lsearch{TESTSUITE/aux-fixed/0123.a
    type=lsearch key="z" opts=NULL
  file lookup required for z
    in TESTSUITE/aux-fixed/0123.aliases3
+ creating new cache entry
  lookup failed
 expanded: ''
 file is not a filter file
@@ -379,6 +394,7 @@ rda_interpret (string): '${lookup{$local_part}lsearch{TESTSUITE/aux-fixed/0123.a
    type=lsearch key="z" opts=NULL
  file lookup required for z
    in TESTSUITE/aux-fixed/0123.aliases4
+ creating new cache entry
  lookup failed
 expanded: ''
 file is not a filter file
@@ -402,6 +418,7 @@ rda_interpret (string): '${lookup{$local_part}lsearch{TESTSUITE/aux-fixed/0123.a
    type=lsearch key="z" opts=NULL
  file lookup required for z
    in TESTSUITE/aux-fixed/0123.aliases5
+ creating new cache entry
  lookup failed
 expanded: ''
 file is not a filter file
@@ -425,6 +442,7 @@ rda_interpret (string): '${lookup{$local_part}lsearch{TESTSUITE/aux-fixed/0123.a
    type=lsearch key="z" opts=NULL
  file lookup required for z
    in TESTSUITE/aux-fixed/0123.aliases6
+ creating new cache entry
  lookup failed
 expanded: ''
 file is not a filter file
diff --git a/test/stderr/0387 b/test/stderr/0387
index 292f52337..0a27a5878 100644
--- a/test/stderr/0387
+++ b/test/stderr/0387
@@ -13,18 +13,21 @@ dropping to exim gid; retaining priv uid
    type=lsearch key="a.b.c" opts=NULL
  file lookup required for a.b.c
    in TESTSUITE/aux-fixed/0387.1
+ creating new cache entry
  lookup failed
  trying partial match *.a.b.c
  internal_search_find: file="TESTSUITE/aux-fixed/0387.1"
    type=lsearch key="*.a.b.c" opts=NULL
  file lookup required for *.a.b.c
    in TESTSUITE/aux-fixed/0387.1
+ creating new cache entry
  lookup failed
  trying partial match *.b.c
  internal_search_find: file="TESTSUITE/aux-fixed/0387.1"
    type=lsearch key="*.b.c" opts=NULL
  file lookup required for *.b.c
    in TESTSUITE/aux-fixed/0387.1
+ creating new cache entry
  lookup yielded: [*.b.c]
  search_open: lsearch "TESTSUITE/aux-fixed/0387.1"
    cached open
@@ -37,18 +40,21 @@ dropping to exim gid; retaining priv uid
    type=lsearch key="x.y.c" opts=NULL
  file lookup required for x.y.c
    in TESTSUITE/aux-fixed/0387.1
+ creating new cache entry
  lookup failed
  trying partial match *.x.y.c
  internal_search_find: file="TESTSUITE/aux-fixed/0387.1"
    type=lsearch key="*.x.y.c" opts=NULL
  file lookup required for *.x.y.c
    in TESTSUITE/aux-fixed/0387.1
+ creating new cache entry
  lookup failed
  trying partial match *.y.c
  internal_search_find: file="TESTSUITE/aux-fixed/0387.1"
    type=lsearch key="*.y.c" opts=NULL
  file lookup required for *.y.c
    in TESTSUITE/aux-fixed/0387.1
+ creating new cache entry
  lookup failed
  search_open: lsearch "TESTSUITE/aux-fixed/0387.1"
    cached open
@@ -79,6 +85,7 @@ dropping to exim gid; retaining priv uid
    type=lsearch key="*" opts=NULL
  file lookup required for *
    in TESTSUITE/aux-fixed/0387.1
+ creating new cache entry
  lookup yielded: [*]
  search_open: lsearch "TESTSUITE/aux-fixed/0387.1"
    cached open
@@ -109,6 +116,7 @@ dropping to exim gid; retaining priv uid
    type=lsearch key="*.c" opts=NULL
  file lookup required for *.c
    in TESTSUITE/aux-fixed/0387.1
+ creating new cache entry
  lookup yielded: [*.c]
  search_open: lsearch "TESTSUITE/aux-fixed/0387.1"
    cached open
@@ -121,12 +129,14 @@ dropping to exim gid; retaining priv uid
    type=lsearch key="x@y.c" opts=NULL
  file lookup required for x@y.c
    in TESTSUITE/aux-fixed/0387.1
+ creating new cache entry
  lookup failed
  trying partial match *.x@y.c
  internal_search_find: file="TESTSUITE/aux-fixed/0387.1"
    type=lsearch key="*.x@y.c" opts=NULL
  file lookup required for *.x@y.c
    in TESTSUITE/aux-fixed/0387.1
+ creating new cache entry
  lookup failed
  trying partial match *.c
  internal_search_find: file="TESTSUITE/aux-fixed/0387.1"
@@ -151,6 +161,7 @@ dropping to exim gid; retaining priv uid
    type=lsearch key="*@y.c" opts=NULL
  file lookup required for *@y.c
    in TESTSUITE/aux-fixed/0387.1
+ creating new cache entry
  lookup yielded: [*@y.c]
  search_open: lsearch "TESTSUITE/aux-fixed/0387.1"
    cached open
@@ -193,12 +204,14 @@ dropping to exim gid; retaining priv uid
    type=lsearch key=".a.b.c" opts=NULL
  file lookup required for .a.b.c
    in TESTSUITE/aux-fixed/0387.1
+ creating new cache entry
  lookup failed
  trying partial match .b.c
  internal_search_find: file="TESTSUITE/aux-fixed/0387.1"
    type=lsearch key=".b.c" opts=NULL
  file lookup required for .b.c
    in TESTSUITE/aux-fixed/0387.1
+ creating new cache entry
  lookup yielded: [.b.c]
  search_open: lsearch "TESTSUITE/aux-fixed/0387.1"
    cached open
@@ -217,6 +230,7 @@ dropping to exim gid; retaining priv uid
    type=lsearch key="b.c" opts=NULL
  file lookup required for b.c
    in TESTSUITE/aux-fixed/0387.1
+ creating new cache entry
  lookup yielded: [b.c]
  search_open: lsearch "TESTSUITE/aux-fixed/0387.1"
    cached open
@@ -235,12 +249,14 @@ dropping to exim gid; retaining priv uid
    type=lsearch key="*a.b.c" opts=NULL
  file lookup required for *a.b.c
    in TESTSUITE/aux-fixed/0387.1
+ creating new cache entry
  lookup failed
  trying partial match *b.c
  internal_search_find: file="TESTSUITE/aux-fixed/0387.1"
    type=lsearch key="*b.c" opts=NULL
  file lookup required for *b.c
    in TESTSUITE/aux-fixed/0387.1
+ creating new cache entry
  lookup yielded: [*b.c]
  search_open: lsearch "TESTSUITE/aux-fixed/0387.1"
    cached open
@@ -253,24 +269,28 @@ dropping to exim gid; retaining priv uid
    type=lsearch key="p.q.r" opts=NULL
  file lookup required for p.q.r
    in TESTSUITE/aux-fixed/0387.1
+ creating new cache entry
  lookup failed
  trying partial match *.p.q.r
  internal_search_find: file="TESTSUITE/aux-fixed/0387.1"
    type=lsearch key="*.p.q.r" opts=NULL
  file lookup required for *.p.q.r
    in TESTSUITE/aux-fixed/0387.1
+ creating new cache entry
  lookup failed
  trying partial match *.q.r
  internal_search_find: file="TESTSUITE/aux-fixed/0387.1"
    type=lsearch key="*.q.r" opts=NULL
  file lookup required for *.q.r
    in TESTSUITE/aux-fixed/0387.1
+ creating new cache entry
  lookup failed
  trying partial match *.r
  internal_search_find: file="TESTSUITE/aux-fixed/0387.1"
    type=lsearch key="*.r" opts=NULL
  file lookup required for *.r
    in TESTSUITE/aux-fixed/0387.1
+ creating new cache entry
  lookup failed
  trying partial match *
  internal_search_find: file="TESTSUITE/aux-fixed/0387.1"
@@ -295,24 +315,28 @@ dropping to exim gid; retaining priv uid
    type=lsearch key=".p.q.r" opts=NULL
  file lookup required for .p.q.r
    in TESTSUITE/aux-fixed/0387.1
+ creating new cache entry
  lookup failed
  trying partial match .q.r
  internal_search_find: file="TESTSUITE/aux-fixed/0387.1"
    type=lsearch key=".q.r" opts=NULL
  file lookup required for .q.r
    in TESTSUITE/aux-fixed/0387.1
+ creating new cache entry
  lookup failed
  trying partial match .r
  internal_search_find: file="TESTSUITE/aux-fixed/0387.1"
    type=lsearch key=".r" opts=NULL
  file lookup required for .r
    in TESTSUITE/aux-fixed/0387.1
+ creating new cache entry
  lookup failed
  trying partial match .
  internal_search_find: file="TESTSUITE/aux-fixed/0387.1"
    type=lsearch key="." opts=NULL
  file lookup required for .
    in TESTSUITE/aux-fixed/0387.1
+ creating new cache entry
  lookup yielded: [.]
  search_open: lsearch "TESTSUITE/aux-fixed/0387.1"
    cached open
@@ -325,18 +349,21 @@ dropping to exim gid; retaining priv uid
    type=lsearch key="x.aa.bb" opts=NULL
  file lookup required for x.aa.bb
    in TESTSUITE/aux-fixed/0387.1
+ creating new cache entry
  lookup failed
  trying partial match ++x.aa.bb
  internal_search_find: file="TESTSUITE/aux-fixed/0387.1"
    type=lsearch key="++x.aa.bb" opts=NULL
  file lookup required for ++x.aa.bb
    in TESTSUITE/aux-fixed/0387.1
+ creating new cache entry
  lookup failed
  trying partial match ++aa.bb
  internal_search_find: file="TESTSUITE/aux-fixed/0387.1"
    type=lsearch key="++aa.bb" opts=NULL
  file lookup required for ++aa.bb
    in TESTSUITE/aux-fixed/0387.1
+ creating new cache entry
  lookup yielded: [++aa.bb]
  search_open: lsearch "TESTSUITE/aux-fixed/0387.1"
    cached open
@@ -349,30 +376,35 @@ dropping to exim gid; retaining priv uid
    type=lsearch key="x.aa.zz" opts=NULL
  file lookup required for x.aa.zz
    in TESTSUITE/aux-fixed/0387.1
+ creating new cache entry
  lookup failed
  trying partial match ++x.aa.zz
  internal_search_find: file="TESTSUITE/aux-fixed/0387.1"
    type=lsearch key="++x.aa.zz" opts=NULL
  file lookup required for ++x.aa.zz
    in TESTSUITE/aux-fixed/0387.1
+ creating new cache entry
  lookup failed
  trying partial match ++aa.zz
  internal_search_find: file="TESTSUITE/aux-fixed/0387.1"
    type=lsearch key="++aa.zz" opts=NULL
  file lookup required for ++aa.zz
    in TESTSUITE/aux-fixed/0387.1
+ creating new cache entry
  lookup failed
  trying partial match ++zz
  internal_search_find: file="TESTSUITE/aux-fixed/0387.1"
    type=lsearch key="++zz" opts=NULL
  file lookup required for ++zz
    in TESTSUITE/aux-fixed/0387.1
+ creating new cache entry
  lookup failed
  trying partial match ++
  internal_search_find: file="TESTSUITE/aux-fixed/0387.1"
    type=lsearch key="++" opts=NULL
  file lookup required for ++
    in TESTSUITE/aux-fixed/0387.1
+ creating new cache entry
  lookup yielded: [++]
  search_open: lsearch "TESTSUITE/aux-fixed/0387.1"
    cached open
diff --git a/test/stderr/0403 b/test/stderr/0403
index 0c22cf8f5..16bf13b5e 100644
--- a/test/stderr/0403
+++ b/test/stderr/0403
@@ -94,6 +94,7 @@ internal_search_find: file="TESTSUITE/aux-fixed/0403.data"
   type=lsearch key="test.ex" opts=NULL
 file lookup required for test.ex
   in TESTSUITE/aux-fixed/0403.data
+creating new cache entry
 lookup yielded: [DOMAINDATA_test.ex]
 test.ex in "lsearch;TESTSUITE/aux-fixed/0403.data"? yes (matched "lsearch;TESTSUITE/aux-fixed/0403.data")
 checking local_parts
@@ -108,6 +109,7 @@ internal_search_find: file="TESTSUITE/aux-fixed/0403.data"
   type=lsearch key="userx" opts=NULL
 file lookup required for userx
   in TESTSUITE/aux-fixed/0403.data
+creating new cache entry
 lookup yielded: [LOCALPARTDATA_userx]
 userx in "lsearch;TESTSUITE/aux-fixed/0403.data"? yes (matched "lsearch;TESTSUITE/aux-fixed/0403.data")
 +++ROUTER:
diff --git a/test/stderr/0414 b/test/stderr/0414
index f1edd1ae3..18a514700 100644
--- a/test/stderr/0414
+++ b/test/stderr/0414
@@ -28,6 +28,7 @@ internal_search_find: file="TESTSUITE/aux-fixed/0414.list1"
   type=lsearch key="b.domain" opts=NULL
 file lookup required for b.domain
   in TESTSUITE/aux-fixed/0414.list1
+creating new cache entry
 lookup failed
 b.domain in "lsearch;TESTSUITE/aux-fixed/0414.list1"? no (end of list)
 search_open: lsearch "TESTSUITE/aux-fixed/0414.list2"
@@ -41,6 +42,7 @@ internal_search_find: file="TESTSUITE/aux-fixed/0414.list2"
   type=lsearch key="b.domain" opts=NULL
 file lookup required for b.domain
   in TESTSUITE/aux-fixed/0414.list2
+creating new cache entry
 lookup yielded: b.domain-data
 b.domain in "lsearch;TESTSUITE/aux-fixed/0414.list2"? yes (matched "lsearch;TESTSUITE/aux-fixed/0414.list2")
 data from lookup saved for cache for +B: key 'b.domain' value 'b.domain-data'
@@ -87,6 +89,7 @@ internal_search_find: file="TESTSUITE/aux-fixed/0414.list1"
   type=lsearch key="a.domain" opts=NULL
 file lookup required for a.domain
   in TESTSUITE/aux-fixed/0414.list1
+creating new cache entry
 lookup yielded: a.domain-data
 a.domain in "lsearch;TESTSUITE/aux-fixed/0414.list1"? yes (matched "lsearch;TESTSUITE/aux-fixed/0414.list1")
 data from lookup saved for cache for +A: key 'a.domain' value 'a.domain-data'
@@ -109,6 +112,7 @@ internal_search_find: file="TESTSUITE/aux-fixed/0414.list2"
   type=lsearch key="a.domain" opts=NULL
 file lookup required for a.domain
   in TESTSUITE/aux-fixed/0414.list2
+creating new cache entry
 lookup failed
 a.domain in "lsearch;TESTSUITE/aux-fixed/0414.list2"? no (end of list)
 a.domain in "+B"? no (end of list)
diff --git a/test/stderr/0437 b/test/stderr/0437
index 0e5a5b3e9..8c2cf0a8a 100644
--- a/test/stderr/0437
+++ b/test/stderr/0437
@@ -9,6 +9,7 @@ Exim version x.yz ....
    type=lsearch key="spool" opts=NULL
  file lookup required for spool
    in TESTSUITE/aux-fixed/0437.ls
+ creating new cache entry
  lookup yielded: spool
 configuration file is TESTSUITE/test-config
 admin user
@@ -26,6 +27,7 @@ search_tidyup called
    type=lsearch key="transport" opts=NULL
  file lookup required for transport
    in TESTSUITE/aux-fixed/0437.ls
+ creating new cache entry
  lookup yielded: t1
 search_tidyup called
 search_tidyup called
@@ -39,6 +41,7 @@ search_tidyup called
    type=lsearch key="file" opts=NULL
  file lookup required for file
    in TESTSUITE/aux-fixed/0437.ls
+ creating new cache entry
  lookup yielded: file
 search_tidyup called
 LOG: MAIN
@@ -58,6 +61,7 @@ search_tidyup called
    type=lsearch key="transport" opts=NULL
  file lookup required for transport
    in TESTSUITE/aux-fixed/0437.ls
+ creating new cache entry
  lookup yielded: t1
 search_tidyup called
 search_tidyup called
@@ -71,6 +75,7 @@ search_tidyup called
    type=lsearch key="file" opts=NULL
  file lookup required for file
    in TESTSUITE/aux-fixed/0437.ls
+ creating new cache entry
  lookup yielded: file
 search_tidyup called
 LOG: MAIN
diff --git a/test/stderr/0464 b/test/stderr/0464
index 6ea3f3f97..625b57122 100644
--- a/test/stderr/0464
+++ b/test/stderr/0464
@@ -31,6 +31,7 @@ internal_search_find: file="TESTSUITE/aux-fixed/0464.domains"
   type=lsearch key="domain1" opts=NULL
 file lookup required for domain1
   in TESTSUITE/aux-fixed/0464.domains
+creating new cache entry
 lookup yielded: data for domain1
 domain1 in "lsearch;TESTSUITE/aux-fixed/0464.domains"? yes (matched "lsearch;TESTSUITE/aux-fixed/0464.domains")
 data from lookup saved for cache for +special_domains: key 'domain1' value 'data for domain1'
@@ -78,6 +79,7 @@ internal_search_find: file="TESTSUITE/aux-fixed/0464.domains"
   type=lsearch key="xxx.domain1" opts=NULL
 file lookup required for xxx.domain1
   in TESTSUITE/aux-fixed/0464.domains
+creating new cache entry
 lookup failed
 xxx.domain1 in "lsearch;TESTSUITE/aux-fixed/0464.domains"? no (end of list)
 xxx.domain1 in "+special_domains"? no (end of list)
diff --git a/test/stderr/0471 b/test/stderr/0471
index f4619a3e9..14fbe5534 100644
--- a/test/stderr/0471
+++ b/test/stderr/0471
@@ -111,12 +111,14 @@ r1@test.ex in "*@*"? yes (matched "*@*")
    type=lsearch key="test.ex" opts=NULL
  file lookup required for test.ex
    in TESTSUITE/aux-fixed/0471.rw
+ creating new cache entry
  lookup failed
  trying partial match *.test.ex
  internal_search_find: file="TESTSUITE/aux-fixed/0471.rw"
    type=lsearch key="*.test.ex" opts=NULL
  file lookup required for *.test.ex
    in TESTSUITE/aux-fixed/0471.rw
+ creating new cache entry
  lookup failed
 address match test: subject=CALLER@myhost.test.ex pattern=*@*
 myhost.test.ex in "*"? yes (matched "*")
@@ -132,12 +134,14 @@ CALLER@myhost.test.ex in "*@*"? yes (matched "*@*")
    type=lsearch key="myhost.test.ex" opts=NULL
  file lookup required for myhost.test.ex
    in TESTSUITE/aux-fixed/0471.rw
+ creating new cache entry
  lookup failed
  trying partial match *.myhost.test.ex
  internal_search_find: file="TESTSUITE/aux-fixed/0471.rw"
    type=lsearch key="*.myhost.test.ex" opts=NULL
  file lookup required for *.myhost.test.ex
    in TESTSUITE/aux-fixed/0471.rw
+ creating new cache entry
  lookup failed
  trying partial match *.test.ex
  internal_search_find: file="TESTSUITE/aux-fixed/0471.rw"
@@ -241,6 +245,7 @@ random@test.example in "*@*"? yes (matched "*@*")
    type=lsearch key="test.example" opts=NULL
  file lookup required for test.example
    in TESTSUITE/aux-fixed/0471.rw
+ creating new cache entry
  lookup yielded: rwtest.example
 LOG: address_rewrite MAIN
   "random@test.example" from to: rewritten as "random@rwtest.example" by rule 1
diff --git a/test/stderr/0484 b/test/stderr/0484
index 25d7f745d..56ce2e13a 100644
--- a/test/stderr/0484
+++ b/test/stderr/0484
@@ -16,6 +16,7 @@ sender address = CALLER@myhost.test.ex
    type=lsearch key="list" opts=NULL
  file lookup required for list
    in TESTSUITE/aux-fixed/0484.aliases
+ creating new cache entry
  lookup yielded: userx, usery
  search_open: lsearch "TESTSUITE/aux-fixed/0484.aliases"
    cached open
@@ -40,6 +41,7 @@ sender address = CALLER@myhost.test.ex
    type=lsearch key="root" opts=NULL
  file lookup required for root
    in TESTSUITE/aux-fixed/0484.aliases
+ creating new cache entry
  lookup yielded: userx
  search_open: lsearch "TESTSUITE/aux-fixed/0484.aliases"
    cached open
@@ -76,6 +78,7 @@ sender address = CALLER@myhost.test.ex
    type=lsearch key="list" opts=NULL
  file lookup required for list
    in TESTSUITE/aux-fixed/0484.aliases2
+ creating new cache entry
  lookup yielded: userx2, usery2
  search_open: lsearch "TESTSUITE/aux-fixed/0484.aliases2"
    cached open
@@ -89,6 +92,7 @@ sender address = CALLER@myhost.test.ex
    type=lsearch key="root" opts=NULL
  file lookup required for root
    in TESTSUITE/aux-fixed/0484.aliases2
+ creating new cache entry
  lookup failed
  search_open: lsearch "TESTSUITE/aux-fixed/0484.aliases2"
    cached open
diff --git a/test/stderr/2200 b/test/stderr/2200
index ba50dffa7..9631e9b82 100644
--- a/test/stderr/2200
+++ b/test/stderr/2200
@@ -10,6 +10,7 @@ dropping to exim gid; retaining priv uid
    type=dnsdb key="a=localhost.test.ex" opts=NULL
  database lookup required for a=localhost.test.ex
  dnsdb key: localhost.test.ex
+ creating new cache entry
  lookup yielded: 127.0.0.1
  search_open: dnsdb "NULL"
    cached open
@@ -35,6 +36,7 @@ search_tidyup called
     type=dnsdb key="a=shorthost.test.ex" opts=NULL
   database lookup required for a=shorthost.test.ex
   dnsdb key: shorthost.test.ex
+  creating new cache entry
   lookup yielded: 127.0.0.1
   search_open: dnsdb "NULL"
     cached open
@@ -45,6 +47,7 @@ search_tidyup called
     type=dnsdb key="a=shorthost.test.ex" opts=NULL
   cached data found but out-of-date;   database lookup required for a=shorthost.test.ex
   dnsdb key: shorthost.test.ex
+  replacing old cache entry
   lookup yielded: 127.0.0.1
 LOG: MAIN
   <= CALLER@myhost.test.ex U=CALLER P=local S=sss
diff --git a/test/stderr/2201 b/test/stderr/2201
index 8f9d0b585..d25ac4575 100644
--- a/test/stderr/2201
+++ b/test/stderr/2201
@@ -37,6 +37,7 @@ database lookup required for test.ex
 dnsdb key: test.ex
 DNS lookup of test.ex (TXT) using fakens
 DNS lookup of test.ex (TXT) succeeded
+creating new cache entry
 lookup yielded: A TXT record for test.ex.
 test.ex in "dnsdb;test.ex"? yes (matched "dnsdb;test.ex")
 checking local_parts
@@ -101,6 +102,7 @@ DNS lookup of unknown (TXT) gave HOST_NOT_FOUND
 returning DNS_NOMATCH
 faking res_search(TXT) response length as 65535
  writing neg-cache entry for unknown-TXT-xxxx, ttl 3000
+creating new cache entry
 lookup failed
 unknown in "dnsdb;unknown"? no (end of list)
 r1 router skipped: local_parts mismatch
@@ -130,6 +132,7 @@ database lookup required for A=myhost.test.ex
 dnsdb key: myhost.test.ex
 DNS lookup of myhost.test.ex (A) using fakens
 DNS lookup of myhost.test.ex (A) succeeded
+creating new cache entry
 lookup yielded: V4NET.10.10.10
 CALLER@myhost.test.ex in "dnsdb;A=myhost.test.ex"? yes (matched "dnsdb;A=myhost.test.ex")
 calling r2 router
@@ -159,6 +162,7 @@ internal_search_find: file="NULL"
   type=dnsdb key="a=shorthost.test.ex" opts=NULL
 database lookup required for a=shorthost.test.ex
 dnsdb key: shorthost.test.ex
+creating new cache entry
 lookup yielded: 127.0.0.1
 search_open: dnsdb "NULL"
   cached open
@@ -178,6 +182,7 @@ internal_search_find: file="NULL"
   type=dnsdb key="a=shorthost.test.ex" opts=NULL
 cached data found but out-of-date; database lookup required for a=shorthost.test.ex
 dnsdb key: shorthost.test.ex
+replacing old cache entry
 lookup yielded: 127.0.0.1
 LOG: MAIN
   <= a@shorthost.test.ex U=CALLER P=local S=sss
diff --git a/test/stderr/2202 b/test/stderr/2202
index 3752ec538..2c595a6dd 100644
--- a/test/stderr/2202
+++ b/test/stderr/2202
@@ -44,6 +44,7 @@ cioce.test.again.dns in dns_again_means_nonexist? yes (matched "*")
 cioce.test.again.dns is in dns_again_means_nonexist: returning DNS_NOMATCH
 DNS: no SOA record found for neg-TTL
  writing neg-cache entry for cioce.test.again.dns-MX-xxxx, ttl -1
+ creating new cache entry
  lookup failed
 sender host name required, to match against *.cioce.test.again.dns
 looking up host name for ip4.ip4.ip4.ip4
diff --git a/test/stderr/2600 b/test/stderr/2600
index 399fa0adb..e5dd60a27 100644
--- a/test/stderr/2600
+++ b/test/stderr/2600
@@ -10,6 +10,7 @@ dropping to exim gid; retaining priv uid
    type=sqlite key="select name from them where id='userx';" opts=NULL
  file lookup required for select name from them where id='userx';
    in TESTSUITE/aux-fixed/sqlitedb
+ creating new cache entry
  lookup yielded: Ayen Other
  search_open: sqlite "TESTSUITE/aux-fixed/sqlitedb"
    cached open
@@ -41,6 +42,7 @@ dropping to exim gid; retaining priv uid
    type=sqlite key="select name from them where id='nothing';" opts=NULL
  file lookup required for select name from them where id='nothing';
    in TESTSUITE/aux-fixed/sqlitedb
+ creating new cache entry
  lookup yielded: 
  search_open: sqlite "TESTSUITE/aux-fixed/sqlitedb"
    cached open
@@ -51,6 +53,7 @@ dropping to exim gid; retaining priv uid
    type=sqlite key="select id,name from them where id='nothing';" opts=NULL
  file lookup required for select id,name from them where id='nothing';
    in TESTSUITE/aux-fixed/sqlitedb
+ creating new cache entry
  lookup yielded: id=nothing name="" 
  search_open: sqlite "TESTSUITE/aux-fixed/sqlitedb"
    cached open
@@ -61,6 +64,7 @@ dropping to exim gid; retaining priv uid
    type=sqlite key="select * from them where id='quote2';" opts=NULL
  file lookup required for select * from them where id='quote2';
    in TESTSUITE/aux-fixed/sqlitedb
+ creating new cache entry
  lookup yielded: name="\"stquot" id=quote2 
  search_open: sqlite "TESTSUITE/aux-fixed/sqlitedb"
    cached open
@@ -71,6 +75,7 @@ dropping to exim gid; retaining priv uid
    type=sqlite key="select * from them where id='newline';" opts=NULL
  file lookup required for select * from them where id='newline';
    in TESTSUITE/aux-fixed/sqlitedb
+ creating new cache entry
  lookup yielded: name="before
  after" id=newline 
  search_open: sqlite "TESTSUITE/aux-fixed/sqlitedb"
@@ -82,6 +87,7 @@ dropping to exim gid; retaining priv uid
    type=sqlite key="select * from them where id='tab';" opts=NULL
  file lookup required for select * from them where id='tab';
    in TESTSUITE/aux-fixed/sqlitedb
+ creating new cache entry
  lookup yielded: name="x	x" id=tab 
  search_open: sqlite "TESTSUITE/aux-fixed/sqlitedb"
    cached open
@@ -92,6 +98,7 @@ dropping to exim gid; retaining priv uid
    type=sqlite key="select * from them where id='its';" opts=NULL
  file lookup required for select * from them where id='its';
    in TESTSUITE/aux-fixed/sqlitedb
+ creating new cache entry
  lookup yielded: name=it's id=its 
  search_open: sqlite "TESTSUITE/aux-fixed/sqlitedb"
    cached open
@@ -102,6 +109,7 @@ dropping to exim gid; retaining priv uid
    type=sqlite key="select * from them where name='it''s';" opts=NULL
  file lookup required for select * from them where name='it''s';
    in TESTSUITE/aux-fixed/sqlitedb
+ creating new cache entry
  lookup yielded: name=it's id=its 
 search_tidyup called
 >>>>>>>>>>>>>>>> Exim pid=pppp (fresh-exec) terminating with rc=0 >>>>>>>>>>>>>>>>
@@ -247,6 +255,7 @@ internal_search_find: file="TESTSUITE/aux-fixed/sqlitedb"
   type=sqlite key="select * from them where id='10.10.10.10'" opts=NULL
 file lookup required for select * from them where id='10.10.10.10'
   in TESTSUITE/aux-fixed/sqlitedb
+creating new cache entry
 lookup yielded: name=ok id=10.10.10.10 
 host in "sqlite;TESTSUITE/aux-fixed/sqlitedb select * from them where id='10.10.10.10'"? yes (matched "sqlite;TESTSUITE/aux-fixed/sqlitedb select * from them where id='10.10.10.10'")
 host in "+relay_hosts"? yes (matched "+relay_hosts")
@@ -377,6 +386,7 @@ processing address_data
    type=sqlite key="select name from them where id='userx'" opts=NULL
  file lookup required for select name from them where id='userx'
    in TESTSUITE/aux-fixed/sqlitedb
+ creating new cache entry
  lookup yielded: Ayen Other
 calling r1 router
 r1 router called for userx@myhost.test.ex
@@ -419,6 +429,7 @@ appendfile transport entered
    type=sqlite key="select id from them where id='userx'" opts=NULL
  file lookup required for select id from them where id='userx'
    in TESTSUITE/aux-fixed/sqlitedb
+ creating new cache entry
  lookup yielded: userx
 appendfile: mode=600 notify_comsat=0 quota=0 warning=0
   file=TESTSUITE/test-mail/userx format=unix
@@ -481,6 +492,7 @@ dropping to exim gid; retaining priv uid
    type=sqlite key="select name from them where id='userx';" opts=NULL
  file lookup required for select name from them where id='userx';
    in TESTSUITE/aux-fixed/sqlitedb
+ creating new cache entry
  lookup yielded: Ayen Other
 search_tidyup called
 >>>>>>>>>>>>>>>> Exim pid=pppp (fresh-exec) terminating with rc=0 >>>>>>>>>>>>>>>>
@@ -495,6 +507,7 @@ dropping to exim gid; retaining priv uid
  internal_search_find: file="NULL"
    type=sqlite key="select name from them where id='userx';" opts=NULL
  database lookup required for select name from them where id='userx';
+ creating new cache entry
  lookup yielded: Ayen Other
 search_tidyup called
 >>>>>>>>>>>>>>>> Exim pid=pppp (fresh-exec) terminating with rc=0 >>>>>>>>>>>>>>>>
diff --git a/test/stderr/2610 b/test/stderr/2610
index 39071aef5..4cc8801f7 100644
--- a/test/stderr/2610
+++ b/test/stderr/2610
@@ -11,6 +11,7 @@ dropping to exim gid; retaining priv uid
  database lookup required for select name from them where id='ph10';
  MySQL query: "select name from them where id='ph10';" opts 'NULL'
  MYSQL new connection: host=127.0.0.1 port=1223 socket=NULL database=test user=root
+ creating new cache entry
  lookup yielded: Philip Hazel
  search_open: mysql "NULL"
    cached open
@@ -32,6 +33,7 @@ dropping to exim gid; retaining priv uid
  MySQL query: "select name from them where id='xxxx';" opts 'NULL'
  MYSQL using cached connection for 127.0.0.1:1223/test/root
  MYSQL: no data found
+ creating new cache entry
  lookup failed
  search_open: mysql "NULL"
    cached open
@@ -43,6 +45,7 @@ dropping to exim gid; retaining priv uid
  database lookup required for select name from them where id='nothing';
  MySQL query: "select name from them where id='nothing';" opts 'NULL'
  MYSQL using cached connection for 127.0.0.1:1223/test/root
+ creating new cache entry
  lookup yielded: 
  search_open: mysql "NULL"
    cached open
@@ -54,6 +57,7 @@ dropping to exim gid; retaining priv uid
  database lookup required for select id,name from them where id='nothing';
  MySQL query: "select id,name from them where id='nothing';" opts 'NULL'
  MYSQL using cached connection for 127.0.0.1:1223/test/root
+ creating new cache entry
  lookup yielded: id=nothing name="" 
  search_open: mysql "NULL"
    cached open
@@ -79,6 +83,7 @@ dropping to exim gid; retaining priv uid
  MySQL query: "select * from them where id='quote';" opts 'NULL'
  MYSQL using cached connection for 127.0.0.1:1223/test/root
  MYSQL: no data found
+ creating new cache entry
  lookup failed
  search_open: mysql "NULL"
    cached open
@@ -91,6 +96,7 @@ dropping to exim gid; retaining priv uid
  MySQL query: "select * from them where id='filter';" opts 'NULL'
  MYSQL using cached connection for 127.0.0.1:1223/test/root
  MYSQL: no data found
+ creating new cache entry
  lookup failed
  search_open: mysql "NULL"
    cached open
@@ -102,6 +108,7 @@ dropping to exim gid; retaining priv uid
  database lookup required for select * from them where id='quote2';
  MySQL query: "select * from them where id='quote2';" opts 'NULL'
  MYSQL using cached connection for 127.0.0.1:1223/test/root
+ creating new cache entry
  lookup yielded: name="\"stquot" id=quote2 
  search_open: mysql "NULL"
    cached open
@@ -114,6 +121,7 @@ dropping to exim gid; retaining priv uid
  MySQL query: "select * from them where id='nlonly';" opts 'NULL'
  MYSQL using cached connection for 127.0.0.1:1223/test/root
  MYSQL: no data found
+ creating new cache entry
  lookup failed
  search_open: mysql "NULL"
    cached open
@@ -135,6 +143,7 @@ dropping to exim gid; retaining priv uid
  database lookup required for servers=127.0.0.1::1223:x; select name from them where id='ph10';
  MySQL query: "servers=127.0.0.1::1223:x; select name from them where id='ph10';" opts 'NULL'
  MYSQL using cached connection for 127.0.0.1:1223/test/root
+ creating new cache entry
  lookup yielded: Philip Hazel
  search_open: mysql "NULL"
    cached open
@@ -146,6 +155,7 @@ dropping to exim gid; retaining priv uid
  database lookup required for servers=127.0.0.1::1223/test/root/:x; select name from them where id='ph10';
  MySQL query: "servers=127.0.0.1::1223/test/root/:x; select name from them where id='ph10';" opts 'NULL'
  MYSQL using cached connection for 127.0.0.1:1223/test/root
+ creating new cache entry
  lookup yielded: Philip Hazel
  search_open: mysql "NULL"
    cached open
@@ -157,6 +167,7 @@ dropping to exim gid; retaining priv uid
  database lookup required for servers=ip4.ip4.ip4.ip4::1223/test/root/:127.0.0.1::1223; select name from them where id='ph10';
  MySQL query: "servers=ip4.ip4.ip4.ip4::1223/test/root/:127.0.0.1::1223; select name from them where id='ph10';" opts 'NULL'
  MYSQL new connection: host=ip4.ip4.ip4.ip4 port=1223 socket=NULL database=test user=root
+ creating new cache entry
  lookup yielded: Philip Hazel
  search_open: mysql "NULL"
    cached open
@@ -168,6 +179,7 @@ dropping to exim gid; retaining priv uid
  database lookup required for servers=localhost(TESTSUITE/mysql/sock)/test/root/; select name from them where id='ph10';
  MySQL query: "servers=localhost(TESTSUITE/mysql/sock)/test/root/; select name from them where id='ph10';" opts 'NULL'
  MYSQL new connection: host=localhost port=0 socket=TESTSUITE/mysql/sock database=test user=root
+ creating new cache entry
  lookup yielded: Philip Hazel
  search_open: mysql "NULL"
    cached open
@@ -179,6 +191,7 @@ dropping to exim gid; retaining priv uid
  database lookup required for SELECT name FROM them WHERE id IN ('ph10', 'aaaa');
  MySQL query: "SELECT name FROM them WHERE id IN ('ph10', 'aaaa');" opts 'NULL'
  MYSQL using cached connection for 127.0.0.1:1223/test/root
+ creating new cache entry
  lookup yielded: Philip Hazel
  Aristotle
  search_open: mysql "NULL"
@@ -191,6 +204,7 @@ dropping to exim gid; retaining priv uid
  database lookup required for SELECT *    FROM them WHERE id IN ('ph10', 'aaaa');
  MySQL query: "SELECT *    FROM them WHERE id IN ('ph10', 'aaaa');" opts 'NULL'
  MYSQL using cached connection for 127.0.0.1:1223/test/root
+ creating new cache entry
  lookup yielded: name="Philip Hazel" id=ph10 
  name=Aristotle id=aaaa 
  search_open: mysql "NULL"
@@ -254,6 +268,7 @@ processing "warn" (TESTSUITE/test-config 25)
  MySQL query: "select name from them where id = 'c'" opts 'NULL'
  MYSQL new connection: host=127.0.0.1 port=1223 socket=NULL database=test user=root
  MYSQL: no data found
+ creating new cache entry
  lookup failed
 check set acl_m0 = ok:   ${lookup mysql                    {select name from them where id = '$local_part'}}
                  = ok:   
@@ -268,6 +283,7 @@ check set acl_m0 = ok:   ${lookup mysql                    {select name from the
  MySQL query: "select name from them where id = 'c'" opts 'servers=127.0.0.1::1223/test/root/'
  MYSQL using cached connection for 127.0.0.1:1223/test/root
  MYSQL: no data found
+ replacing old cache entry
  lookup failed
 check set acl_m0 = ok:   ${lookup mysql,servers=127.0.0.1::1223/test/root/      {select name from them where id = '$local_part'}}
                  = ok:   
@@ -282,6 +298,7 @@ check set acl_m0 = ok:   ${lookup mysql,servers=127.0.0.1::1223/test/root/
  MySQL query: "select name from them where id = 'c'" opts 'servers=127.0.0.1::1223'
  MYSQL using cached connection for 127.0.0.1:1223/test/root
  MYSQL: no data found
+ replacing old cache entry
  lookup failed
 check set acl_m0 = ok:   ${lookup mysql,servers=127.0.0.1::1223    {select name from them where id = '$local_part'}}
                  = ok:   
@@ -312,6 +329,7 @@ database lookup required for select * from them where id='c'
 MySQL query: "select * from them where id='c'" opts 'NULL'
 MYSQL using cached connection for 127.0.0.1:1223/test/root
 MYSQL: no data found
+creating new cache entry
 lookup failed
 host in "net-mysql;select * from them where id='c'"? no (end of list)
 warn: condition test failed in ACL "check_recipient"
@@ -367,6 +385,7 @@ database lookup required for select * from them where id='10.0.0.0'
 MySQL query: "select * from them where id='10.0.0.0'" opts 'NULL'
 MYSQL using cached connection for 127.0.0.1:1223/test/root
 MYSQL: no data found
+creating new cache entry
 lookup failed
 host in "net-mysql;select * from them where id='10.0.0.0'"? no (end of list)
 host in "+relay_hosts"? no (end of list)
@@ -480,6 +499,7 @@ processing address_data
  database lookup required for select name from them where id='ph10'
  MySQL query: "select name from them where id='ph10'" opts 'NULL'
  MYSQL new connection: host=127.0.0.1 port=1223 socket=NULL database=test user=root
+ creating new cache entry
  lookup yielded: Philip Hazel
 calling r1 router
 r1 router called for ph10@myhost.test.ex
@@ -524,6 +544,7 @@ appendfile transport entered
  database lookup required for select id from them where id='ph10'
  MySQL query: "select id from them where id='ph10'" opts 'NULL'
  MYSQL new connection: host=127.0.0.1 port=1223 socket=NULL database=test user=root
+ creating new cache entry
  lookup yielded: ph10
 appendfile: mode=600 notify_comsat=0 quota=0 warning=0
   file=TESTSUITE/test-mail/ph10 format=unix
diff --git a/test/stderr/2620 b/test/stderr/2620
index 8c610d87e..eee26190d 100644
--- a/test/stderr/2620
+++ b/test/stderr/2620
@@ -15,6 +15,7 @@ dropping to exim gid; retaining priv uid
  database lookup required for select name from them where id='ph10';
  PostgreSQL query: "select name from them where id='ph10';" opts 'NULL'
  PGSQL new connection: host=localhost port=1223 database=test user=CALLER
+ creating new cache entry
  lookup yielded: Philip Hazel
  search_open: pgsql "NULL"
    cached open
@@ -36,6 +37,7 @@ dropping to exim gid; retaining priv uid
  PostgreSQL query: "select name from them where id='xxxx';" opts 'NULL'
  PGSQL using cached connection for localhost:1223/test/CALLER
  PGSQL: no data found
+ creating new cache entry
  lookup failed
  search_open: pgsql "NULL"
    cached open
@@ -47,6 +49,7 @@ dropping to exim gid; retaining priv uid
  database lookup required for select name from them where id='nothing';
  PostgreSQL query: "select name from them where id='nothing';" opts 'NULL'
  PGSQL using cached connection for localhost:1223/test/CALLER
+ creating new cache entry
  lookup yielded: 
  search_open: pgsql "NULL"
    cached open
@@ -58,6 +61,7 @@ dropping to exim gid; retaining priv uid
  database lookup required for select id,name from them where id='nothing';
  PostgreSQL query: "select id,name from them where id='nothing';" opts 'NULL'
  PGSQL using cached connection for localhost:1223/test/CALLER
+ creating new cache entry
  lookup yielded: id=nothing name="" 
  search_open: pgsql "NULL"
    cached open
@@ -82,6 +86,7 @@ dropping to exim gid; retaining priv uid
  database lookup required for select * from them where id='quote2';
  PostgreSQL query: "select * from them where id='quote2';" opts 'NULL'
  PGSQL using cached connection for localhost:1223/test/CALLER
+ creating new cache entry
  lookup yielded: name="\"stquot" id=quote2 
  search_open: pgsql "NULL"
    cached open
@@ -93,6 +98,7 @@ dropping to exim gid; retaining priv uid
  database lookup required for select * from them where id='newline';
  PostgreSQL query: "select * from them where id='newline';" opts 'NULL'
  PGSQL using cached connection for localhost:1223/test/CALLER
+ creating new cache entry
  lookup yielded: name="before
  after" id=newline 
  search_open: pgsql "NULL"
@@ -105,6 +111,7 @@ dropping to exim gid; retaining priv uid
  database lookup required for select * from them where id='tab';
  PostgreSQL query: "select * from them where id='tab';" opts 'NULL'
  PGSQL using cached connection for localhost:1223/test/CALLER
+ creating new cache entry
  lookup yielded: name="x	x" id=tab 
  search_open: pgsql "NULL"
    cached open
@@ -116,6 +123,7 @@ dropping to exim gid; retaining priv uid
  database lookup required for select * from them where name='''stquot';
  PostgreSQL query: "select * from them where name='''stquot';" opts 'NULL'
  PGSQL using cached connection for localhost:1223/test/CALLER
+ creating new cache entry
  lookup yielded: name='stquot id=quote1 
  search_open: pgsql "NULL"
    cached open
@@ -137,6 +145,7 @@ dropping to exim gid; retaining priv uid
  database lookup required for servers=localhost::1223:x; select name from them where id='ph10';
  PostgreSQL query: "servers=localhost::1223:x; select name from them where id='ph10';" opts 'NULL'
  PGSQL using cached connection for localhost:1223/test/CALLER
+ creating new cache entry
  lookup yielded: Philip Hazel
  search_open: pgsql "NULL"
    cached open
@@ -148,6 +157,7 @@ dropping to exim gid; retaining priv uid
  database lookup required for servers=localhost::1223/test/CALLER/:x; select name from them where id='ph10';
  PostgreSQL query: "servers=localhost::1223/test/CALLER/:x; select name from them where id='ph10';" opts 'NULL'
  PGSQL using cached connection for localhost:1223/test/CALLER
+ creating new cache entry
  lookup yielded: Philip Hazel
  search_open: pgsql "NULL"
    cached open
@@ -159,6 +169,7 @@ dropping to exim gid; retaining priv uid
  database lookup required for servers=(TESTSUITE/pgsql/.s.PGSQL.1223)/test/CALLER/:x; select name from them where id='ph10';
  PostgreSQL query: "servers=(TESTSUITE/pgsql/.s.PGSQL.1223)/test/CALLER/:x; select name from them where id='ph10';" opts 'NULL'
  PGSQL new connection: socket=TESTSUITE/pgsql/.s.PGSQL.1223 database=test user=CALLER
+ creating new cache entry
  lookup yielded: Philip Hazel
  search_open: pgsql "NULL"
    cached open
@@ -170,6 +181,7 @@ dropping to exim gid; retaining priv uid
  database lookup required for SELECT name FROM them WHERE id IN ('ph10', 'aaaa');
  PostgreSQL query: "SELECT name FROM them WHERE id IN ('ph10', 'aaaa');" opts 'NULL'
  PGSQL using cached connection for localhost:1223/test/CALLER
+ creating new cache entry
  lookup yielded: Philip Hazel
  Aristotle
  search_open: pgsql "NULL"
@@ -182,6 +194,7 @@ dropping to exim gid; retaining priv uid
  database lookup required for SELECT *    FROM them WHERE id IN ('ph10', 'aaaa');
  PostgreSQL query: "SELECT *    FROM them WHERE id IN ('ph10', 'aaaa');" opts 'NULL'
  PGSQL using cached connection for localhost:1223/test/CALLER
+ creating new cache entry
  lookup yielded: name="Philip Hazel" id=ph10 
  name=Aristotle id=aaaa 
  search_open: pgsql "NULL"
@@ -244,6 +257,7 @@ processing "warn" (TESTSUITE/test-config 27)
  PostgreSQL query: "select name from them where id = 'c'" opts 'NULL'
  PGSQL new connection: host=localhost port=1223 database=test user=CALLER
  PGSQL: no data found
+ creating new cache entry
  lookup failed
 check set acl_m0 = ok:   ${lookup pgsql                    {select name from them where id = '$local_part'}}
                  = ok:   
@@ -274,6 +288,7 @@ database lookup required for select * from them where id='c'
 PostgreSQL query: "select * from them where id='c'" opts 'NULL'
 PGSQL using cached connection for localhost:1223/test/CALLER
 PGSQL: no data found
+creating new cache entry
 lookup failed
 host in "net-pgsql;select * from them where id='c'"? no (end of list)
 warn: condition test failed in ACL "check_recipient"
@@ -329,6 +344,7 @@ database lookup required for select * from them where id='10.0.0.0'
 PostgreSQL query: "select * from them where id='10.0.0.0'" opts 'NULL'
 PGSQL using cached connection for localhost:1223/test/CALLER
 PGSQL: no data found
+creating new cache entry
 lookup failed
 host in "net-pgsql;select * from them where id='10.0.0.0'"? no (end of list)
 host in "+relay_hosts"? no (end of list)
@@ -543,6 +559,7 @@ processing address_data
  database lookup required for select name from them where id='ph10'
  PostgreSQL query: "select name from them where id='ph10'" opts 'NULL'
  PGSQL new connection: host=localhost port=1223 database=test user=CALLER
+ creating new cache entry
  lookup yielded: Philip Hazel
 calling r1 router
 r1 router called for CALLER@myhost.test.ex
@@ -587,6 +604,7 @@ appendfile transport entered
  database lookup required for select id from them where id='ph10'
  PostgreSQL query: "select id from them where id='ph10'" opts 'NULL'
  PGSQL new connection: host=localhost port=1223 database=test user=CALLER
+ creating new cache entry
  lookup yielded: ph10
 appendfile: mode=600 notify_comsat=0 quota=0 warning=0
   file=TESTSUITE/test-mail/ph10 format=unix
@@ -651,6 +669,7 @@ dropping to exim gid; retaining priv uid
  database lookup required for select name from them where id='ph10';
  PostgreSQL query: "select name from them where id='ph10';" opts 'NULL'
  PGSQL new connection: socket=TESTSUITE/pgsql/.s.PGSQL.1223 database=test user=CALLER
+ creating new cache entry
  lookup yielded: Philip Hazel
 search_tidyup called
 close PGSQL connection: (TESTSUITE/pgsql/.s.PGSQL.1223)/test/CALLER
diff --git a/test/stderr/3201 b/test/stderr/3201
index 32bf69ca6..601a9ec85 100644
--- a/test/stderr/3201
+++ b/test/stderr/3201
@@ -31,6 +31,7 @@ internal_search_find: file="NULL"
   type=testdb key="fail" opts=NULL
 database lookup required for fail
 testdb lookup forced FAIL
+creating new cache entry
 lookup failed
 host in "testdb;fail"? no (end of list)
 deny: condition test failed in ACL "connect1"
@@ -73,6 +74,7 @@ internal_search_find: file="NULL"
   type=testdb key="fail" opts=NULL
 database lookup required for fail
 testdb lookup forced FAIL
+creating new cache entry
 lookup failed
 host in "net-testdb;fail"? no (end of list)
 deny: condition test failed in ACL "connect2"
diff --git a/test/stderr/3212 b/test/stderr/3212
index 1c944c24c..7b7719801 100644
--- a/test/stderr/3212
+++ b/test/stderr/3212
@@ -16,6 +16,7 @@ sender address = CALLER@myhost.test.ex
    type=lsearch key="list" opts=NULL
  file lookup required for list
    in TESTSUITE/aux-fixed/3212.aliases
+ creating new cache entry
  lookup yielded: userx, usery
  search_open: lsearch "TESTSUITE/aux-fixed/3212.aliases"
    cached open
@@ -40,6 +41,7 @@ sender address = CALLER@myhost.test.ex
    type=lsearch key="root" opts=NULL
  file lookup required for root
    in TESTSUITE/aux-fixed/3212.aliases
+ creating new cache entry
  lookup yielded: userx
  search_open: lsearch "TESTSUITE/aux-fixed/3212.aliases"
    cached open
@@ -74,6 +76,7 @@ sender address = CALLER@myhost.test.ex
  internal_search_find: file="NULL"
    type=testdb key="something" opts=NULL
  database lookup required for something
+ creating new cache entry
  lookup yielded: something
  search_open: testdb "NULL"
    cached open
@@ -108,6 +111,7 @@ sender address = CALLER@myhost.test.ex
  internal_search_find: file="NULL"
    type=testdb key="something" opts=NULL
  database lookup required for something
+ creating new cache entry
  lookup yielded: something
  search_open: lsearch "TESTSUITE/aux-fixed/3212.aliases"
    cached open
diff --git a/test/stdout/2500 b/test/stdout/2500
index 7e413c0a3..c6014d388 100644
--- a/test/stdout/2500
+++ b/test/stdout/2500
@@ -1,3 +1,4 @@
+> dsearch specifics
 > ok:         2500.tst
 > fail:       FAIL
 > Failed: failed to open TESTSUITE/dir_not_here for directory search: No such file or directory
@@ -14,3 +15,13 @@
 > fail,subdir:FAIL
 > fail,subdir:FAIL
 > 
+> cachelayer tests
+> fail:       FAIL
+> createfile: OK
+> fail,cached:FAIL
+> ok,no_rd    test-data
+> delfile:    OK
+> ok,cached:  test-data
+> fail,no_rd  FAIL
+> fail:       FAIL
+>