Rejig debug output in route_finduser() to show more data, including the

error from getpwnam() if it issues one.

29 files changed, 229 insertions, 29 deletions

diff --git a/doc/doc-txt/ChangeLog b/doc/doc-txt/ChangeLog
index e25f552d8..dd6ffa843 100644
--- a/doc/doc-txt/ChangeLog
+++ b/doc/doc-txt/ChangeLog
@@ -1,4 +1,4 @@
-$Cambridge: exim/doc/doc-txt/ChangeLog,v 1.374 2006/07/13 14:46:05 ph10 Exp $
+$Cambridge: exim/doc/doc-txt/ChangeLog,v 1.375 2006/07/14 14:00:16 ph10 Exp $
 
 Change log file for Exim from version 4.21
 -------------------------------------------
@@ -104,6 +104,9 @@ PH/17 Added an extra condition to the default value of delay_warning_condition
       The Auto-Submitted: header is standardised, whereas I don't think
       Precedence: ever was.
 
+PH/18 Refactored debugging code in route_finduser() to show more information,
+      in particular, the error code if getpwnam() issues one.
+
 
 Exim version 4.62
 -----------------
diff --git a/src/src/route.c b/src/src/route.c
index c5594b27c..436f769a2 100644
--- a/src/src/route.c
+++ b/src/src/route.c
@@ -1,4 +1,4 @@
-/* $Cambridge: exim/src/src/route.c,v 1.8 2006/02/07 11:19:00 ph10 Exp $ */
+/* $Cambridge: exim/src/src/route.c,v 1.9 2006/07/14 14:00:16 ph10 Exp $ */
 
 /*************************************************
 *     Exim - an Internet mail transport agent    *
@@ -1077,7 +1077,12 @@ static uschar lastshell[128];
 BOOL
 route_finduser(uschar *s, struct passwd **pw, uid_t *return_uid)
 {
-if (Ustrcmp(lastname, s) != 0)
+BOOL cache_set = (Ustrcmp(lastname, s) == 0);
+
+DEBUG(D_uid) debug_printf("seeking password data for user \"%s\": %s\n", s,
+  cache_set? "using cached result" : "cache not available");
+
+if (!cache_set)
   {
   int i = 0;
 
@@ -1122,14 +1127,25 @@ if (Ustrcmp(lastname, s) != 0)
     pwcopy.pw_shell = CS lastshell;
     lastpw = &pwcopy;
     }
+
+  else DEBUG(D_uid)
+    {
+    if (errno != 0) debug_printf("getpwnam(%s) failed: %s\n", s,
+      strerror(errno));
+    }
+  }
+
+if (lastpw == NULL)
+  {
+  DEBUG(D_uid) debug_printf("getpwnam() returned NULL (user not found)\n");
+  return FALSE;
   }
 else
   {
-  DEBUG(D_uid) debug_printf("finduser used cached passwd data for %s\n", s);
+  DEBUG(D_uid) debug_printf("getpwnam() succeeded uid=%d gid=%d\n",
+    lastpw->pw_uid, lastpw->pw_gid);
   }
 
-if (lastpw == NULL) return FALSE;
-
 if (return_uid != NULL) *return_uid = lastpw->pw_uid;
 if (pw != NULL) *pw = lastpw;
 
diff --git a/test/stderr/0022 b/test/stderr/0022
index deab48a24..4835ebd39 100644
--- a/test/stderr/0022
+++ b/test/stderr/0022
@@ -5,6 +5,8 @@ configuration file is TESTSUITE/test-config
 admin user
 changed uid/gid: privilege not needed
   uid=EXIM_UID gid=EXIM_GID pid=pppp
+seeking password data for user "CALLER": cache not available
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
 originator: uid=CALLER_UID gid=CALLER_GID login=CALLER name=CALLER_NAME
 sender address = CALLER@test.ex
 sender_fullhost = [V4NET.9.8.7]
@@ -66,6 +68,8 @@ configuration file is TESTSUITE/test-config
 admin user
 changed uid/gid: privilege not needed
   uid=EXIM_UID gid=EXIM_GID pid=pppp
+seeking password data for user "CALLER": cache not available
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
 originator: uid=CALLER_UID gid=CALLER_GID login=CALLER name=CALLER_NAME
 sender address = CALLER@test.ex
 sender_fullhost = [V4NET.9.8.7]
@@ -129,6 +133,8 @@ configuration file is TESTSUITE/test-config
 admin user
 changed uid/gid: privilege not needed
   uid=EXIM_UID gid=EXIM_GID pid=pppp
+seeking password data for user "CALLER": cache not available
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
 originator: uid=CALLER_UID gid=CALLER_GID login=CALLER name=CALLER_NAME
 sender address = CALLER@test.ex
 sender_fullhost = [V4NET.9.8.7]
diff --git a/test/stderr/0085 b/test/stderr/0085
index 47b066a8c..675c6452c 100644
--- a/test/stderr/0085
+++ b/test/stderr/0085
@@ -5,6 +5,8 @@ configuration file is TESTSUITE/test-config
 admin user
 changed uid/gid: privilege not needed
   uid=EXIM_UID gid=EXIM_GID pid=pppp
+seeking password data for user "CALLER": cache not available
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
 originator: uid=CALLER_UID gid=CALLER_GID login=CALLER name=CALLER_NAME
 sender address = abc@d.e.f
 Verifying: uid=EXIM_UID gid=EXIM_GID euid=EXIM_UID egid=EXIM_GID
@@ -202,6 +204,8 @@ configuration file is TESTSUITE/test-config
 admin user
 changed uid/gid: privilege not needed
   uid=EXIM_UID gid=EXIM_GID pid=pppp
+seeking password data for user "CALLER": cache not available
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
 originator: uid=CALLER_UID gid=CALLER_GID login=CALLER name=CALLER_NAME
 sender address = CALLER@myhost.test.ex
 Verifying: uid=EXIM_UID gid=EXIM_GID euid=EXIM_UID egid=EXIM_GID
diff --git a/test/stderr/0094 b/test/stderr/0094
index 0e16e5f1a..cb4a9cc86 100644
--- a/test/stderr/0094
+++ b/test/stderr/0094
@@ -67,6 +67,8 @@ configuration file is TESTSUITE/test-config
 admin user
 changed uid/gid: privilege not needed
   uid=EXIM_UID gid=EXIM_GID pid=pppp
+seeking password data for user "CALLER": cache not available
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
 originator: uid=CALLER_UID gid=CALLER_GID login=CALLER name=CALLER_NAME
 sender address = CALLER@test.ex
 sender_fullhost = [V4NET.99.99.90]
diff --git a/test/stderr/0275 b/test/stderr/0275
index 4853b652a..79cdb9dfc 100644
--- a/test/stderr/0275
+++ b/test/stderr/0275
@@ -3,6 +3,8 @@ changed uid/gid: forcing real = effective
   uid=uuuu gid=CALLER_GID pid=pppp
 configuration file is TESTSUITE/test-config
 admin user
+seeking password data for user "CALLER": cache not available
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
 originator: uid=CALLER_UID gid=CALLER_GID login=CALLER name=CALLER_NAME
 sender address = CALLER@test.ex
 Address testing: uid=uuuu gid=EXIM_GID euid=uuuu egid=EXIM_GID
@@ -102,6 +104,8 @@ configuration file is TESTSUITE/test-config
 admin user
 changed uid/gid: privilege not needed
   uid=EXIM_UID gid=EXIM_GID pid=pppp
+seeking password data for user "CALLER": cache not available
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
 originator: uid=CALLER_UID gid=CALLER_GID login=CALLER name=CALLER_NAME
 sender address = CALLER@test.ex
 set_process_info: pppp accepting a local non-SMTP message from <CALLER@test.ex>
@@ -140,6 +144,8 @@ changed uid/gid: forcing real = effective
 configuration file is TESTSUITE/test-config
 trusted user
 admin user
+seeking password data for user "CALLER": cache not available
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
 set_process_info: pppp delivering specified messages
 set_process_info: pppp delivering 10HmaX-0005vi-00
 reading spool file 10HmaX-0005vi-00-H
diff --git a/test/stderr/0278 b/test/stderr/0278
index 2c0389993..39c5a5692 100644
--- a/test/stderr/0278
+++ b/test/stderr/0278
@@ -3,6 +3,8 @@ changed uid/gid: forcing real = effective
   uid=uuuu gid=CALLER_GID pid=pppp
 configuration file is TESTSUITE/test-config
 admin user
+seeking password data for user "CALLER": cache not available
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
 originator: uid=CALLER_UID gid=CALLER_GID login=CALLER name=CALLER_NAME
 sender address = CALLER@test.ex
 Address testing: uid=uuuu gid=EXIM_GID euid=uuuu egid=EXIM_GID
@@ -39,7 +41,8 @@ cached yes match for +local_localparts
 cached lookup data = NULL
 CALLER in "+local_localparts"? yes (matched "+local_localparts" - cached)
 checking for local user
-finduser used cached passwd data for CALLER
+seeking password data for user "CALLER": using cached result
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
 calling r3 router
 r3 router called for CALLER@test.ex
   domain = test.ex
@@ -60,6 +63,8 @@ configuration file is TESTSUITE/test-config
 admin user
 changed uid/gid: privilege not needed
   uid=EXIM_UID gid=EXIM_GID pid=pppp
+seeking password data for user "CALLER": cache not available
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
 originator: uid=CALLER_UID gid=CALLER_GID login=CALLER name=CALLER_NAME
 sender address = CALLER@test.ex
 set_process_info: pppp accepting a local non-SMTP message from <CALLER@test.ex>
@@ -98,6 +103,8 @@ changed uid/gid: forcing real = effective
 configuration file is TESTSUITE/test-config
 trusted user
 admin user
+seeking password data for user "CALLER": cache not available
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
 set_process_info: pppp delivering specified messages
 set_process_info: pppp delivering 10HmaX-0005vi-00
 reading spool file 10HmaX-0005vi-00-H
@@ -151,7 +158,8 @@ cached yes match for +local_localparts
 cached lookup data = NULL
 CALLER in "+local_localparts"? yes (matched "+local_localparts" - cached)
 checking for local user
-finduser used cached passwd data for CALLER
+seeking password data for user "CALLER": using cached result
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
 calling r3 router
 r3 router called for CALLER@test.ex
   domain = test.ex
@@ -220,6 +228,8 @@ changed uid/gid: forcing real = effective
   uid=uuuu gid=CALLER_GID pid=pppp
 configuration file is TESTSUITE/test-config
 admin user
+seeking password data for user "CALLER": cache not available
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
 originator: uid=CALLER_UID gid=CALLER_GID login=CALLER name=CALLER_NAME
 sender address = CALLER@test.ex
 Address testing: uid=uuuu gid=EXIM_GID euid=uuuu egid=EXIM_GID
diff --git a/test/stderr/0279 b/test/stderr/0279
index e97c793f1..5a3b7a099 100644
--- a/test/stderr/0279
+++ b/test/stderr/0279
@@ -1,10 +1,13 @@
 Exim version x.yz ....
 changed uid/gid: forcing real = effective
   uid=uuuu gid=CALLER_GID pid=pppp
+seeking password data for user "CALLER": cache not available
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
 configuration file is TESTSUITE/test-config
 trusted user
 admin user
-finduser used cached passwd data for CALLER
+seeking password data for user "CALLER": using cached result
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
 originator: uid=CALLER_UID gid=CALLER_GID login=CALLER name=
 sender address = CALLER@test.ex
 Address testing: uid=uuuu gid=EXIM_GID euid=uuuu egid=EXIM_GID
@@ -48,7 +51,8 @@ r2 router skipped: senders mismatch
 --------> r3 router <--------
 local_part=CALLER domain=test.ex
 checking for local user
-finduser used cached passwd data for CALLER
+seeking password data for user "CALLER": using cached result
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
 checking senders
 cached yes match for +local_addresses
 cached lookup data = NULL
@@ -69,10 +73,13 @@ search_tidyup called
 Exim version x.yz ....
 changed uid/gid: forcing real = effective
   uid=uuuu gid=CALLER_GID pid=pppp
+seeking password data for user "CALLER": cache not available
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
 configuration file is TESTSUITE/test-config
 trusted user
 admin user
-finduser used cached passwd data for CALLER
+seeking password data for user "CALLER": using cached result
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
 originator: uid=CALLER_UID gid=CALLER_GID login=CALLER name=
 sender address = user1@fun.1
 Address testing: uid=uuuu gid=EXIM_GID euid=uuuu egid=EXIM_GID
diff --git a/test/stderr/0283 b/test/stderr/0283
index 95238bd9a..95d0f0a4e 100644
--- a/test/stderr/0283
+++ b/test/stderr/0283
@@ -1,19 +1,31 @@
 Exim version x.yz ....
 changed uid/gid: forcing real = effective
   uid=uuuu gid=CALLER_GID pid=pppp
+seeking password data for user "root": cache not available
+getpwnam() succeeded uid=uuuu gid=gggg
 configuration file is TESTSUITE/test-config
 admin user
 changed uid/gid: privilege not needed
   uid=EXIM_UID gid=EXIM_GID pid=pppp
+seeking password data for user "CALLER": cache not available
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
+seeking password data for user "root": cache not available
+getpwnam() succeeded uid=uuuu gid=gggg
 LOG: MAIN
   <= CALLER@myhost.test.ex U=CALLER P=local S=sss
 created log directory TESTSUITE/spool/log
 Exim version x.yz ....
 changed uid/gid: forcing real = effective
   uid=uuuu gid=EXIM_GID pid=pppp
+seeking password data for user "root": cache not available
+getpwnam() succeeded uid=uuuu gid=gggg
 configuration file is TESTSUITE/test-config
 trusted user
 admin user
+seeking password data for user "CALLER": cache not available
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
+seeking password data for user "root": cache not available
+getpwnam() succeeded uid=uuuu gid=gggg
 changed uid/gid: local delivery to somebody <somebody@myhost.test.ex> transport=t1
   uid=EXIM_UID gid=EXIM_GID pid=pppp
 transport error EPIPE ignored
@@ -24,19 +36,31 @@ changed uid/gid: post-delivery tidying
 Exim version x.yz ....
 changed uid/gid: forcing real = effective
   uid=uuuu gid=EXIM_GID pid=pppp
+seeking password data for user "root": cache not available
+getpwnam() succeeded uid=uuuu gid=gggg
 configuration file is TESTSUITE/test-config
 trusted user
 admin user
 changed uid/gid: privilege not needed
   uid=EXIM_UID gid=EXIM_GID pid=pppp
+seeking password data for user "CALLER": cache not available
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
+seeking password data for user "root": cache not available
+getpwnam() succeeded uid=uuuu gid=gggg
 LOG: MAIN
   <= <> R=10HmaY-0005vi-00 U=EXIMUSER P=local S=sss
 Exim version x.yz ....
 changed uid/gid: forcing real = effective
   uid=uuuu gid=EXIM_GID pid=pppp
+seeking password data for user "root": cache not available
+getpwnam() succeeded uid=uuuu gid=gggg
 configuration file is TESTSUITE/test-config
 trusted user
 admin user
+seeking password data for user "CALLER": cache not available
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
+seeking password data for user "root": cache not available
+getpwnam() succeeded uid=uuuu gid=gggg
 changed uid/gid: local delivery to CALLER <CALLER@myhost.test.ex> transport=t2
   uid=CALLER_UID gid=CALLER_GID pid=pppp
 LOG: MAIN
@@ -54,18 +78,30 @@ LOG: MAIN
 Exim version x.yz ....
 changed uid/gid: forcing real = effective
   uid=uuuu gid=CALLER_GID pid=pppp
+seeking password data for user "root": cache not available
+getpwnam() succeeded uid=uuuu gid=gggg
 configuration file is TESTSUITE/test-config
 admin user
 changed uid/gid: privilege not needed
   uid=EXIM_UID gid=EXIM_GID pid=pppp
+seeking password data for user "CALLER": cache not available
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
+seeking password data for user "root": cache not available
+getpwnam() succeeded uid=uuuu gid=gggg
 LOG: MAIN
   <= CALLER@myhost.test.ex U=CALLER P=local S=sss
 Exim version x.yz ....
 changed uid/gid: forcing real = effective
   uid=uuuu gid=EXIM_GID pid=pppp
+seeking password data for user "root": cache not available
+getpwnam() succeeded uid=uuuu gid=gggg
 configuration file is TESTSUITE/test-config
 trusted user
 admin user
+seeking password data for user "CALLER": cache not available
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
+seeking password data for user "root": cache not available
+getpwnam() succeeded uid=uuuu gid=gggg
 LOG: MAIN PANIC
   User 0 set for t3 transport is on the never_users list
 LOG: MAIN
diff --git a/test/stderr/0303 b/test/stderr/0303
index f017d84ec..c690b62ec 100644
--- a/test/stderr/0303
+++ b/test/stderr/0303
@@ -43,6 +43,8 @@ MUNGED: ::1 will be omitted in what follows
 Exim version x.yz ....
 changed uid/gid: forcing real = effective
   uid=uuuu gid=CALLER_GID pid=pppp
+seeking password data for user "CALLER": cache not available
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
 configuration file is TESTSUITE/test-config
 trusted user
 admin user
@@ -110,6 +112,8 @@ search_tidyup called
 Exim version x.yz ....
 changed uid/gid: forcing real = effective
   uid=uuuu gid=CALLER_GID pid=pppp
+seeking password data for user "CALLER": cache not available
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
 configuration file is TESTSUITE/test-config
 trusted user
 admin user
diff --git a/test/stderr/0361 b/test/stderr/0361
index 3788438ff..07e0ce3d1 100644
--- a/test/stderr/0361
+++ b/test/stderr/0361
@@ -12,6 +12,8 @@ configuration file is TESTSUITE/test-config
 admin user
 changed uid/gid: privilege not needed
   uid=EXIM_UID gid=EXIM_GID pid=pppp
+seeking password data for user "CALLER": cache not available
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
 originator: uid=CALLER_UID gid=CALLER_GID login=CALLER name=CALLER_NAME
 sender address = CALLER@test.ex
 set_process_info: pppp accepting a local non-SMTP message from <CALLER@test.ex>
@@ -49,6 +51,8 @@ changed uid/gid: forcing real = effective
 configuration file is TESTSUITE/test-config
 trusted user
 admin user
+seeking password data for user "CALLER": cache not available
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
 set_process_info: pppp delivering specified messages
 set_process_info: pppp delivering 10HmaY-0005vi-00
 reading spool file 10HmaY-0005vi-00-H
diff --git a/test/stderr/0362 b/test/stderr/0362
index ff1b2acd4..60c6b653a 100644
--- a/test/stderr/0362
+++ b/test/stderr/0362
@@ -5,6 +5,8 @@ configuration file is TESTSUITE/test-config
 admin user
 changed uid/gid: privilege not needed
   uid=EXIM_UID gid=EXIM_GID pid=pppp
+seeking password data for user "CALLER": cache not available
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
 originator: uid=CALLER_UID gid=CALLER_GID login=CALLER name=CALLER_NAME
 sender address = CALLER@test.ex
 sender_fullhost = [V4NET.0.0.0]
diff --git a/test/stderr/0381 b/test/stderr/0381
index 61e236edf..bca2de5bf 100644
--- a/test/stderr/0381
+++ b/test/stderr/0381
@@ -1,6 +1,8 @@
 Exim version x.yz ....
 changed uid/gid: forcing real = effective
   uid=uuuu gid=CALLER_GID pid=pppp
+seeking password data for user "CALLER": cache not available
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
 configuration file is TESTSUITE/test-config
 trusted user
 admin user
diff --git a/test/stderr/0386 b/test/stderr/0386
index 89e64a9e0..2679f5b74 100644
--- a/test/stderr/0386
+++ b/test/stderr/0386
@@ -1,12 +1,15 @@
 Exim version x.yz ....
 changed uid/gid: forcing real = effective
   uid=uuuu gid=CALLER_GID pid=pppp
+seeking password data for user "CALLER": cache not available
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
 configuration file is TESTSUITE/test-config
 trusted user
 admin user
 changed uid/gid: privilege not needed
   uid=EXIM_UID gid=EXIM_GID pid=pppp
-finduser used cached passwd data for CALLER
+seeking password data for user "CALLER": using cached result
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
 originator: uid=CALLER_UID gid=CALLER_GID login=CALLER name=CALLER_NAME
 sender address = CALLER@test.ex
 sender_fullhost = [V4NET.9.8.7]
@@ -116,12 +119,15 @@ search_tidyup called
 Exim version x.yz ....
 changed uid/gid: forcing real = effective
   uid=uuuu gid=CALLER_GID pid=pppp
+seeking password data for user "CALLER": cache not available
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
 configuration file is TESTSUITE/test-config
 trusted user
 admin user
 changed uid/gid: privilege not needed
   uid=EXIM_UID gid=EXIM_GID pid=pppp
-finduser used cached passwd data for CALLER
+seeking password data for user "CALLER": using cached result
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
 originator: uid=CALLER_UID gid=CALLER_GID login=CALLER name=CALLER_NAME
 sender address = NULL
 sender_fullhost = [V4NET.11.12.13]
@@ -193,10 +199,13 @@ exec TESTSUITE/eximdir/exim -DEXIM_PATH=TESTSUITE/eximdir/exim -C TESTSUITE/test
 Exim version x.yz ....
 changed uid/gid: forcing real = effective
   uid=uuuu gid=EXIM_GID pid=pppp
+seeking password data for user "CALLER": cache not available
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
 configuration file is TESTSUITE/test-config
 trusted user
 admin user
-finduser used cached passwd data for CALLER
+seeking password data for user "CALLER": using cached result
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
 set_process_info: pppp delivering specified messages
 set_process_info: pppp delivering 10HmaX-0005vi-00
 reading spool file 10HmaX-0005vi-00-H
@@ -348,10 +357,13 @@ exec TESTSUITE/eximdir/exim -DEXIM_PATH=TESTSUITE/eximdir/exim -C TESTSUITE/test
 Exim version x.yz ....
 changed uid/gid: forcing real = effective
   uid=uuuu gid=EXIM_GID pid=pppp
+seeking password data for user "CALLER": cache not available
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
 configuration file is TESTSUITE/test-config
 trusted user
 admin user
-finduser used cached passwd data for CALLER
+seeking password data for user "CALLER": using cached result
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
 set_process_info: pppp delivering specified messages
 set_process_info: pppp delivering 10HmaY-0005vi-00
 reading spool file 10HmaY-0005vi-00-H
diff --git a/test/stderr/0398 b/test/stderr/0398
index 6ed0f82e7..5a151153f 100644
--- a/test/stderr/0398
+++ b/test/stderr/0398
@@ -5,6 +5,8 @@ configuration file is TESTSUITE/test-config
 admin user
 changed uid/gid: privilege not needed
   uid=EXIM_UID gid=EXIM_GID pid=pppp
+seeking password data for user "CALLER": cache not available
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
 originator: uid=CALLER_UID gid=CALLER_GID login=CALLER name=CALLER_NAME
 sender address = CALLER@test.ex
 set_process_info: pppp accepting a local SMTP message from <CALLER@test.ex>
diff --git a/test/stderr/0402 b/test/stderr/0402
index 52886dcc8..393aa4ea0 100644
--- a/test/stderr/0402
+++ b/test/stderr/0402
@@ -5,8 +5,12 @@ configuration file is TESTSUITE/test-config
 admin user
 changed uid/gid: privilege not needed
   uid=EXIM_UID gid=EXIM_GID pid=pppp
-finduser used cached passwd data for CALLER
-finduser used cached passwd data for CALLER
+seeking password data for user "CALLER": cache not available
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
+seeking password data for user "CALLER": using cached result
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
+seeking password data for user "CALLER": using cached result
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
 originator: uid=CALLER_UID gid=CALLER_GID login=CALLER name=CALLER_NAME
 sender address = CALLER@test.ex
 set_process_info: pppp accepting a local non-SMTP message from <CALLER@test.ex>
@@ -92,8 +96,12 @@ changed uid/gid: forcing real = effective
 configuration file is TESTSUITE/test-config
 trusted user
 admin user
-finduser used cached passwd data for CALLER
-finduser used cached passwd data for CALLER
+seeking password data for user "CALLER": cache not available
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
+seeking password data for user "CALLER": using cached result
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
+seeking password data for user "CALLER": using cached result
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
 set_process_info: pppp delivering specified messages
 set_process_info: pppp delivering 10HmaX-0005vi-00
 reading spool file 10HmaX-0005vi-00-H
diff --git a/test/stderr/0403 b/test/stderr/0403
index 46522ed7b..7d132041a 100644
--- a/test/stderr/0403
+++ b/test/stderr/0403
@@ -5,6 +5,8 @@ configuration file is TESTSUITE/test-config
 admin user
 changed uid/gid: privilege not needed
   uid=EXIM_UID gid=EXIM_GID pid=pppp
+seeking password data for user "CALLER": cache not available
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
 originator: uid=CALLER_UID gid=CALLER_GID login=CALLER name=CALLER_NAME
 sender address = CALLER@test.ex
 set_process_info: pppp accepting a local non-SMTP message from <CALLER@test.ex>
@@ -43,6 +45,8 @@ changed uid/gid: forcing real = effective
 configuration file is TESTSUITE/test-config
 trusted user
 admin user
+seeking password data for user "CALLER": cache not available
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
 set_process_info: pppp delivering specified messages
 set_process_info: pppp delivering 10HmaX-0005vi-00
 reading spool file 10HmaX-0005vi-00-H
diff --git a/test/stderr/0404 b/test/stderr/0404
index eacb762b5..6a53a9d06 100644
--- a/test/stderr/0404
+++ b/test/stderr/0404
@@ -5,7 +5,10 @@ configuration file is TESTSUITE/test-config
 admin user
 changed uid/gid: privilege not needed
   uid=EXIM_UID gid=EXIM_GID pid=pppp
-finduser used cached passwd data for CALLER
+seeking password data for user "CALLER": cache not available
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
+seeking password data for user "CALLER": using cached result
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
 originator: uid=CALLER_UID gid=CALLER_GID login=CALLER name=CALLER_NAME
 sender address = CALLER@test.ex
 set_process_info: pppp accepting a local non-SMTP message from <CALLER@test.ex>
@@ -141,7 +144,10 @@ changed uid/gid: forcing real = effective
 configuration file is TESTSUITE/test-config
 trusted user
 admin user
-finduser used cached passwd data for CALLER
+seeking password data for user "CALLER": cache not available
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
+seeking password data for user "CALLER": using cached result
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
 set_process_info: pppp delivering specified messages
 set_process_info: pppp delivering 10HmaX-0005vi-00
 reading spool file 10HmaX-0005vi-00-H
@@ -236,7 +242,10 @@ configuration file is TESTSUITE/test-config
 admin user
 changed uid/gid: privilege not needed
   uid=EXIM_UID gid=EXIM_GID pid=pppp
-finduser used cached passwd data for CALLER
+seeking password data for user "CALLER": cache not available
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
+seeking password data for user "CALLER": using cached result
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
 originator: uid=CALLER_UID gid=CALLER_GID login=CALLER name=CALLER_NAME
 sender address = 
 set_process_info: pppp accepting a local non-SMTP message from <>
@@ -283,7 +292,10 @@ changed uid/gid: forcing real = effective
 configuration file is TESTSUITE/test-config
 trusted user
 admin user
-finduser used cached passwd data for CALLER
+seeking password data for user "CALLER": cache not available
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
+seeking password data for user "CALLER": using cached result
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
 set_process_info: pppp delivering specified messages
 set_process_info: pppp delivering 10HmaY-0005vi-00
 reading spool file 10HmaY-0005vi-00-H
diff --git a/test/stderr/0408 b/test/stderr/0408
index 18d673e78..8ba1fe4eb 100644
--- a/test/stderr/0408
+++ b/test/stderr/0408
@@ -5,6 +5,8 @@ configuration file is TESTSUITE/test-config
 admin user
 changed uid/gid: privilege not needed
   uid=EXIM_UID gid=EXIM_GID pid=pppp
+seeking password data for user "CALLER": cache not available
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
 originator: uid=CALLER_UID gid=CALLER_GID login=CALLER name=CALLER_NAME
 sender address = CALLER@test.ex
 set_process_info: pppp accepting a local non-SMTP message from <CALLER@test.ex>
@@ -43,6 +45,8 @@ changed uid/gid: forcing real = effective
 configuration file is TESTSUITE/test-config
 trusted user
 admin user
+seeking password data for user "CALLER": cache not available
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
 set_process_info: pppp delivering specified messages
 set_process_info: pppp delivering 10HmaX-0005vi-00
 reading spool file 10HmaX-0005vi-00-H
diff --git a/test/stderr/0414 b/test/stderr/0414
index eec8f385e..fd1090e94 100644
--- a/test/stderr/0414
+++ b/test/stderr/0414
@@ -3,6 +3,8 @@ changed uid/gid: forcing real = effective
   uid=uuuu gid=CALLER_GID pid=pppp
 configuration file is TESTSUITE/test-config
 admin user
+seeking password data for user "CALLER": cache not available
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
 originator: uid=CALLER_UID gid=CALLER_GID login=CALLER name=CALLER_NAME
 sender address = CALLER@test.ex
 Address testing: uid=uuuu gid=EXIM_GID euid=uuuu egid=EXIM_GID
diff --git a/test/stderr/0465 b/test/stderr/0465
index cfa58eb8e..f429e3c47 100644
--- a/test/stderr/0465
+++ b/test/stderr/0465
@@ -1,6 +1,8 @@
 Exim version x.yz ....
 changed uid/gid: forcing real = effective
   uid=uuuu gid=CALLER_GID pid=pppp
+seeking password data for user "CALLER": cache not available
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
 configuration file is TESTSUITE/test-config
 trusted user
 admin user
@@ -29,6 +31,8 @@ exim: bad -f address "abc@somewhere.": domain is malformed (trailing dot not all
 Exim version x.yz ....
 changed uid/gid: forcing real = effective
   uid=uuuu gid=CALLER_GID pid=pppp
+seeking password data for user "CALLER": cache not available
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
 configuration file is TESTSUITE/test-config
 trusted user
 admin user
@@ -88,6 +92,8 @@ search_tidyup called
 Exim version x.yz ....
 changed uid/gid: forcing real = effective
   uid=uuuu gid=CALLER_GID pid=pppp
+seeking password data for user "CALLER": cache not available
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
 configuration file is TESTSUITE/test-config
 trusted user
 admin user
diff --git a/test/stderr/0487 b/test/stderr/0487
index 07628551a..fdade23da 100644
--- a/test/stderr/0487
+++ b/test/stderr/0487
@@ -1,12 +1,15 @@
 Exim version x.yz ....
 changed uid/gid: forcing real = effective
   uid=uuuu gid=CALLER_GID pid=pppp
+seeking password data for user "CALLER": cache not available
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
 configuration file is TESTSUITE/test-config
 trusted user
 admin user
 changed uid/gid: privilege not needed
   uid=EXIM_UID gid=EXIM_GID pid=pppp
-finduser used cached passwd data for CALLER
+seeking password data for user "CALLER": using cached result
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
 originator: uid=CALLER_UID gid=CALLER_GID login=CALLER name=CALLER_NAME
 sender address = NULL
  in hosts_connection_nolog? no (option unset)
@@ -60,10 +63,13 @@ exec TESTSUITE/eximdir/exim -DEXIM_PATH=TESTSUITE/eximdir/exim -C TESTSUITE/test
 Exim version x.yz ....
 changed uid/gid: forcing real = effective
   uid=uuuu gid=EXIM_GID pid=pppp
+seeking password data for user "CALLER": cache not available
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
 configuration file is TESTSUITE/test-config
 trusted user
 admin user
-finduser used cached passwd data for CALLER
+seeking password data for user "CALLER": using cached result
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
 set_process_info: pppp delivering specified messages
 set_process_info: pppp delivering 10HmaX-0005vi-00
 reading spool file 10HmaX-0005vi-00-H
diff --git a/test/stderr/2201 b/test/stderr/2201
index e959fea8f..ca89d960c 100644
--- a/test/stderr/2201
+++ b/test/stderr/2201
@@ -1,10 +1,13 @@
 Exim version x.yz ....
 changed uid/gid: forcing real = effective
   uid=uuuu gid=CALLER_GID pid=pppp
+seeking password data for user "CALLER": cache not available
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
 configuration file is TESTSUITE/test-config
 trusted user
 admin user
-finduser used cached passwd data for CALLER
+seeking password data for user "CALLER": using cached result
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
 originator: uid=CALLER_UID gid=CALLER_GID login=CALLER name=CALLER_NAME
 sender address = CALLER@myhost.test.ex
 Address testing: uid=uuuu gid=EXIM_GID euid=uuuu egid=EXIM_GID
diff --git a/test/stderr/2600 b/test/stderr/2600
index 9ba7bc19d..1c0fb042a 100644
--- a/test/stderr/2600
+++ b/test/stderr/2600
@@ -111,6 +111,8 @@ configuration file is TESTSUITE/test-config
 admin user
 changed uid/gid: privilege not needed
   uid=EXIM_UID gid=EXIM_GID pid=pppp
+seeking password data for user "CALLER": cache not available
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
 originator: uid=CALLER_UID gid=CALLER_GID login=CALLER name=CALLER_NAME
 sender address = CALLER@myhost.test.ex
 sender_fullhost = [10.0.0.0]
@@ -198,6 +200,8 @@ configuration file is TESTSUITE/test-config
 admin user
 changed uid/gid: privilege not needed
   uid=EXIM_UID gid=EXIM_GID pid=pppp
+seeking password data for user "CALLER": cache not available
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
 originator: uid=CALLER_UID gid=CALLER_GID login=CALLER name=CALLER_NAME
 sender address = CALLER@myhost.test.ex
 sender_fullhost = [10.10.10.10]
@@ -275,6 +279,8 @@ configuration file is TESTSUITE/test-config
 admin user
 changed uid/gid: privilege not needed
   uid=EXIM_UID gid=EXIM_GID pid=pppp
+seeking password data for user "CALLER": cache not available
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
 originator: uid=CALLER_UID gid=CALLER_GID login=CALLER name=CALLER_NAME
 sender address = CALLER@myhost.test.ex
 set_process_info: pppp accepting a local non-SMTP message from <CALLER@myhost.test.ex>
@@ -314,6 +320,8 @@ configuration file is TESTSUITE/test-config
 trusted user
 admin user
 skipping ACL configuration - not needed
+seeking password data for user "CALLER": cache not available
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
 set_process_info: pppp delivering specified messages
 set_process_info: pppp delivering 10HmaX-0005vi-00
 reading spool file 10HmaX-0005vi-00-H
diff --git a/test/stderr/3210 b/test/stderr/3210
index c4e40bb14..7d6faab4b 100644
--- a/test/stderr/3210
+++ b/test/stderr/3210
@@ -3,6 +3,8 @@ changed uid/gid: forcing real = effective
   uid=uuuu gid=CALLER_GID pid=pppp
 configuration file is TESTSUITE/test-config
 admin user
+seeking password data for user "CALLER": cache not available
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
 originator: uid=CALLER_UID gid=CALLER_GID login=CALLER name=CALLER_NAME
 sender address = CALLER@test.ex
 Address testing: uid=uuuu gid=EXIM_GID euid=uuuu egid=EXIM_GID
diff --git a/test/stderr/3400 b/test/stderr/3400
index 96b099052..a2cc076ef 100644
--- a/test/stderr/3400
+++ b/test/stderr/3400
@@ -354,12 +354,15 @@ LOG: H=(test.host) [10.0.0.3] F=<junk@jink.jonk.test.ex> rejected RCPT <userx@cu
 Exim version x.yz ....
 changed uid/gid: forcing real = effective
   uid=uuuu gid=CALLER_GID pid=pppp
+seeking password data for user "CALLER": cache not available
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
 configuration file is TESTSUITE/test-config
 trusted user
 admin user
 changed uid/gid: privilege not needed
   uid=EXIM_UID gid=EXIM_GID pid=pppp
-finduser used cached passwd data for CALLER
+seeking password data for user "CALLER": using cached result
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
 originator: uid=CALLER_UID gid=CALLER_GID login=CALLER name=CALLER_NAME
 sender address = NULL
 sender_fullhost = [10.0.0.5]
diff --git a/test/stderr/5004 b/test/stderr/5004
index 05f68fa33..1143fdb3b 100644
--- a/test/stderr/5004
+++ b/test/stderr/5004
@@ -5,7 +5,10 @@ configuration file is TESTSUITE/test-config
 admin user
 changed uid/gid: privilege not needed
   uid=EXIM_UID gid=EXIM_GID pid=pppp
-finduser used cached passwd data for CALLER
+seeking password data for user "CALLER": cache not available
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
+seeking password data for user "CALLER": using cached result
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
 originator: uid=CALLER_UID gid=CALLER_GID login=CALLER name=CALLER_NAME
 sender address = CALLER@test.ex
 set_process_info: pppp accepting a local non-SMTP message from <CALLER@test.ex>
@@ -44,7 +47,10 @@ changed uid/gid: forcing real = effective
 configuration file is TESTSUITE/test-config
 trusted user
 admin user
-finduser used cached passwd data for CALLER
+seeking password data for user "CALLER": cache not available
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
+seeking password data for user "CALLER": using cached result
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
 set_process_info: pppp delivering specified messages
 set_process_info: pppp delivering 10HmaX-0005vi-00
 reading spool file 10HmaX-0005vi-00-H
diff --git a/test/stderr/5005 b/test/stderr/5005
index 87fc73f8d..4e2a84b59 100644
--- a/test/stderr/5005
+++ b/test/stderr/5005
@@ -5,6 +5,8 @@ configuration file is TESTSUITE/test-config
 admin user
 changed uid/gid: privilege not needed
   uid=EXIM_UID gid=EXIM_GID pid=pppp
+seeking password data for user "CALLER": cache not available
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
 originator: uid=CALLER_UID gid=CALLER_GID login=CALLER name=CALLER_NAME
 sender address = CALLER@test.ex
 set_process_info: pppp accepting a local non-SMTP message from <CALLER@test.ex>
@@ -43,6 +45,8 @@ changed uid/gid: forcing real = effective
 configuration file is TESTSUITE/test-config
 trusted user
 admin user
+seeking password data for user "CALLER": cache not available
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
 set_process_info: pppp delivering specified messages
 set_process_info: pppp delivering 10HmaX-0005vi-00
 reading spool file 10HmaX-0005vi-00-H
@@ -169,6 +173,8 @@ configuration file is TESTSUITE/test-config
 admin user
 changed uid/gid: privilege not needed
   uid=EXIM_UID gid=EXIM_GID pid=pppp
+seeking password data for user "CALLER": cache not available
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
 originator: uid=CALLER_UID gid=CALLER_GID login=CALLER name=CALLER_NAME
 sender address = CALLER@test.ex
 set_process_info: pppp accepting a local non-SMTP message from <CALLER@test.ex>
@@ -206,6 +212,8 @@ changed uid/gid: forcing real = effective
 configuration file is TESTSUITE/test-config
 trusted user
 admin user
+seeking password data for user "CALLER": cache not available
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
 set_process_info: pppp delivering specified messages
 set_process_info: pppp delivering 10HmaY-0005vi-00
 reading spool file 10HmaY-0005vi-00-H
@@ -333,6 +341,8 @@ configuration file is TESTSUITE/test-config
 admin user
 changed uid/gid: privilege not needed
   uid=EXIM_UID gid=EXIM_GID pid=pppp
+seeking password data for user "CALLER": cache not available
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
 originator: uid=CALLER_UID gid=CALLER_GID login=CALLER name=CALLER_NAME
 sender address = CALLER@test.ex
 set_process_info: pppp accepting a local non-SMTP message from <CALLER@test.ex>
@@ -370,6 +380,8 @@ changed uid/gid: forcing real = effective
 configuration file is TESTSUITE/test-config
 trusted user
 admin user
+seeking password data for user "CALLER": cache not available
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
 set_process_info: pppp delivering specified messages
 set_process_info: pppp delivering 10HmaZ-0005vi-00
 reading spool file 10HmaZ-0005vi-00-H
@@ -508,6 +520,8 @@ configuration file is TESTSUITE/test-config
 admin user
 changed uid/gid: privilege not needed
   uid=EXIM_UID gid=EXIM_GID pid=pppp
+seeking password data for user "CALLER": cache not available
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
 originator: uid=CALLER_UID gid=CALLER_GID login=CALLER name=CALLER_NAME
 sender address = CALLER@test.ex
 set_process_info: pppp accepting a local non-SMTP message from <CALLER@test.ex>
@@ -545,6 +559,8 @@ changed uid/gid: forcing real = effective
 configuration file is TESTSUITE/test-config
 trusted user
 admin user
+seeking password data for user "CALLER": cache not available
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
 set_process_info: pppp delivering specified messages
 set_process_info: pppp delivering 10HmbA-0005vi-00
 reading spool file 10HmbA-0005vi-00-H
diff --git a/test/stderr/5006 b/test/stderr/5006
index 20a0c04d3..695bbd866 100644
--- a/test/stderr/5006
+++ b/test/stderr/5006
@@ -5,6 +5,8 @@ configuration file is TESTSUITE/test-config
 admin user
 changed uid/gid: privilege not needed
   uid=EXIM_UID gid=EXIM_GID pid=pppp
+seeking password data for user "CALLER": cache not available
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
 originator: uid=CALLER_UID gid=CALLER_GID login=CALLER name=CALLER_NAME
 sender address = CALLER@test.ex
 set_process_info: pppp accepting a local non-SMTP message from <CALLER@test.ex>
@@ -43,6 +45,8 @@ changed uid/gid: forcing real = effective
 configuration file is TESTSUITE/test-config
 trusted user
 admin user
+seeking password data for user "CALLER": cache not available
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
 set_process_info: pppp delivering specified messages
 set_process_info: pppp delivering 10HmaX-0005vi-00
 reading spool file 10HmaX-0005vi-00-H