Re: [exim] Trim down pgsql callouts

Αρχική Σελίδα
Delete this message
Reply to this message
Συντάκτης: Sam Smith
Ημερομηνία:  
Προς: exim-users
Αντικείμενο: Re: [exim] Trim down pgsql callouts
Thank you for your reply.

I have attached to this message the config file you requested (minus
comments), and the results of running exim in debugging mode and
connecting via SMTP to route one message.

Thanks for your help so far. It took me a while to figure out those
commands, but they are indeed useful!

--Sam

On Wed, Jul 09, 2008 at 09:45:40PM -0700, Phil Pennock wrote:
> On 2008-07-09 at 22:03 +0100, Sam Smith wrote:
> > So I ran the command exim joseph@??? 2>&1| tee /path/to/logfile
>
> If you're invoking Exim like this and the initial delivery is deferred,
> then the invoking Exim has to talk to the DB and later the queue-runner
> needs to talk to the DB separately.
>
> Also, lookup caches are flushed after routing, for instance, so if
> there's data that you want to use again at delivery (Transport) time, it
> makes sense to use "address_data" on the Router to preserve it and
> $address_data in the Transport to retrieve it; this data is stored in
> the spool file.
>
> If you're normally injecting via SMTP, then can you please run with the
> -bd daemonising flag, send the mail via SMTP and post the full debug
> output, since (as you say) there's nothing confidential in it?
>
> It's probably worth doing "exim -bd -d+all 2>&1 | tee debug.log" to get
> all debugging possible, so that we can pick over it in detail. Please
> don't cut out parts of the log -- send the whole thing, since we need to
> be able to figure out what's changing to cause Exim to do the lookups.
>
> If you're trying to avoid interfering with an existing production Exim,
> then use "-bd -oX 26 -d+all" to listen on port 26.
> an existing production Exim, then use "-bd -oX 26 -d+all" to listen on
> port 26.
>
> How much of your configuration are you happy posting? If all of it,
> then good. :^) You can (probably) strip comments for this audience:
>
> grep '^[^#]' `exim -bV | sed -n 's/Configuration file is //p'` >conf
>
> -Phil
>
> --
> ## List details at http://lists.exim.org/mailman/listinfo/exim-users
> ## Exim details at http://www.exim.org/
> ## Please use the Wiki with this list - http://wiki.exim.org/

hide pgsql_servers = 127.0.0.1/testdb/root/;lkjlk
exim_path = /usr/sbin/exim4
domainlist local_domains = samibm.com : localhost
PGS_VAR = {lookup pgsql \
   {select mailbox,username,uid from mailtest \
    where username='${quote_pgsql:$local_part}'}}
acl_smtp_rcpt=accept
begin routers
notlocal:
  driver = dnslookup
  domains = ! +local_domains 
  transport = remote_smtp
 db_user:
   debug_print = "R: local_user for $local_part@$domain"
   driver = accept
   domains = +local_domains
   local_parts = ${extract {username}{$PGS_VAR}}
   transport = db_mail_spool
   cannot_route_message = Unknown user : not a v_user
begin transports
db_mail_spool:
  debug_print = "T: db appendfile for $local_part@$domain"
  driver = appendfile
  file = ${extract {mailbox}{$PGS_VAR}}
  delivery_date_add
  envelope_to_add
  return_path_add
  group = mail
  user = ${extract{uid}{$PGS_VAR}}
  mode = 0660
  mode_fail_narrower = false
remote_smtp:
  debug_print = "T: remote_smtp for $local_part@$domain"
  driver = smtp
begin retry
begin rewrite

hide pgsql_servers = 127.0.0.1/testdb/root/;lkjlk
exim_path = /usr/sbin/exim4
domainlist local_domains = samibm.com : localhost
PGS_VAR = {lookup pgsql \
   {select mailbox,username,uid from mailtest \
    where username='${quote_pgsql:$local_part}'}}
acl_smtp_rcpt=accept
begin routers
notlocal:
  driver = dnslookup
  domains = ! +local_domains 
  transport = remote_smtp
 db_user:
   debug_print = "R: local_user for $local_part@$domain"
   driver = accept
   domains = +local_domains
   local_parts = ${extract {username}{$PGS_VAR}}
   transport = db_mail_spool
   cannot_route_message = Unknown user : not a v_user
begin transports
db_mail_spool:
  debug_print = "T: db appendfile for $local_part@$domain"
  driver = appendfile
  file = ${extract {mailbox}{$PGS_VAR}}
  delivery_date_add
  envelope_to_add
  return_path_add
  group = mail
  user = ${extract{uid}{$PGS_VAR}}
  mode = 0660
  mode_fail_narrower = false
remote_smtp:
  debug_print = "T: remote_smtp for $local_part@$domain"
  driver = smtp
begin retry
begin rewrite

13:05:34 4656 Exim version 4.63 uid=0 gid=0 pid=4656 D=fffdffff
Berkeley DB: Sleepycat Software: Berkeley DB 4.3.29: (September  6, 2005)
Support for: crypteq iconv() IPv6 PAM Perl GnuTLS move_frozen_messages Content_Scanning Old_Demime
Lookups: lsearch wildlsearch nwildlsearch iplsearch cdb dbm dbmnz dnsdb dsearch ldap ldapdn ldapm mysql nis nis0 passwd pgsql sqlite
Authenticators: cram_md5 cyrus_sasl plaintext spa
Routers: accept dnslookup ipliteral iplookup manualroute queryprogram redirect
Transports: appendfile/maildir/mailstore/mbx autoreply lmtp pipe smtp
Fixed never_users: 0
Size of off_t: 8
13:05:34  4656 changed uid/gid: forcing real = effective
13:05:34  4656   uid=0 gid=0 pid=4656
13:05:34  4656   auxiliary group list: <none>
13:05:34  4656 configuration file is /var/lib/exim4/config.autogenerated
13:05:34  4656 log selectors = 00000ffc 00089001
13:05:34  4656 cwd=/home/sam 3 args: exim -bd -d+all
13:05:34  4656 trusted user
13:05:34  4656 admin user
13:05:34  4656 originator: uid=0 gid=0 login=root name=root
13:05:34  4656 listening on all interfaces (IPv6) port 25
13:05:34  4656 listening on all interfaces (IPv4) port 25
13:05:34  4656 pid written to /var/run/exim4/exim.pid
13:05:34  4656 changed uid/gid: running as a daemon
13:05:34  4656   uid=104 gid=107 pid=4656
13:05:34  4656   auxiliary group list: 107
13:05:34  4656 LOG: MAIN
13:05:34  4656   exim 4.63 daemon started: pid=4656, no queue runs, listening for SMTP on port 25 (IPv6 and IPv4)
13:05:34  4656 set_process_info:  4656 daemon: no queue runs, listening for SMTP on port 25 (IPv6 and IPv4)
13:05:34  4656 daemon running with uid=104 gid=107 euid=104 egid=107
13:05:34  4656 Listening...
13:07:24  4656 Connection request from 192.168.181.151 port 42587
13:07:24  4656 interface address=192.168.181.151 port=25
13:07:24  4656 search_tidyup called
13:07:24  4698 host in rfc1413_hosts? yes (matched "*")
13:07:24  4698 doing ident callback
13:07:24  4698 ident connection to 192.168.181.151 failed: Connection refused
13:07:24  4698 sender_fullhost = [192.168.181.151]
13:07:24  4698 sender_rcvhost = [192.168.181.151]
13:07:24  4698 Process 4698 is handling incoming connection from [192.168.181.151]
13:07:24  4698 host in host_lookup? no (option unset)
13:07:24  4698 set_process_info:  4698 handling incoming connection from [192.168.181.151]
13:07:24  4698 host in host_reject_connection? no (option unset)
13:07:24  4698 host in sender_unqualified_hosts? no (option unset)
13:07:24  4698 host in recipient_unqualified_hosts? no (option unset)
13:07:24  4698 host in helo_verify_hosts? no (option unset)
13:07:24  4698 host in helo_try_verify_hosts? no (option unset)
13:07:24  4698 host in helo_accept_junk_hosts? no (option unset)
13:07:24  4698 expanding: $smtp_active_hostname ESMTP Exim $version_number $tod_full
13:07:24  4698    result: localhost ESMTP Exim 4.63 Wed, 16 Jul 2008 13:07:24 +0100
13:07:24  4698 SMTP>> 220 localhost ESMTP Exim 4.63 Wed, 16 Jul 2008 13:07:24 +0100
13:07:24  4698 Process 4698 is ready for new message
13:07:24  4698 smtp_setup_msg entered
13:07:24  4656 1 SMTP accept process running
13:07:24  4656 Listening...
13:07:32  4698 SMTP<< helo samtest.com
13:07:32  4698 samtest.com in helo_lookup_domains? no (end of list)
13:07:32  4698 sender_fullhost = (samtest.com) [192.168.181.151]
13:07:32  4698 sender_rcvhost = [192.168.181.151] (helo=samtest.com)
13:07:32  4698 set_process_info:  4698 handling incoming connection from (samtest.com) [192.168.181.151]
13:07:32  4698 SMTP>> 250 localhost Hello samtest.com [192.168.181.151]
13:07:43  4698 SMTP<< mail from: sam@???
13:07:43  4698 SMTP>> 250 OK
13:07:50  4698 SMTP<< rcpt to: joseph@???
13:07:50  4698 processing "accept"
13:07:50  4698 accept: condition test succeeded
13:07:50  4698 SMTP>> 250 Accepted
13:07:52  4698 SMTP<< data
13:07:52  4698 SMTP>> 354 Enter message, ending with "." on a line by itself
13:07:52  4698 search_tidyup called
13:07:54  4698 host in ignore_fromline_hosts? no (option unset)
13:07:54  4698 >>Headers received:
13:07:54  4698 
13:07:54  4698 search_tidyup called
13:07:54  4698 >>Headers after rewriting and local additions:
13:07:54  4698 
13:07:54  4698 Data file written for message 1KJ5nU-0001Dm-Hl
13:07:54  4698 expanding: ${tod_full}
13:07:54  4698    result: Wed, 16 Jul 2008 13:07:54 +0100
13:07:54  4698 condition: def:sender_rcvhost
13:07:54  4698    result: true
13:07:54  4698 expanding: from $sender_rcvhost
13:07:54  4698     
13:07:54  4698    result: from [192.168.181.151] (helo=samtest.com)
13:07:54  4698     
13:07:54  4698 condition: def:sender_ident
13:07:54  4698    result: false
13:07:54  4698 expanding: $sender_ident
13:07:54  4698    result: 
13:07:54  4698 skipping: result is not used
13:07:54  4698 expanding: from ${quote_local_part:$sender_ident} 
13:07:54  4698    result: from  
13:07:54  4698 skipping: result is not used
13:07:54  4698 condition: def:sender_helo_name
13:07:54  4698    result: false
13:07:54  4698 expanding: (helo=$sender_helo_name)
13:07:54  4698     
13:07:54  4698    result: (helo=)
13:07:54  4698     
13:07:54  4698 skipping: result is not used
13:07:54  4698 expanding: ${if def:sender_ident {from ${quote_local_part:$sender_ident} }}${if def:sender_helo_name {(helo=$sender_helo_name)
13:07:54  4698     }}
13:07:54  4698    result: 
13:07:54  4698 skipping: result is not used
13:07:54  4698 condition: def:received_protocol
13:07:54  4698    result: true
13:07:54  4698 expanding: with $received_protocol
13:07:54  4698    result: with smtp
13:07:54  4698 condition: def:tls_cipher
13:07:54  4698    result: false
13:07:54  4698 expanding: ($tls_cipher)
13:07:54  4698     
13:07:54  4698    result: ()
13:07:54  4698     
13:07:54  4698 skipping: result is not used
13:07:54  4698 condition: def:sender_address
13:07:54  4698    result: true
13:07:54  4698 expanding: (envelope-from <$sender_address>)
13:07:54  4698     
13:07:54  4698    result: (envelope-from <sam@???>)
13:07:54  4698     
13:07:54  4698 condition: def:received_for
13:07:54  4698    result: true
13:07:54  4698 expanding: 
13:07:54  4698     for $received_for
13:07:54  4698    result: 
13:07:54  4698     for joseph@???
13:07:54  4698 expanding: Received: ${if def:sender_rcvhost {from $sender_rcvhost
13:07:54  4698     }{${if def:sender_ident {from ${quote_local_part:$sender_ident} }}${if def:sender_helo_name {(helo=$sender_helo_name)
13:07:54  4698     }}}}by $primary_hostname ${if def:received_protocol {with $received_protocol}} ${if def:tls_cipher {($tls_cipher)
13:07:54  4698     }}(Exim $version_number)
13:07:54  4698     ${if def:sender_address {(envelope-from <$sender_address>)
13:07:54  4698     }}id $message_exim_id${if def:received_for {
13:07:54  4698     for $received_for}}
13:07:54  4698    result: Received: from [192.168.181.151] (helo=samtest.com)
13:07:54  4698     by localhost with smtp (Exim 4.63)
13:07:54  4698     (envelope-from <sam@???>)
13:07:54  4698     id 1KJ5nU-0001Dm-Hl
13:07:54  4698     for joseph@???
13:07:54  4698 >>Generated Received: header line
13:07:54  4698 P Received: from [192.168.181.151] (helo=samtest.com)
13:07:54  4698     by localhost with smtp (Exim 4.63)
13:07:54  4698     (envelope-from <sam@???>)
13:07:54  4698     id 1KJ5nU-0001Dm-Hl
13:07:54  4698     for joseph@???; Wed, 16 Jul 2008 13:07:54 +0100
13:07:54  4698 calling local_scan(); timeout=300
13:07:54  4698 local_scan() returned 0 NULL
13:07:54  4698 expanding: ${tod_full}
13:07:54  4698    result: Wed, 16 Jul 2008 13:07:54 +0100
13:07:54  4698 Writing spool header file
13:07:54  4698 Size of headers = 200
13:07:54  4698 LOG: MAIN
13:07:54  4698   <= sam@??? H=(samtest.com) [192.168.181.151] P=smtp S=206
13:07:54  4698 SMTP>> 250 OK id=1KJ5nU-0001Dm-Hl
13:07:54  4698 search_tidyup called
13:07:54  4698 Sender: sam@???
13:07:54  4698 Recipients:
13:07:54  4698   joseph@???
13:07:54  4698 forked delivery process 4707
13:07:54  4698 Process 4698 is ready for new message
13:07:54  4698 smtp_setup_msg entered
13:07:54  4707 exec /usr/sbin/exim4 -d=0xfffdffff -Mc 1KJ5nU-0001Dm-Hl
13:07:54  4707 Exim version 4.63 uid=104 gid=107 pid=4707 D=fffdffff
Berkeley DB: Sleepycat Software: Berkeley DB 4.3.29: (September  6, 2005)
Support for: crypteq iconv() IPv6 PAM Perl GnuTLS move_frozen_messages Content_Scanning Old_Demime
Lookups: lsearch wildlsearch nwildlsearch iplsearch cdb dbm dbmnz dnsdb dsearch ldap ldapdn ldapm mysql nis nis0 passwd pgsql sqlite
Authenticators: cram_md5 cyrus_sasl plaintext spa
Routers: accept dnslookup ipliteral iplookup manualroute queryprogram redirect
Transports: appendfile/maildir/mailstore/mbx autoreply lmtp pipe smtp
Fixed never_users: 0
Size of off_t: 8
13:07:54  4707 changed uid/gid: forcing real = effective
13:07:54  4707   uid=0 gid=107 pid=4707
13:07:54  4707   auxiliary group list: <none>
13:07:54  4707 configuration file is /var/lib/exim4/config.autogenerated
13:07:54  4707 log selectors = 00000ffc 00089001
13:07:54  4707 cwd=/var/spool/exim4 4 args: /usr/sbin/exim4 -d=0xfffdffff -Mc 1KJ5nU-0001Dm-Hl
13:07:54  4707 trusted user
13:07:54  4707 admin user
13:07:54  4707 set_process_info:  4707 delivering specified messages
13:07:54  4707 set_process_info:  4707 delivering 1KJ5nU-0001Dm-Hl
13:07:54  4707 reading spool file 1KJ5nU-0001Dm-Hl-H
13:07:54  4707 user=root uid=0 gid=0 sender=sam@???
13:07:54  4707 sender_fullhost = (samtest.com) [192.168.181.151]
13:07:54  4707 sender_rcvhost = [192.168.181.151] (helo=samtest.com)
13:07:54  4707 sender_local=0 ident=unset
13:07:54  4707 Non-recipients:
13:07:54  4707 Empty Tree
13:07:54  4707 ---- End of tree ----
13:07:54  4707 recipients_count=1
13:07:54  4707 body_linecount=1 message_linecount=5
13:07:54  4707 Delivery address list:
13:07:54  4707   joseph@??? 
13:07:54  4707 locking /var/spool/exim4/db/retry.lockfile
13:07:54  4707 locked /var/spool/exim4/db/retry.lockfile
13:07:54  4707 EXIM_DBOPEN(/var/spool/exim4/db/retry)
13:07:54  4707 returned from EXIM_DBOPEN
13:07:54  4707 opened hints database /var/spool/exim4/db/retry: flags=O_RDONLY
13:07:54  4707 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
13:07:54  4707 Considering: joseph@???
13:07:54  4707 unique = joseph@???
13:07:54  4707 dbfn_read: key=R:samibm.com
13:07:54  4707 dbfn_read: key=R:joseph@???
13:07:54  4707 no domain retry record
13:07:54  4707 no address retry record
13:07:54  4707 joseph@???: queued for routing
13:07:54  4707 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
13:07:54  4707 routing joseph@???
13:07:54  4707 --------> notlocal router <--------
13:07:54  4707 local_part=joseph domain=samibm.com
13:07:54  4707 checking domains
13:07:54  4707 samibm.com in "samibm.com : localhost"? yes (matched "samibm.com")
13:07:54  4707 samibm.com in "! +local_domains"? no (matched "! +local_domains")
13:07:54  4707 notlocal router skipped: domains mismatch
13:07:54  4707 --------> db_user router <--------
13:07:54  4707 local_part=joseph domain=samibm.com
13:07:54  4707 checking domains
13:07:54  4707 cached yes match for +local_domains
13:07:54  4707 cached lookup data = NULL
13:07:54  4707 samibm.com in "+local_domains"? yes (matched "+local_domains" - cached)
13:07:54  4707 checking local_parts
13:07:54  4707 expanding: username
13:07:54  4707    result: username
13:07:54  4707 expanding: $local_part
13:07:54  4707    result: joseph
13:07:54  4707 expanding: select mailbox,username,uid from mailtest where username='${quote_pgsql:$local_part}'
13:07:54  4707    result: select mailbox,username,uid from mailtest where username='joseph'
13:07:54  4707 search_open: pgsql "NULL"
13:07:54  4707 search_find: file="NULL"
13:07:54  4707   key="select mailbox,username,uid from mailtest where username='joseph'" partial=-1 affix=NULL starflags=0
13:07:54  4707 LRU list:
13:07:54  4707 internal_search_find: file="NULL"
13:07:54  4707   type=pgsql key="select mailbox,username,uid from mailtest where username='joseph'"
13:07:54  4707 database lookup required for select mailbox,username,uid from mailtest where username='joseph'
13:07:54  4707 PGSQL query: select mailbox,username,uid from mailtest where username='joseph'
13:07:54  4707 PGSQL new connection: host=127.0.0.1 port= database=testdb user=root
13:07:54  4707 lookup yielded: mailbox=/home/joseph/mail username=joseph uid=1004 
13:07:54  4707 expanding: ${lookup pgsql {select mailbox,username,uid from mailtest where username='${quote_pgsql:$local_part}'}}
13:07:54  4707    result: mailbox=/home/joseph/mail username=joseph uid=1004 
13:07:54  4707 expanding: ${extract {username}{${lookup pgsql {select mailbox,username,uid from mailtest where username='${quote_pgsql:$local_part}'}}}}
13:07:54  4707    result: joseph
13:07:54  4707 joseph in "joseph"? yes (matched "joseph")
13:07:54  4707 expanding: R: local_user for $local_part@$domain
13:07:54  4707    result: R: local_user for joseph@???
13:07:54  4707 R: local_user for joseph@???
13:07:54  4707 calling db_user router
13:07:54  4707 db_user router called for joseph@???
13:07:54  4707   domain = samibm.com
13:07:54  4707 set transport db_mail_spool
13:07:54  4707 queued for db_mail_spool transport: local_part = joseph
13:07:54  4707 domain = samibm.com
13:07:54  4707   errors_to=NULL
13:07:54  4707   domain_data=NULL localpart_data=NULL
13:07:54  4707 routed by db_user router
13:07:54  4707   envelope to: joseph@???
13:07:54  4707   transport: db_mail_spool
13:07:54  4707 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
13:07:54  4707 After routing:
13:07:54  4707   Local deliveries:
13:07:54  4707     joseph@???
13:07:54  4707   Remote deliveries:
13:07:54  4707   Failed addresses:
13:07:54  4707   Deferred addresses:
13:07:54  4707 search_tidyup called
13:07:54  4707 close PGSQL connection: 127.0.0.1/testdb/root
13:07:54  4707 >>>>>>>>>>>>>>>> Local deliveries >>>>>>>>>>>>>>>>
13:07:54  4707 --------> joseph@??? <--------
13:07:54  4707 locking /var/spool/exim4/db/retry.lockfile
13:07:54  4707 locked /var/spool/exim4/db/retry.lockfile
13:07:54  4707 EXIM_DBOPEN(/var/spool/exim4/db/retry)
13:07:54  4707 returned from EXIM_DBOPEN
13:07:54  4707 opened hints database /var/spool/exim4/db/retry: flags=O_RDONLY
13:07:54  4707 dbfn_read: key=T:joseph@???
13:07:54  4707 no retry record exists
13:07:54  4707 expanding: uid
13:07:54  4707    result: uid
13:07:54  4707 expanding: $local_part
13:07:54  4707    result: joseph
13:07:54  4707 expanding: select mailbox,username,uid from mailtest where username='${quote_pgsql:$local_part}'
13:07:54  4707    result: select mailbox,username,uid from mailtest where username='joseph'
13:07:54  4707 search_open: pgsql "NULL"
13:07:54  4707 search_find: file="NULL"
13:07:54  4707   key="select mailbox,username,uid from mailtest where username='joseph'" partial=-1 affix=NULL starflags=0
13:07:54  4707 LRU list:
13:07:54  4707 internal_search_find: file="NULL"
13:07:54  4707   type=pgsql key="select mailbox,username,uid from mailtest where username='joseph'"
13:07:54  4707 database lookup required for select mailbox,username,uid from mailtest where username='joseph'
13:07:54  4707 PGSQL query: select mailbox,username,uid from mailtest where username='joseph'
13:07:54  4707 PGSQL new connection: host=127.0.0.1 port= database=testdb user=root
13:07:54  4707 lookup yielded: mailbox=/home/joseph/mail username=joseph uid=1004 
13:07:54  4707 expanding: ${lookup pgsql {select mailbox,username,uid from mailtest where username='${quote_pgsql:$local_part}'}}
13:07:54  4707    result: mailbox=/home/joseph/mail username=joseph uid=1004 
13:07:54  4707 expanding: ${extract{uid}{${lookup pgsql {select mailbox,username,uid from mailtest where username='${quote_pgsql:$local_part}'}}}}
13:07:54  4707    result: 1004
13:07:54  4707 seeking password data for user "1004": cache not available
13:07:54  4707 search_tidyup called
13:07:54  4707 close PGSQL connection: 127.0.0.1/testdb/root
13:07:54  4711 changed uid/gid: local delivery to joseph <joseph@???> transport=db_mail_spool
13:07:54  4711   uid=1004 gid=8 pid=4711
13:07:54  4711   auxiliary group list: <none>
13:07:54  4711   home=NULL current=/
13:07:54  4711 set_process_info:  4711 delivering 1KJ5nU-0001Dm-Hl to joseph using db_mail_spool
13:07:54  4711 expanding: T: db appendfile for $local_part@$domain
13:07:54  4711    result: T: db appendfile for joseph@???
13:07:54  4711 T: db appendfile for joseph@???
13:07:54  4711 appendfile transport entered
13:07:54  4711 expanding: mailbox
13:07:54  4711    result: mailbox
13:07:54  4711 expanding: $local_part
13:07:54  4711    result: joseph
13:07:54  4711 expanding: select mailbox,username,uid from mailtest where username='${quote_pgsql:$local_part}'
13:07:54  4711    result: select mailbox,username,uid from mailtest where username='joseph'
13:07:54  4711 search_open: pgsql "NULL"
13:07:54  4711 search_find: file="NULL"
13:07:54  4711   key="select mailbox,username,uid from mailtest where username='joseph'" partial=-1 affix=NULL starflags=0
13:07:54  4711 LRU list:
13:07:54  4711 internal_search_find: file="NULL"
13:07:54  4711   type=pgsql key="select mailbox,username,uid from mailtest where username='joseph'"
13:07:54  4711 database lookup required for select mailbox,username,uid from mailtest where username='joseph'
13:07:54  4711 PGSQL query: select mailbox,username,uid from mailtest where username='joseph'
13:07:54  4711 PGSQL new connection: host=127.0.0.1 port= database=testdb user=root
13:07:54  4711 lookup yielded: mailbox=/home/joseph/mail username=joseph uid=1004 
13:07:54  4711 expanding: ${lookup pgsql {select mailbox,username,uid from mailtest where username='${quote_pgsql:$local_part}'}}
13:07:54  4711    result: mailbox=/home/joseph/mail username=joseph uid=1004 
13:07:54  4711 expanding: ${extract {mailbox}{${lookup pgsql {select mailbox,username,uid from mailtest where username='${quote_pgsql:$local_part}'}}}}
13:07:54  4711    result: /home/joseph/mail
13:07:54  4711 appendfile: mode=660 notify_comsat=0 quota=0 warning=0
13:07:54  4711   file=/home/joseph/mail format=unix
13:07:54  4711   message_prefix=From ${if def:return_path{$return_path}{MAILER-DAEMON}} ${tod_bsdinbox}\n
13:07:54  4711   message_suffix=\n
13:07:54  4711   maildir_use_size_file=no
13:07:54  4711   locking by lockfile fcntl 
13:07:54  4711 lock name: /home/joseph/mail.lock
13:07:54  4711 hitch name: /home/joseph/mail.lock.localhost.487de49a.00001267
13:07:54  4711 lock file created
13:07:54  4711 mailbox /home/joseph/mail is locked
13:07:54  4711 writing to file /home/joseph/mail
13:07:54  4711 condition: def:return_path
13:07:54  4711    result: true
13:07:54  4711 expanding: $return_path
13:07:54  4711    result: sam@???
13:07:54  4711 expanding: MAILER-DAEMON
13:07:54  4711    result: MAILER-DAEMON
13:07:54  4711 skipping: result is not used
13:07:54  4711 expanding: From ${if def:return_path{$return_path}{MAILER-DAEMON}} ${tod_bsdinbox}
13:07:54  4711 
13:07:54  4711    result: From sam@??? Wed Jul 16 13:07:54 2008
13:07:54  4711 
13:07:54  4711 writing data block fd=7 size=46 timeout=0
13:07:54  4711 writing data block fd=7 size=315 timeout=0
13:07:54  4711 writing data block fd=7 size=1 timeout=0
13:07:54  4711 appendfile yields 0 with errno=0 more_errno=0
13:07:54  4707 journalling joseph@???
13:07:54  4711 search_tidyup called
13:07:54  4711 close PGSQL connection: 127.0.0.1/testdb/root
13:07:54  4707 db_mail_spool transport returned OK for joseph@???
13:07:54  4707 post-process joseph@??? (0)
13:07:54  4707 joseph@??? delivered
13:07:54  4707 LOG: MAIN
13:07:54  4707   => joseph <joseph@???> R=db_user T=db_mail_spool
13:07:54  4707 >>>>>>>>>>>>>>>> deliveries are done >>>>>>>>>>>>>>>>
13:07:54  4707 changed uid/gid: post-delivery tidying
13:07:54  4707   uid=104 gid=107 pid=4707
13:07:54  4707   auxiliary group list: <none>
13:07:54  4707 set_process_info:  4707 tidying up after delivering 1KJ5nU-0001Dm-Hl
13:07:54  4707 Processing retry items
13:07:54  4707 Succeeded addresses:
13:07:54  4707 joseph@???: no retry items
13:07:54  4707 Failed addresses:
13:07:54  4707 Deferred addresses:
13:07:54  4707 end of retry processing
13:07:54  4707 LOG: MAIN
13:07:54  4707   Completed
13:07:54  4707 end delivery of 1KJ5nU-0001Dm-Hl
13:07:54  4707 search_tidyup called
13:07:54  4707 search_tidyup called
13:07:54  4707 >>>>>>>>>>>>>>>> Exim pid=4707 terminating with rc=0 >>>>>>>>>>>>>>>>