On Tue, Jan 23, 2007 at 02:50:52PM +0000, Philip Hazel wrote:
> On Tue, 23 Jan 2007, Tim Bishop wrote:
>
> > command = /usr/local/bin/exim -oMr spam-scanned -os 5m -bS
> > transport_filter = /usr/local/bin/spamc -x -U ...
> > use_bsmtp = true
>
> > However, if I add -bS to the command line it behaves differently
> > and says:
> >
> > skipping ACL configuration - not needed
>
> Please post the complete debug output and show the full command line;
> that particular message should occur only for runs of Exim that do not
> receive messages. The code looks fairly unambiguous.
On closer inspection of the logs that "skipping ACL configuration" line
happens later on. Comparing a log with -bS and without the former
doesn't do any ACL stuff in the place where the latter does.
Two logs attached.
log.local, generated by running:
/usr/local/bin/exim -oMr spam-scanned \
-C /cluster/BackupMX/etc/exim/configure -d+all tdb@???
log.bsmtp, generated by running:
/usr/local/bin/exim -oMr spam-scanned \
-C /cluster/BackupMX/etc/exim/configure -d+all -bS
Input fed to both commands can be seen in the logs.
So it still looks like the ACL stuff isn't happening.
Thanks,
Tim.
--
Tim Bishop
http://www.bishnet.net/tim/
PGP Key: 0x5AE7D984
# /usr/local/bin/exim -oMr spam-scanned -C /cluster/BackupMX/etc/exim/configure -d+all -bS
14:58:59 29998 Exim version 4.66 uid=0 gid=1 pid=29998 D=fffdffff
Probably ndbm
Support for: crypteq iconv() OpenSSL
Lookups: lsearch wildlsearch nwildlsearch iplsearch dbm dbmnz mysql
Authenticators: plaintext
Routers: accept dnslookup ipliteral manualroute queryprogram redirect
Transports: appendfile/maildir autoreply pipe smtp
Fixed never_users: 0
Size of off_t: 4
14:58:59 29998 changed uid/gid: forcing real = effective
14:58:59 29998 uid=0 gid=1 pid=29998
14:58:59 29998 auxiliary group list: <none>
14:58:59 29998 seeking password data for user "root": cache not available
14:58:59 29998 getpwnam() succeeded uid=0 gid=1
14:58:59 29998 configuration file is /cluster/BackupMX/etc/exim/configure
14:58:59 29998 log selectors = 00000ffc 00089001
14:58:59 29998 cwd=/home/cur/tdb 7 args: /usr/local/bin/exim -oMr spam-scanned -C /cluster/BackupMX/etc/exim/configure -d+all -bS
14:58:59 29998 trusted user
14:58:59 29998 admin user
14:58:59 29998 changed uid/gid: privilege not needed
14:58:59 29998 uid=15614 gid=29001 pid=29998
14:58:59 29998 auxiliary group list: 29001
14:58:59 29998 expanding: $1
14:58:59 29998 result: Super-User
14:58:59 29998 user name "Super-User" extracted from gecos field "Super-User"
14:58:59 29998 originator: uid=0 gid=1 login=root name=Super-User
14:58:59 29998 sender address = NULL
14:58:59 29998 in hosts_connection_nolog? no (option unset)
14:58:59 29998 LOG: smtp_connection MAIN
14:58:59 29998 SMTP connection from root
14:58:59 29998 smtp_setup_msg entered
MAIL FROM: tdb@???
RCPT TO: tdb@???
DATA
test
.
14:59:03 29998 SMTP<< MAIL FROM: tdb@???
14:59:03 29998 SMTP<< RCPT TO: tdb@???
14:59:03 29998 SMTP<< DATA
14:59:03 29998 search_tidyup called
14:59:03 29998 >>Headers received:
14:59:03 29998
14:59:03 29998 rewrite_one_header: type=F:
14:59:03 29998 From: tdb@???
14:59:03 29998 search_tidyup called
14:59:03 29998 >>Headers after rewriting and local additions:
14:59:03 29998 I Message-Id: <E1H9N71-0007nq-Il@???>
14:59:03 29998 F From: tdb@???
14:59:03 29998 Date: Tue, 23 Jan 2007 14:59:03 +0000
14:59:03 29998
14:59:03 29998 Data file written for message 1H9N71-0007nq-Il
14:59:03 29998 expanding: ${tod_full}
14:59:03 29998 result: Tue, 23 Jan 2007 14:59:03 +0000
14:59:03 29998 condition: def:sender_rcvhost
14:59:03 29998 result: false
14:59:03 29998 expanding: from $sender_rcvhost
14:59:03 29998
14:59:03 29998 result: from
14:59:03 29998
14:59:03 29998 skipping: result is not used
14:59:03 29998 condition: def:sender_ident
14:59:03 29998 result: true
14:59:03 29998 expanding: $sender_ident
14:59:03 29998 result: root
14:59:03 29998 expanding: from ${quote_local_part:$sender_ident}
14:59:03 29998 result: from root
14:59:03 29998 condition: def:sender_helo_name
14:59:03 29998 result: false
14:59:03 29998 expanding: (helo=$sender_helo_name)
14:59:03 29998
14:59:03 29998 result: (helo=)
14:59:03 29998
14:59:03 29998 skipping: result is not used
14:59:03 29998 expanding: ${if def:sender_ident {from ${quote_local_part:$sender_ident} }}${if def:sender_helo_name {(helo=$sender_helo_name)
14:59:03 29998 }}
14:59:03 29998 result: from root
14:59:03 29998 condition: def:received_protocol
14:59:03 29998 result: true
14:59:03 29998 expanding: with $received_protocol
14:59:03 29998 result: with spam-scanned
14:59:03 29998 condition: def:tls_cipher
14:59:03 29998 result: false
14:59:03 29998 expanding: ($tls_cipher)
14:59:03 29998
14:59:03 29998 result: ()
14:59:03 29998
14:59:03 29998 skipping: result is not used
14:59:03 29998 condition: def:sender_address
14:59:03 29998 result: true
14:59:03 29998 expanding: (envelope-from <$sender_address>)
14:59:03 29998
14:59:03 29998 result: (envelope-from <tdb@???>)
14:59:03 29998
14:59:03 29998 condition: def:received_for
14:59:03 29998 result: true
14:59:03 29998 expanding:
14:59:03 29998 for $received_for
14:59:03 29998 result:
14:59:03 29998 for tdb@???
14:59:03 29998 expanding: Received: ${if def:sender_rcvhost {from $sender_rcvhost
14:59:03 29998 }{${if def:sender_ident {from ${quote_local_part:$sender_ident} }}${if def:sender_helo_name {(helo=$sender_helo_name)
14:59:03 29998 }}}}by $primary_hostname ${if def:received_protocol {with $received_protocol}} ${if def:tls_cipher {($tls_cipher)
14:59:03 29998 }}(Exim $version_number)
14:59:03 29998 ${if def:sender_address {(envelope-from <$sender_address>)
14:59:03 29998 }}id $message_exim_id${if def:received_for {
14:59:03 29998 for $received_for}}
14:59:03 29998 result: Received: from root by re.ukc.ac.uk with spam-scanned (Exim 4.66)
14:59:03 29998 (envelope-from <tdb@???>)
14:59:03 29998 id 1H9N71-0007nq-Il
14:59:03 29998 for tdb@???
14:59:03 29998 >>Generated Received: header line
14:59:03 29998 P Received: from root by re.ukc.ac.uk with spam-scanned (Exim 4.66)
14:59:03 29998 (envelope-from <tdb@???>)
14:59:03 29998 id 1H9N71-0007nq-Il
14:59:03 29998 for tdb@???; Tue, 23 Jan 2007 14:59:03 +0000
14:59:03 29998 calling local_scan(); timeout=300
14:59:03 29998 local_scan() returned 0 NULL
14:59:03 29998 expanding: ${tod_full}
14:59:03 29998 result: Tue, 23 Jan 2007 14:59:03 +0000
14:59:03 29998 Writing spool header file
14:59:03 29998 Size of headers = 284
14:59:03 29998 LOG: MAIN
14:59:03 29998 <= tdb@??? U=root P=spam-scanned S=290
14:59:03 29998 search_tidyup called
14:59:03 29998 smtp_setup_msg entered
14:59:03 29999 exec /usr/local/bin/exim -C /cluster/BackupMX/etc/exim/configure -d=0xfffdffff -Mc 1H9N71-0007nq-Il
14:59:03 29999 Exim version 4.66 uid=15614 gid=29001 pid=29999 D=fffdffff
Probably ndbm
Support for: crypteq iconv() OpenSSL
Lookups: lsearch wildlsearch nwildlsearch iplsearch dbm dbmnz mysql
Authenticators: plaintext
Routers: accept dnslookup ipliteral manualroute queryprogram redirect
Transports: appendfile/maildir autoreply pipe smtp
Fixed never_users: 0
Size of off_t: 4
14:59:03 29999 changed uid/gid: forcing real = effective
14:59:03 29999 uid=0 gid=29001 pid=29999
14:59:03 29999 auxiliary group list: <none>
14:59:03 29999 seeking password data for user "root": cache not available
14:59:03 29999 getpwnam() succeeded uid=0 gid=1
14:59:03 29999 configuration file is /cluster/BackupMX/etc/exim/configure
14:59:03 29999 log selectors = 00000ffc 00089001
14:59:03 29999 cwd=/cluster/BackupMX/var/exim 6 args: /usr/local/bin/exim -C /cluster/BackupMX/etc/exim/configure -d=0xfffdffff -Mc 1H9N71-0007nq-Il
14:59:03 29999 trusted user
14:59:03 29999 admin user
14:59:03 29999 skipping ACL configuration - not needed
14:59:03 29999 set_process_info: 29999 delivering specified messages
14:59:03 29999 set_process_info: 29999 delivering 1H9N71-0007nq-Il
14:59:03 29999 reading spool file 1H9N71-0007nq-Il-H
14:59:03 29999 user=root uid=0 gid=1 sender=tdb@???
14:59:03 29999 sender_local=0 ident=root
14:59:03 29999 Non-recipients:
14:59:03 29999 Empty Tree
14:59:03 29999 ---- End of tree ----
14:59:03 29999 recipients_count=1
14:59:03 29999 body_linecount=1 message_linecount=7
14:59:03 29999 Delivery address list:
14:59:03 29999 tdb@???
14:59:03 29999 locking /cluster/BackupMX/var/exim/db/retry.lockfile
14:59:03 29999 locked /cluster/BackupMX/var/exim/db/retry.lockfile
14:59:03 29999 EXIM_DBOPEN(/cluster/BackupMX/var/exim/db/retry)
14:59:03 29999 returned from EXIM_DBOPEN
14:59:03 29999 opened hints database /cluster/BackupMX/var/exim/db/retry: flags=O_RDONLY
14:59:03 29999 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
14:59:03 29999 Considering: tdb@???
14:59:03 29999 unique = tdb@???
14:59:03 29999 dbfn_read: key=R:mx.cs.kent.ac.uk
14:59:03 29999 dbfn_read: key=R:tdb@???
14:59:03 29999 dbfn_read: key=R:tdb@???:<tdb@???>
14:59:03 29999 no domain retry record
14:59:03 29999 no address retry record
14:59:03 29999 tdb@???: queued for routing
14:59:03 29999 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
14:59:03 29999 routing tdb@???
14:59:03 29999 --------> global_aliases router <--------
14:59:03 29999 local_part=tdb domain=mx.cs.kent.ac.uk
14:59:03 29999 checking domains
14:59:03 29999 mx.cs.kent.ac.uk in "cstest.kent.ac.uk : *.cstest.kent.ac.uk"? no (end of list)
14:59:03 29999 mx.cs.kent.ac.uk in "ukc.ac.uk : kent.ac.uk"? no (end of list)
14:59:03 29999 mx.cs.kent.ac.uk in "*.ukc.ac.uk : *.kent.ac.uk"? yes (matched "*.kent.ac.uk")
14:59:03 29999 mx.cs.kent.ac.uk in "!+ignore_domains : +kent_domains : +kent_hosts"? yes (matched "+kent_hosts")
14:59:03 29999 calling global_aliases router
14:59:03 29999 rda_interpret (string): ${lookup{${sg{$local_part}{^~}{}}}lsearch{/etc/aliases}}
14:59:03 29999 expanding: $local_part
14:59:03 29999 result: tdb
14:59:03 29999 expanding: ^~
14:59:03 29999 result: ^~
14:59:03 29999 expanding:
14:59:03 29999 result:
14:59:03 29999 expanding: ${sg{$local_part}{^~}{}}
14:59:03 29999 result: tdb
14:59:03 29999 expanding: /etc/aliases
14:59:03 29999 result: /etc/aliases
14:59:03 29999 search_open: lsearch "/etc/aliases"
14:59:03 29999 search_find: file="/etc/aliases"
14:59:03 29999 key="tdb" partial=-1 affix=NULL starflags=0
14:59:03 29999 LRU list:
14:59:03 29999 :/etc/aliases
14:59:03 29999 End
14:59:03 29999 internal_search_find: file="/etc/aliases"
14:59:03 29999 type=lsearch key="tdb"
14:59:03 29999 file lookup required for tdb
14:59:03 29999 in /etc/aliases
14:59:03 29999 lookup failed
14:59:03 29999 expanding: ${lookup{${sg{$local_part}{^~}{}}}lsearch{/etc/aliases}}
14:59:03 29999 result:
14:59:03 29999 expanded:
14:59:03 29999 file is not a filter file
14:59:03 29999 parse_forward_list:
14:59:03 29999 global_aliases router declined for tdb@???
14:59:03 29999 --------> host_route router <--------
14:59:03 29999 local_part=tdb domain=mx.cs.kent.ac.uk
14:59:03 29999 checking domains
14:59:03 29999 cached no match for +kent_domains
14:59:03 29999 cached lookup data = NULL
14:59:03 29999 mx.cs.kent.ac.uk in "mx.cs.ukc.ac.uk : mx.cs.kent.ac.uk : cs.ukc.ac.uk : cs.kent.ac.uk"? yes (matched "mx.cs.kent.ac.uk")
14:59:03 29999 mx.cs.kent.ac.uk in "!+kent_domains : !+mx_domains : !+local_domains : +kent_hosts"? no (matched "!+mx_domains")
14:59:03 29999 host_route router skipped: domains mismatch
14:59:03 29999 --------> hub_route router <--------
14:59:03 29999 local_part=tdb domain=mx.cs.kent.ac.uk
14:59:03 29999 checking domains
14:59:03 29999 mx.cs.kent.ac.uk in "@ : re.ukc.ac.uk : re.kent.ac.uk"? no (end of list)
14:59:03 29999 cached yes match for +mx_domains
14:59:03 29999 cached lookup data = NULL
14:59:03 29999 mx.cs.kent.ac.uk in "!+local_domains : !+mx_domains"? no (matched "!+mx_domains" - cached)
14:59:03 29999 hub_route router skipped: domains mismatch
14:59:03 29999 --------> spamcheck_route router <--------
14:59:03 29999 local_part=tdb domain=mx.cs.kent.ac.uk
14:59:03 29999 checking "condition"
14:59:03 29999 expanding: $received_protocol
14:59:03 29999 result: spam-scanned
14:59:03 29999 expanding: spam-scanned
14:59:03 29999 result: spam-scanned
14:59:03 29999 expanding: $received_protocol
14:59:03 29999 result:
14:59:03 29999 skipping: result is not used
14:59:03 29999 expanding: local
14:59:03 29999 result: local
14:59:03 29999 skipping: result is not used
14:59:03 29999 condition: and {{!eq {$received_protocol}{spam-scanned}} {!eq {$received_protocol}{local}}}
14:59:03 29999 result: false
14:59:03 29999 expanding: 1
14:59:03 29999 result: 1
14:59:03 29999 skipping: result is not used
14:59:03 29999 expanding: 0
14:59:03 29999 result: 0
14:59:03 29999 expanding: ${if and {{!eq {$received_protocol}{spam-scanned}} {!eq {$received_protocol}{local}}} {1}{0}}
14:59:03 29999 result: 0
14:59:03 29999 spamcheck_route router skipped: condition failure
14:59:03 29999 --------> mx_route router <--------
14:59:03 29999 local_part=tdb domain=mx.cs.kent.ac.uk
14:59:03 29999 checking domains
14:59:03 29999 cached yes match for +mx_domains
14:59:03 29999 cached lookup data = NULL
14:59:03 29999 mx.cs.kent.ac.uk in "+mx_domains"? yes (matched "+mx_domains" - cached)
14:59:03 29999 calling mx_route router
14:59:03 29999 rda_interpret (string): ${sg{${lookup mysql{select alias from mx_aliases where login='${sg{${quote_mysql:$local_part}}{^~}{}}'}{$value}fail}}{^([^@]+)(@.*)?\$}{\$1$local_part_suffix\$2}}
14:59:03 29999 expanding: $local_part
14:59:03 29999 result: tdb
14:59:03 29999 expanding: ${quote_mysql:$local_part}
14:59:03 29999 result: tdb
14:59:03 29999 expanding: ^~
14:59:03 29999 result: ^~
14:59:03 29999 expanding:
14:59:03 29999 result:
14:59:03 29999 expanding: select alias from mx_aliases where login='${sg{${quote_mysql:$local_part}}{^~}{}}'
14:59:03 29999 result: select alias from mx_aliases where login='tdb'
14:59:03 29999 search_open: mysql "NULL"
14:59:03 29999 search_find: file="NULL"
14:59:03 29999 key="select alias from mx_aliases where login='tdb'" partial=-1 affix=NULL starflags=0
14:59:03 29999 LRU list:
14:59:03 29999 :/etc/aliases
14:59:03 29999 End
14:59:03 29999 internal_search_find: file="NULL"
14:59:03 29999 type=mysql key="select alias from mx_aliases where login='tdb'"
14:59:03 29999 database lookup required for select alias from mx_aliases where login='tdb'
14:59:03 29999 MYSQL query: select alias from mx_aliases where login='tdb'
14:59:03 29999 MYSQL new connection: host=maildb.cs.ukc.ac.uk port=0 socket=NULL database=exim user=exim
14:59:03 29999 lookup yielded: ~tdb@???
14:59:03 29999 expanding: $value
14:59:03 29999 result: ~tdb@???
14:59:03 29999 expanding: ${lookup mysql{select alias from mx_aliases where login='${sg{${quote_mysql:$local_part}}{^~}{}}'}{$value}fail}
14:59:03 29999 result: ~tdb@???
14:59:03 29999 expanding: ^([^@]+)(@.*)?\$
14:59:03 29999 result: ^([^@]+)(@.*)?$
14:59:03 29999 expanding: \$1$local_part_suffix\$2
14:59:03 29999 result: $1$2
14:59:03 29999 expanding: $1$2
14:59:03 29999 result: ~tdb@???
14:59:03 29999 expanding: ${sg{${lookup mysql{select alias from mx_aliases where login='${sg{${quote_mysql:$local_part}}{^~}{}}'}{$value}fail}}{^([^@]+)(@.*)?\$}{\$1$local_part_suffix\$2}}
14:59:03 29999 result: ~tdb@???
14:59:03 29999 expanded: ~tdb@???
14:59:03 29999 file is not a filter file
14:59:03 29999 parse_forward_list: ~tdb@???
14:59:03 29999 extract item: ~tdb@???
14:59:03 29999 mx_route router generated ~tdb@???
14:59:03 29999 errors_to=NULL transport=NULL
14:59:03 29999 uid=unset gid=unset home=NULL
14:59:03 29999 routed by mx_route router
14:59:03 29999 envelope to: tdb@???
14:59:03 29999 transport: <none>
14:59:03 29999 locking /cluster/BackupMX/var/exim/db/retry.lockfile
14:59:03 29999 locked /cluster/BackupMX/var/exim/db/retry.lockfile
14:59:03 29999 EXIM_DBOPEN(/cluster/BackupMX/var/exim/db/retry)
14:59:03 29999 returned from EXIM_DBOPEN
14:59:03 29999 opened hints database /cluster/BackupMX/var/exim/db/retry: flags=O_RDONLY
14:59:03 29999 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
14:59:03 29999 Considering: ~tdb@???
14:59:03 29999 unique = ~tdb@???
14:59:03 29999 dbfn_read: key=R:myrtle.ukc.ac.uk
14:59:03 29999 dbfn_read: key=R:~tdb@???
14:59:03 29999 dbfn_read: key=R:~tdb@???:<tdb@???>
14:59:03 29999 no domain retry record
14:59:03 29999 no address retry record
14:59:03 29999 ~tdb@???: queued for routing
14:59:03 29999 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
14:59:03 29999 routing ~tdb@???
14:59:03 29999 --------> global_aliases router <--------
14:59:03 29999 local_part=~tdb domain=myrtle.ukc.ac.uk
14:59:03 29999 checking domains
14:59:03 29999 myrtle.ukc.ac.uk in "cstest.kent.ac.uk : *.cstest.kent.ac.uk"? no (end of list)
14:59:03 29999 myrtle.ukc.ac.uk in "ukc.ac.uk : kent.ac.uk"? no (end of list)
14:59:03 29999 myrtle.ukc.ac.uk in "*.ukc.ac.uk : *.kent.ac.uk"? yes (matched "*.ukc.ac.uk")
14:59:03 29999 myrtle.ukc.ac.uk in "!+ignore_domains : +kent_domains : +kent_hosts"? yes (matched "+kent_hosts")
14:59:03 29999 calling global_aliases router
14:59:03 29999 rda_interpret (string): ${lookup{${sg{$local_part}{^~}{}}}lsearch{/etc/aliases}}
14:59:03 29999 expanding: $local_part
14:59:03 29999 result: ~tdb
14:59:03 29999 expanding: ^~
14:59:03 29999 result: ^~
14:59:03 29999 expanding:
14:59:03 29999 result:
14:59:03 29999 expanding: ${sg{$local_part}{^~}{}}
14:59:03 29999 result: tdb
14:59:03 29999 expanding: /etc/aliases
14:59:03 29999 result: /etc/aliases
14:59:03 29999 search_open: lsearch "/etc/aliases"
14:59:03 29999 cached open
14:59:03 29999 search_find: file="/etc/aliases"
14:59:03 29999 key="tdb" partial=-1 affix=NULL starflags=0
14:59:03 29999 LRU list:
14:59:03 29999 :/etc/aliases
14:59:03 29999 End
14:59:03 29999 internal_search_find: file="/etc/aliases"
14:59:03 29999 type=lsearch key="tdb"
14:59:03 29999 cached data used for lookup of tdb
14:59:03 29999 in /etc/aliases
14:59:03 29999 lookup failed
14:59:03 29999 expanding: ${lookup{${sg{$local_part}{^~}{}}}lsearch{/etc/aliases}}
14:59:03 29999 result:
14:59:03 29999 expanded:
14:59:03 29999 file is not a filter file
14:59:03 29999 parse_forward_list:
14:59:03 29999 global_aliases router declined for ~tdb@???
14:59:03 29999 --------> host_route router <--------
14:59:03 29999 local_part=~tdb domain=myrtle.ukc.ac.uk
14:59:03 29999 checking domains
14:59:03 29999 cached no match for +kent_domains
14:59:03 29999 cached lookup data = NULL
14:59:03 29999 myrtle.ukc.ac.uk in "mx.cs.ukc.ac.uk : mx.cs.kent.ac.uk : cs.ukc.ac.uk : cs.kent.ac.uk"? no (end of list)
14:59:03 29999 myrtle.ukc.ac.uk in "@ : re.ukc.ac.uk : re.kent.ac.uk"? no (end of list)
14:59:03 29999 cached yes match for +kent_hosts
14:59:03 29999 cached lookup data = NULL
14:59:03 29999 myrtle.ukc.ac.uk in "!+kent_domains : !+mx_domains : !+local_domains : +kent_hosts"? yes (matched "+kent_hosts" - cached)
14:59:03 29999 calling host_route router
14:59:03 29999 host_route router called for ~tdb@???
14:59:03 29999 domain = myrtle.ukc.ac.uk
14:59:03 29999 DNS lookup of myrtle.ukc.ac.uk (MX) gave NO_DATA
14:59:03 29999 returning DNS_NODATA
14:59:03 29999 DNS lookup of myrtle.ukc.ac.uk (A) succeeded
14:59:03 29999 Actual local interface address is 127.0.0.1 (lo0)
14:59:03 29999 Actual local interface address is 129.12.4.21 (bge0)
14:59:03 29999 Actual local interface address is 129.12.4.20 (bge0:1)
14:59:03 29999 Actual local interface address is 129.12.4.51 (bge0:2)
14:59:03 29999 Actual local interface address is 129.12.4.50 (bge0:3)
14:59:03 29999 Actual local interface address is 129.12.4.10 (bge0:4)
14:59:03 29999 Actual local interface address is 129.12.4.62 (bge0:7)
14:59:03 29999 Actual local interface address is 129.12.4.22 (ce0)
14:59:03 29999 fully qualified name = myrtle.ukc.ac.uk
14:59:03 29999 myrtle.ukc.ac.uk 129.12.3.176 mx=-1 sort=-454
14:59:03 29999 set transport remote_smtp
14:59:03 29999 queued for remote_smtp transport: local_part = ~tdb
14:59:03 29999 domain = myrtle.ukc.ac.uk
14:59:03 29999 errors_to=NULL
14:59:03 29999 domain_data=NULL localpart_data=NULL
14:59:03 29999 routed by host_route router
14:59:03 29999 envelope to: ~tdb@???
14:59:03 29999 transport: remote_smtp
14:59:03 29999 host myrtle.ukc.ac.uk [129.12.3.176]
14:59:03 29999 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
14:59:03 29999 After routing:
14:59:03 29999 Local deliveries:
14:59:03 29999 Remote deliveries:
14:59:03 29999 ~tdb@???
14:59:03 29999 Failed addresses:
14:59:03 29999 Deferred addresses:
14:59:03 29999 search_tidyup called
14:59:03 29999 close MYSQL connection: maildb.cs.ukc.ac.uk/exim/exim
14:59:03 29999 >>>>>>>>>>>>>>>> Remote deliveries >>>>>>>>>>>>>>>>
14:59:03 29999 --------> ~tdb@??? <--------
14:59:03 29999 search_tidyup called
14:59:03 4 changed uid/gid: remote delivery to ~tdb@??? with transport=remote_smtp
14:59:03 4 uid=15614 gid=29001 pid=4
14:59:03 4 auxiliary group list: <none>
14:59:03 4 set_process_info: 4 delivering 1H9N71-0007nq-Il using remote_smtp
14:59:03 4 remote_smtp transport entered
14:59:03 4 ~tdb@???
14:59:03 29999 set_process_info: 29999 delivering 1H9N71-0007nq-Il: waiting for a remote delivery subprocess to finish
14:59:03 29999 selecting on subprocess pipes
14:59:03 4 myrtle.ukc.ac.uk in queue_smtp_domains? no (option unset)
14:59:03 4 checking status of myrtle.ukc.ac.uk
14:59:03 4 locking /cluster/BackupMX/var/exim/db/retry.lockfile
14:59:03 4 locked /cluster/BackupMX/var/exim/db/retry.lockfile
14:59:03 4 EXIM_DBOPEN(/cluster/BackupMX/var/exim/db/retry)
14:59:03 4 returned from EXIM_DBOPEN
14:59:03 4 opened hints database /cluster/BackupMX/var/exim/db/retry: flags=O_RDONLY
14:59:03 4 dbfn_read: key=T:myrtle.ukc.ac.uk:129.12.3.176
14:59:03 4 dbfn_read: key=T:myrtle.ukc.ac.uk:129.12.3.176:1H9N71-0007nq-Il
14:59:03 4 no host retry record
14:59:03 4 no message retry record
14:59:03 4 myrtle.ukc.ac.uk [129.12.3.176] status = usable
14:59:03 4 129.12.3.176 in serialize_hosts? no (option unset)
14:59:03 4 delivering 1H9N71-0007nq-Il to myrtle.ukc.ac.uk [129.12.3.176] (~tdb@???)
14:59:03 4 set_process_info: 4 delivering 1H9N71-0007nq-Il to myrtle.ukc.ac.uk [129.12.3.176] (~tdb@???)
14:59:03 4 expanding: $primary_hostname
14:59:03 4 result: re.ukc.ac.uk
14:59:03 4 Connecting to myrtle.ukc.ac.uk [129.12.3.176]:25 ... connected
14:59:03 4 waiting for data on socket
14:59:03 4 read response data: size=70
14:59:03 4 SMTP<< 220 myrtle.ukc.ac.uk ESMTP Exim 4.60 Tue, 23 Jan 2007 14:59:03 +0000
14:59:03 4 129.12.3.176 in hosts_avoid_esmtp? no (option unset)
14:59:03 4 SMTP>> EHLO re.ukc.ac.uk
14:59:03 4 waiting for data on socket
14:59:03 4 read response data: size=123
14:59:03 4 SMTP<< 250-myrtle.ukc.ac.uk Hello exim at bes.ukc.ac.uk [129.12.4.20]
14:59:03 4 250-SIZE 52428800
14:59:03 4 250-PIPELINING
14:59:03 4 250-STARTTLS
14:59:03 4 250 HELP
14:59:03 4 129.12.3.176 in hosts_avoid_tls? no (option unset)
14:59:03 4 SMTP>> STARTTLS
14:59:03 4 waiting for data on socket
14:59:03 4 read response data: size=18
14:59:03 4 SMTP<< 220 TLS go ahead
14:59:03 4 Initialized TLS
14:59:03 4 Calling SSL_connect
14:59:03 4 SSL info: before/connect initialization
14:59:03 4 SSL info: before/connect initialization
14:59:03 4 SSL info: SSLv2/v3 write client hello A
14:59:03 4 SSL info: SSLv3 read server hello A
14:59:03 4 SSL info: SSLv3 read server certificate A
14:59:03 4 SSL info: SSLv3 read server done A
14:59:03 4 SSL info: SSLv3 write client key exchange A
14:59:03 4 SSL info: SSLv3 write change cipher spec A
14:59:03 4 SSL info: SSLv3 write finished A
14:59:03 4 SSL info: SSLv3 flush data
14:59:03 4 SSL info: SSLv3 read finished A
14:59:03 4 SSL info: SSL negotiation finished successfully
14:59:03 4 SSL info: SSL negotiation finished successfully
14:59:03 4 SSL_connect succeeded
14:59:03 4 Cipher: TLSv1:AES256-SHA:256
14:59:03 4 SMTP>> EHLO re.ukc.ac.uk
14:59:03 4 tls_do_write(ffbfca80, 19)
14:59:03 4 SSL_write(SSL, ffbfca80, 19)
14:59:03 4 outbytes=19 error=0
14:59:03 4 waiting for data on socket
14:59:03 4 Calling SSL_read(28b8e0, ffbfce80, 4096)
14:59:03 4 read response data: size=109
14:59:03 4 SMTP<< 250-myrtle.ukc.ac.uk Hello exim at bes.ukc.ac.uk [129.12.4.20]
14:59:03 4 250-SIZE 52428800
14:59:03 4 250-PIPELINING
14:59:03 4 250 HELP
14:59:03 4 using PIPELINING
14:59:03 4 129.12.3.176 in hosts_require_auth? no (option unset)
14:59:03 4 SMTP>> MAIL FROM:<tdb@???> SIZE=1322
14:59:03 4 SMTP>> RCPT TO:<~tdb@???>
14:59:03 4 SMTP>> DATA
14:59:03 4 tls_do_write(ffbfca80, 77)
14:59:03 4 SSL_write(SSL, ffbfca80, 77)
14:59:03 4 outbytes=77 error=0
14:59:03 4 waiting for data on socket
14:59:03 4 Calling SSL_read(28b8e0, ffbfce80, 4096)
14:59:03 4 read response data: size=8
14:59:03 4 SMTP<< 250 OK
14:59:03 4 waiting for data on socket
14:59:03 4 Calling SSL_read(28b8e0, ffbfce80, 4096)
14:59:03 4 read response data: size=14
14:59:03 4 SMTP<< 250 Accepted
14:59:03 4 waiting for data on socket
14:59:03 4 Calling SSL_read(28b8e0, ffbfce80, 4096)
14:59:03 4 read response data: size=56
14:59:03 4 SMTP<< 354 Enter message, ending with "." on a line by itself
14:59:03 4 SMTP>> writing message and terminating "."
14:59:03 4 writing data block fd=7 size=302 timeout=300
14:59:03 4 tls_do_write(2848d8, 302)
14:59:03 4 SSL_write(SSL, 2848d8, 302)
14:59:03 4 outbytes=302 error=0
14:59:03 4 waiting for data on socket
14:59:03 4 Calling SSL_read(28b8e0, ffbfce80, 4096)
14:59:03 4 read response data: size=28
14:59:03 4 SMTP<< 250 OK id=1H9N71-000274-SR
14:59:03 4 journalling ~tdb@???
14:59:03 4 ok=1 send_quit=1 send_rset=0 continue_more=0 yield=0 first_address is NULL
14:59:03 4 129.12.3.176 in hosts_nopass_tls? no (option unset)
14:59:03 4 transport_check_waiting entered
14:59:03 4 sequence=1 local_max=500 global_max=-1
14:59:03 4 locking /cluster/BackupMX/var/exim/db/wait-remote_smtp.lockfile
14:59:03 4 locked /cluster/BackupMX/var/exim/db/wait-remote_smtp.lockfile
14:59:03 4 EXIM_DBOPEN(/cluster/BackupMX/var/exim/db/wait-remote_smtp)
14:59:03 4 returned from EXIM_DBOPEN
14:59:03 4 opened hints database /cluster/BackupMX/var/exim/db/wait-remote_smtp: flags=O_RDWR
14:59:03 4 dbfn_read: key=myrtle.ukc.ac.uk
14:59:03 4 no messages waiting for myrtle.ukc.ac.uk
14:59:03 4 SMTP>> QUIT
14:59:03 4 tls_do_write(ffbfca80, 6)
14:59:03 4 SSL_write(SSL, ffbfca80, 6)
14:59:03 4 outbytes=6 error=0
14:59:03 4 tls_close(): shutting down SSL
14:59:03 4 SSL info: SSL negotiation finished successfully
14:59:03 4 set_process_info: 4 delivering 1H9N71-0007nq-Il: just tried myrtle.ukc.ac.uk [129.12.3.176] for ~tdb@???: result OK
14:59:03 4 Leaving remote_smtp transport
14:59:03 4 set_process_info: 4 delivering 1H9N71-0007nq-Il (just run remote_smtp for ~tdb@??? in subprocess)
14:59:03 4 search_tidyup called
14:59:03 29999 reading pipe for subprocess 4 (not ended)
14:59:03 29999 read() yielded 149
14:59:03 29999 Z0 item read
14:59:03 29999 remote delivery process 4 ended
14:59:03 29999 set_process_info: 29999 delivering 1H9N71-0007nq-Il
14:59:03 29999 post-process ~tdb@??? (0)
14:59:03 29999 ~tdb@??? delivered
14:59:03 29999 tdb@???: children all complete
14:59:03 29999 LOG: MAIN
14:59:03 29999 => ~tdb@??? <tdb@???> R=host_route T=remote_smtp H=myrtle.ukc.ac.uk [129.12.3.176] X=TLSv1:AES256-SHA:256
14:59:03 29999 >>>>>>>>>>>>>>>> deliveries are done >>>>>>>>>>>>>>>>
14:59:03 29999 changed uid/gid: post-delivery tidying
14:59:03 29999 uid=15614 gid=29001 pid=29999
14:59:03 29999 auxiliary group list: <none>
14:59:03 29999 set_process_info: 29999 tidying up after delivering 1H9N71-0007nq-Il
14:59:03 29999 Processing retry items
14:59:03 29999 Succeeded addresses:
14:59:03 29999 ~tdb@???: no retry items
14:59:03 29999 tdb@???: no retry items
14:59:03 29999 tdb@???: no retry items
14:59:03 29999 Failed addresses:
14:59:03 29999 Deferred addresses:
14:59:03 29999 end of retry processing
14:59:03 29999 LOG: MAIN
14:59:03 29999 Completed
14:59:03 29999 end delivery of 1H9N71-0007nq-Il
14:59:03 29999 search_tidyup called
14:59:03 29999 search_tidyup called
14:59:03 29999 >>>>>>>>>>>>>>>> Exim pid=29999 terminating with rc=0 >>>>>>>>>>>>>>>>
QUIT
14:59:05 29998 SMTP<< QUIT
14:59:05 29998 search_tidyup called
14:59:05 29998 >>>>>>>>>>>>>>>> Exim pid=29998 terminating with rc=0 >>>>>>>>>>>>>>>>
# /usr/local/bin/exim -oMr spam-scanned -C /cluster/BackupMX/etc/exim/configure -d+all tdb@???
15:01:01 259 Exim version 4.66 uid=0 gid=1 pid=259 D=fffdffff
Probably ndbm
Support for: crypteq iconv() OpenSSL
Lookups: lsearch wildlsearch nwildlsearch iplsearch dbm dbmnz mysql
Authenticators: plaintext
Routers: accept dnslookup ipliteral manualroute queryprogram redirect
Transports: appendfile/maildir autoreply pipe smtp
Fixed never_users: 0
Size of off_t: 4
15:01:01 259 changed uid/gid: forcing real = effective
15:01:01 259 uid=0 gid=1 pid=259
15:01:01 259 auxiliary group list: <none>
15:01:01 259 seeking password data for user "root": cache not available
15:01:01 259 getpwnam() succeeded uid=0 gid=1
15:01:01 259 configuration file is /cluster/BackupMX/etc/exim/configure
15:01:01 259 log selectors = 00000ffc 00089001
15:01:01 259 cwd=/home/cur/tdb 7 args: /usr/local/bin/exim -oMr spam-scanned -C /cluster/BackupMX/etc/exim/configure -d+all tdb@???
15:01:01 259 trusted user
15:01:01 259 admin user
15:01:01 259 changed uid/gid: privilege not needed
15:01:01 259 uid=15614 gid=29001 pid=259
15:01:01 259 auxiliary group list: 29001
15:01:01 259 expanding: $1
15:01:01 259 result: Super-User
15:01:01 259 user name "Super-User" extracted from gecos field "Super-User"
15:01:01 259 originator: uid=0 gid=1 login=root name=Super-User
15:01:01 259 sender address = root@???
15:01:01 259 set_process_info: 259 accepting a local non-SMTP message from <root@???>
15:01:01 259 Sender: root@???
15:01:01 259 Recipients:
15:01:01 259 tdb@???
15:01:01 259 using ACL "acl_not_smtp_start"
15:01:01 259 processing "accept"
15:01:01 259 check control = suppress_local_fixups
15:01:01 259 accept: condition test succeeded
15:01:01 259 search_tidyup called
test
.
15:01:05 259 >>Headers received:
15:01:05 259
15:01:05 259 search_tidyup called
15:01:05 259 >>Headers after rewriting and local additions:
15:01:05 259
15:01:05 259 Data file written for message 1H9N8v-00004B-Fw
15:01:05 259 expanding: ${tod_full}
15:01:05 259 result: Tue, 23 Jan 2007 15:01:05 +0000
15:01:05 259 condition: def:sender_rcvhost
15:01:05 259 result: false
15:01:05 259 expanding: from $sender_rcvhost
15:01:05 259
15:01:05 259 result: from
15:01:05 259
15:01:05 259 skipping: result is not used
15:01:05 259 condition: def:sender_ident
15:01:05 259 result: true
15:01:05 259 expanding: $sender_ident
15:01:05 259 result: root
15:01:05 259 expanding: from ${quote_local_part:$sender_ident}
15:01:05 259 result: from root
15:01:05 259 condition: def:sender_helo_name
15:01:05 259 result: false
15:01:05 259 expanding: (helo=$sender_helo_name)
15:01:05 259
15:01:05 259 result: (helo=)
15:01:05 259
15:01:05 259 skipping: result is not used
15:01:05 259 expanding: ${if def:sender_ident {from ${quote_local_part:$sender_ident} }}${if def:sender_helo_name {(helo=$sender_helo_name)
15:01:05 259 }}
15:01:05 259 result: from root
15:01:05 259 condition: def:received_protocol
15:01:05 259 result: true
15:01:05 259 expanding: with $received_protocol
15:01:05 259 result: with spam-scanned
15:01:05 259 condition: def:tls_cipher
15:01:05 259 result: false
15:01:05 259 expanding: ($tls_cipher)
15:01:05 259
15:01:05 259 result: ()
15:01:05 259
15:01:05 259 skipping: result is not used
15:01:05 259 condition: def:sender_address
15:01:05 259 result: true
15:01:05 259 expanding: (envelope-from <$sender_address>)
15:01:05 259
15:01:05 259 result: (envelope-from <root@???>)
15:01:05 259
15:01:05 259 condition: def:received_for
15:01:05 259 result: true
15:01:05 259 expanding:
15:01:05 259 for $received_for
15:01:05 259 result:
15:01:05 259 for tdb@???
15:01:05 259 expanding: Received: ${if def:sender_rcvhost {from $sender_rcvhost
15:01:05 259 }{${if def:sender_ident {from ${quote_local_part:$sender_ident} }}${if def:sender_helo_name {(helo=$sender_helo_name)
15:01:05 259 }}}}by $primary_hostname ${if def:received_protocol {with $received_protocol}} ${if def:tls_cipher {($tls_cipher)
15:01:05 259 }}(Exim $version_number)
15:01:05 259 ${if def:sender_address {(envelope-from <$sender_address>)
15:01:05 259 }}id $message_exim_id${if def:received_for {
15:01:05 259 for $received_for}}
15:01:05 259 result: Received: from root by re.ukc.ac.uk with spam-scanned (Exim 4.66)
15:01:05 259 (envelope-from <root@???>)
15:01:05 259 id 1H9N8v-00004B-Fw
15:01:05 259 for tdb@???
15:01:05 259 >>Generated Received: header line
15:01:05 259 P Received: from root by re.ukc.ac.uk with spam-scanned (Exim 4.66)
15:01:05 259 (envelope-from <root@???>)
15:01:05 259 id 1H9N8v-00004B-Fw
15:01:05 259 for tdb@???; Tue, 23 Jan 2007 15:01:05 +0000
15:01:05 259 calling local_scan(); timeout=300
15:01:05 259 local_scan() returned 0 NULL
15:01:05 259 expanding: ${tod_full}
15:01:05 259 result: Tue, 23 Jan 2007 15:01:05 +0000
15:01:05 259 Writing spool header file
15:01:05 259 Size of headers = 181
15:01:05 259 LOG: MAIN
15:01:05 259 <= root@??? U=root P=spam-scanned S=187
15:01:05 259 search_tidyup called
15:01:05 259 search_tidyup called
15:01:05 259 >>>>>>>>>>>>>>>> Exim pid=259 terminating with rc=0 >>>>>>>>>>>>>>>>
15:01:05 265 exec /usr/local/bin/exim -C /cluster/BackupMX/etc/exim/configure -d=0xfffdffff -Mc 1H9N8v-00004B-Fw
root@?[1mbes?[m [/home/cur/tdb] # 15:01:05 265 Exim version 4.66 uid=15614 gid=29001 pid=265 D=fffdffff
Probably ndbm
Support for: crypteq iconv() OpenSSL
Lookups: lsearch wildlsearch nwildlsearch iplsearch dbm dbmnz mysql
Authenticators: plaintext
Routers: accept dnslookup ipliteral manualroute queryprogram redirect
Transports: appendfile/maildir autoreply pipe smtp
Fixed never_users: 0
Size of off_t: 4
15:01:05 265 changed uid/gid: forcing real = effective
15:01:05 265 uid=0 gid=29001 pid=265
15:01:05 265 auxiliary group list: <none>
15:01:05 265 seeking password data for user "root": cache not available
15:01:05 265 getpwnam() succeeded uid=0 gid=1
15:01:05 265 configuration file is /cluster/BackupMX/etc/exim/configure
15:01:05 265 log selectors = 00000ffc 00089001
15:01:05 265 cwd=/cluster/BackupMX/var/exim 6 args: /usr/local/bin/exim -C /cluster/BackupMX/etc/exim/configure -d=0xfffdffff -Mc 1H9N8v-00004B-Fw
15:01:05 265 trusted user
15:01:05 265 admin user
15:01:05 265 skipping ACL configuration - not needed
15:01:05 265 set_process_info: 265 delivering specified messages
15:01:05 265 set_process_info: 265 delivering 1H9N8v-00004B-Fw
15:01:05 265 reading spool file 1H9N8v-00004B-Fw-H
15:01:05 265 user=root uid=0 gid=1 sender=root@???
15:01:05 265 sender_local=1 ident=root
15:01:05 265 Non-recipients:
15:01:05 265 Empty Tree
15:01:05 265 ---- End of tree ----
15:01:05 265 recipients_count=1
15:01:05 265 body_linecount=1 message_linecount=4
15:01:05 265 Delivery address list:
15:01:05 265 tdb@???
15:01:05 265 locking /cluster/BackupMX/var/exim/db/retry.lockfile
15:01:05 265 locked /cluster/BackupMX/var/exim/db/retry.lockfile
15:01:05 265 EXIM_DBOPEN(/cluster/BackupMX/var/exim/db/retry)
15:01:05 265 returned from EXIM_DBOPEN
15:01:05 265 opened hints database /cluster/BackupMX/var/exim/db/retry: flags=O_RDONLY
15:01:05 265 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
15:01:05 265 Considering: tdb@???
15:01:05 265 unique = tdb@???
15:01:05 265 dbfn_read: key=R:mx.cs.kent.ac.uk
15:01:05 265 dbfn_read: key=R:tdb@???
15:01:05 265 dbfn_read: key=R:tdb@???:<root@???>
15:01:05 265 no domain retry record
15:01:05 265 no address retry record
15:01:05 265 tdb@???: queued for routing
15:01:05 265 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
15:01:05 265 routing tdb@???
15:01:05 265 --------> global_aliases router <--------
15:01:05 265 local_part=tdb domain=mx.cs.kent.ac.uk
15:01:05 265 checking domains
15:01:05 265 mx.cs.kent.ac.uk in "cstest.kent.ac.uk : *.cstest.kent.ac.uk"? no (end of list)
15:01:05 265 mx.cs.kent.ac.uk in "ukc.ac.uk : kent.ac.uk"? no (end of list)
15:01:05 265 mx.cs.kent.ac.uk in "*.ukc.ac.uk : *.kent.ac.uk"? yes (matched "*.kent.ac.uk")
15:01:05 265 mx.cs.kent.ac.uk in "!+ignore_domains : +kent_domains : +kent_hosts"? yes (matched "+kent_hosts")
15:01:05 265 calling global_aliases router
15:01:05 265 rda_interpret (string): ${lookup{${sg{$local_part}{^~}{}}}lsearch{/etc/aliases}}
15:01:05 265 expanding: $local_part
15:01:05 265 result: tdb
15:01:05 265 expanding: ^~
15:01:05 265 result: ^~
15:01:05 265 expanding:
15:01:05 265 result:
15:01:05 265 expanding: ${sg{$local_part}{^~}{}}
15:01:05 265 result: tdb
15:01:05 265 expanding: /etc/aliases
15:01:05 265 result: /etc/aliases
15:01:05 265 search_open: lsearch "/etc/aliases"
15:01:05 265 search_find: file="/etc/aliases"
15:01:05 265 key="tdb" partial=-1 affix=NULL starflags=0
15:01:05 265 LRU list:
15:01:05 265 :/etc/aliases
15:01:05 265 End
15:01:05 265 internal_search_find: file="/etc/aliases"
15:01:05 265 type=lsearch key="tdb"
15:01:05 265 file lookup required for tdb
15:01:05 265 in /etc/aliases
15:01:05 265 lookup failed
15:01:05 265 expanding: ${lookup{${sg{$local_part}{^~}{}}}lsearch{/etc/aliases}}
15:01:05 265 result:
15:01:05 265 expanded:
15:01:05 265 file is not a filter file
15:01:05 265 parse_forward_list:
15:01:05 265 global_aliases router declined for tdb@???
15:01:05 265 --------> host_route router <--------
15:01:05 265 local_part=tdb domain=mx.cs.kent.ac.uk
15:01:05 265 checking domains
15:01:05 265 cached no match for +kent_domains
15:01:05 265 cached lookup data = NULL
15:01:05 265 mx.cs.kent.ac.uk in "mx.cs.ukc.ac.uk : mx.cs.kent.ac.uk : cs.ukc.ac.uk : cs.kent.ac.uk"? yes (matched "mx.cs.kent.ac.uk")
15:01:05 265 mx.cs.kent.ac.uk in "!+kent_domains : !+mx_domains : !+local_domains : +kent_hosts"? no (matched "!+mx_domains")
15:01:05 265 host_route router skipped: domains mismatch
15:01:05 265 --------> hub_route router <--------
15:01:05 265 local_part=tdb domain=mx.cs.kent.ac.uk
15:01:05 265 checking domains
15:01:05 265 mx.cs.kent.ac.uk in "@ : re.ukc.ac.uk : re.kent.ac.uk"? no (end of list)
15:01:05 265 cached yes match for +mx_domains
15:01:05 265 cached lookup data = NULL
15:01:05 265 mx.cs.kent.ac.uk in "!+local_domains : !+mx_domains"? no (matched "!+mx_domains" - cached)
15:01:05 265 hub_route router skipped: domains mismatch
15:01:05 265 --------> spamcheck_route router <--------
15:01:05 265 local_part=tdb domain=mx.cs.kent.ac.uk
15:01:05 265 checking "condition"
15:01:05 265 expanding: $received_protocol
15:01:05 265 result: spam-scanned
15:01:05 265 expanding: spam-scanned
15:01:05 265 result: spam-scanned
15:01:05 265 expanding: $received_protocol
15:01:05 265 result:
15:01:05 265 skipping: result is not used
15:01:05 265 expanding: local
15:01:05 265 result: local
15:01:05 265 skipping: result is not used
15:01:05 265 condition: and {{!eq {$received_protocol}{spam-scanned}} {!eq {$received_protocol}{local}}}
15:01:05 265 result: false
15:01:05 265 expanding: 1
15:01:05 265 result: 1
15:01:05 265 skipping: result is not used
15:01:05 265 expanding: 0
15:01:05 265 result: 0
15:01:05 265 expanding: ${if and {{!eq {$received_protocol}{spam-scanned}} {!eq {$received_protocol}{local}}} {1}{0}}
15:01:05 265 result: 0
15:01:05 265 spamcheck_route router skipped: condition failure
15:01:05 265 --------> mx_route router <--------
15:01:05 265 local_part=tdb domain=mx.cs.kent.ac.uk
15:01:05 265 checking domains
15:01:05 265 cached yes match for +mx_domains
15:01:05 265 cached lookup data = NULL
15:01:05 265 mx.cs.kent.ac.uk in "+mx_domains"? yes (matched "+mx_domains" - cached)
15:01:05 265 calling mx_route router
15:01:05 265 rda_interpret (string): ${sg{${lookup mysql{select alias from mx_aliases where login='${sg{${quote_mysql:$local_part}}{^~}{}}'}{$value}fail}}{^([^@]+)(@.*)?\$}{\$1$local_part_suffix\$2}}
15:01:05 265 expanding: $local_part
15:01:05 265 result: tdb
15:01:05 265 expanding: ${quote_mysql:$local_part}
15:01:05 265 result: tdb
15:01:05 265 expanding: ^~
15:01:05 265 result: ^~
15:01:05 265 expanding:
15:01:05 265 result:
15:01:05 265 expanding: select alias from mx_aliases where login='${sg{${quote_mysql:$local_part}}{^~}{}}'
15:01:05 265 result: select alias from mx_aliases where login='tdb'
15:01:05 265 search_open: mysql "NULL"
15:01:05 265 search_find: file="NULL"
15:01:05 265 key="select alias from mx_aliases where login='tdb'" partial=-1 affix=NULL starflags=0
15:01:05 265 LRU list:
15:01:05 265 :/etc/aliases
15:01:05 265 End
15:01:05 265 internal_search_find: file="NULL"
15:01:05 265 type=mysql key="select alias from mx_aliases where login='tdb'"
15:01:05 265 database lookup required for select alias from mx_aliases where login='tdb'
15:01:05 265 MYSQL query: select alias from mx_aliases where login='tdb'
15:01:05 265 MYSQL new connection: host=maildb.cs.ukc.ac.uk port=0 socket=NULL database=exim user=exim
15:01:05 265 lookup yielded: ~tdb@???
15:01:05 265 expanding: $value
15:01:05 265 result: ~tdb@???
15:01:05 265 expanding: ${lookup mysql{select alias from mx_aliases where login='${sg{${quote_mysql:$local_part}}{^~}{}}'}{$value}fail}
15:01:05 265 result: ~tdb@???
15:01:05 265 expanding: ^([^@]+)(@.*)?\$
15:01:05 265 result: ^([^@]+)(@.*)?$
15:01:05 265 expanding: \$1$local_part_suffix\$2
15:01:05 265 result: $1$2
15:01:05 265 expanding: $1$2
15:01:05 265 result: ~tdb@???
15:01:05 265 expanding: ${sg{${lookup mysql{select alias from mx_aliases where login='${sg{${quote_mysql:$local_part}}{^~}{}}'}{$value}fail}}{^([^@]+)(@.*)?\$}{\$1$local_part_suffix\$2}}
15:01:05 265 result: ~tdb@???
15:01:05 265 expanded: ~tdb@???
15:01:05 265 file is not a filter file
15:01:05 265 parse_forward_list: ~tdb@???
15:01:05 265 extract item: ~tdb@???
15:01:05 265 mx_route router generated ~tdb@???
15:01:05 265 errors_to=NULL transport=NULL
15:01:05 265 uid=unset gid=unset home=NULL
15:01:05 265 routed by mx_route router
15:01:05 265 envelope to: tdb@???
15:01:05 265 transport: <none>
15:01:05 265 locking /cluster/BackupMX/var/exim/db/retry.lockfile
15:01:05 265 locked /cluster/BackupMX/var/exim/db/retry.lockfile
15:01:05 265 EXIM_DBOPEN(/cluster/BackupMX/var/exim/db/retry)
15:01:05 265 returned from EXIM_DBOPEN
15:01:05 265 opened hints database /cluster/BackupMX/var/exim/db/retry: flags=O_RDONLY
15:01:05 265 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
15:01:05 265 Considering: ~tdb@???
15:01:05 265 unique = ~tdb@???
15:01:05 265 dbfn_read: key=R:myrtle.ukc.ac.uk
15:01:05 265 dbfn_read: key=R:~tdb@???
15:01:05 265 dbfn_read: key=R:~tdb@???:<root@???>
15:01:05 265 no domain retry record
15:01:05 265 no address retry record
15:01:05 265 ~tdb@???: queued for routing
15:01:05 265 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
15:01:05 265 routing ~tdb@???
15:01:05 265 --------> global_aliases router <--------
15:01:05 265 local_part=~tdb domain=myrtle.ukc.ac.uk
15:01:05 265 checking domains
15:01:05 265 myrtle.ukc.ac.uk in "cstest.kent.ac.uk : *.cstest.kent.ac.uk"? no (end of list)
15:01:05 265 myrtle.ukc.ac.uk in "ukc.ac.uk : kent.ac.uk"? no (end of list)
15:01:05 265 myrtle.ukc.ac.uk in "*.ukc.ac.uk : *.kent.ac.uk"? yes (matched "*.ukc.ac.uk")
15:01:05 265 myrtle.ukc.ac.uk in "!+ignore_domains : +kent_domains : +kent_hosts"? yes (matched "+kent_hosts")
15:01:05 265 calling global_aliases router
15:01:05 265 rda_interpret (string): ${lookup{${sg{$local_part}{^~}{}}}lsearch{/etc/aliases}}
15:01:05 265 expanding: $local_part
15:01:05 265 result: ~tdb
15:01:05 265 expanding: ^~
15:01:05 265 result: ^~
15:01:05 265 expanding:
15:01:05 265 result:
15:01:05 265 expanding: ${sg{$local_part}{^~}{}}
15:01:05 265 result: tdb
15:01:05 265 expanding: /etc/aliases
15:01:05 265 result: /etc/aliases
15:01:05 265 search_open: lsearch "/etc/aliases"
15:01:05 265 cached open
15:01:05 265 search_find: file="/etc/aliases"
15:01:05 265 key="tdb" partial=-1 affix=NULL starflags=0
15:01:05 265 LRU list:
15:01:05 265 :/etc/aliases
15:01:05 265 End
15:01:05 265 internal_search_find: file="/etc/aliases"
15:01:05 265 type=lsearch key="tdb"
15:01:05 265 cached data used for lookup of tdb
15:01:05 265 in /etc/aliases
15:01:05 265 lookup failed
15:01:05 265 expanding: ${lookup{${sg{$local_part}{^~}{}}}lsearch{/etc/aliases}}
15:01:05 265 result:
15:01:05 265 expanded:
15:01:05 265 file is not a filter file
15:01:05 265 parse_forward_list:
15:01:05 265 global_aliases router declined for ~tdb@???
15:01:05 265 --------> host_route router <--------
15:01:05 265 local_part=~tdb domain=myrtle.ukc.ac.uk
15:01:05 265 checking domains
15:01:05 265 cached no match for +kent_domains
15:01:05 265 cached lookup data = NULL
15:01:05 265 myrtle.ukc.ac.uk in "mx.cs.ukc.ac.uk : mx.cs.kent.ac.uk : cs.ukc.ac.uk : cs.kent.ac.uk"? no (end of list)
15:01:05 265 myrtle.ukc.ac.uk in "@ : re.ukc.ac.uk : re.kent.ac.uk"? no (end of list)
15:01:05 265 cached yes match for +kent_hosts
15:01:05 265 cached lookup data = NULL
15:01:05 265 myrtle.ukc.ac.uk in "!+kent_domains : !+mx_domains : !+local_domains : +kent_hosts"? yes (matched "+kent_hosts" - cached)
15:01:05 265 calling host_route router
15:01:05 265 host_route router called for ~tdb@???
15:01:05 265 domain = myrtle.ukc.ac.uk
;; res_nquerydomain(myrtle.ukc.ac.uk, <Nil>, 1, 15)
;; res_query(myrtle.ukc.ac.uk, 1, 15)
;; res_nmkquery(QUERY, myrtle.ukc.ac.uk, IN, MX)
;; res_send()
;; ->>HEADER<<- opcode: QUERY, status: NOERROR, id: 1149
;; flags: rd; QUERY: 1, ANSWER: 0, AUTHORITY: 0, ADDITIONAL: 0
;; myrtle.ukc.ac.uk, type = MX, class = IN
;; Querying server (# 1) address = 129.12.4.56
;; new DG socket
;; got answer:
;; ->>HEADER<<- opcode: QUERY, status: NOERROR, id: 1149
;; flags: qr aa rd ra; QUERY: 1, ANSWER: 0, AUTHORITY: 1, ADDITIONAL: 0
;; myrtle.ukc.ac.uk, type = MX, class = IN
ukc.ac.uk. 2H IN SOA dns0.ukc.ac.uk. network-support.ukc.ac.uk. (
103705 ; serial
1H ; refresh
30M ; retry
1W ; expiry
1D ) ; minimum
;; rcode = 0, ancount=0
15:01:05 265 DNS lookup of myrtle.ukc.ac.uk (MX) gave NO_DATA
15:01:05 265 returning DNS_NODATA
;; res_nquerydomain(myrtle.ukc.ac.uk, <Nil>, 1, 1)
;; res_query(myrtle.ukc.ac.uk, 1, 1)
;; res_nmkquery(QUERY, myrtle.ukc.ac.uk, IN, A)
;; res_send()
;; ->>HEADER<<- opcode: QUERY, status: NOERROR, id: 1150
;; flags: rd; QUERY: 1, ANSWER: 0, AUTHORITY: 0, ADDITIONAL: 0
;; myrtle.ukc.ac.uk, type = A, class = IN
;; Querying server (# 1) address = 129.12.4.56
;; new DG socket
;; got answer:
;; ->>HEADER<<- opcode: QUERY, status: NOERROR, id: 1150
;; flags: qr aa rd ra; QUERY: 1, ANSWER: 1, AUTHORITY: 3, ADDITIONAL: 4
;; myrtle.ukc.ac.uk, type = A, class = IN
myrtle.ukc.ac.uk. 2H IN A 129.12.3.176
ukc.ac.uk. 2H IN NS dns1.ukc.ac.uk.
ukc.ac.uk. 2H IN NS cancer.ucs.ed.ac.uk.
ukc.ac.uk. 2H IN NS dns0.ukc.ac.uk.
dns0.ukc.ac.uk. 2H IN A 129.12.21.8
dns1.ukc.ac.uk. 2H IN A 129.12.21.3
cancer.ucs.ed.ac.uk. 5h22m55s IN A 129.215.166.13
cancer.ucs.ed.ac.uk. 5h22m55s IN A 129.215.200.7
15:01:05 265 DNS lookup of myrtle.ukc.ac.uk (A) succeeded
15:01:05 265 Actual local interface address is 127.0.0.1 (lo0)
15:01:05 265 Actual local interface address is 129.12.4.21 (bge0)
15:01:05 265 Actual local interface address is 129.12.4.20 (bge0:1)
15:01:05 265 Actual local interface address is 129.12.4.51 (bge0:2)
15:01:05 265 Actual local interface address is 129.12.4.50 (bge0:3)
15:01:05 265 Actual local interface address is 129.12.4.10 (bge0:4)
15:01:05 265 Actual local interface address is 129.12.4.62 (bge0:7)
15:01:05 265 Actual local interface address is 129.12.4.22 (ce0)
15:01:05 265 fully qualified name = myrtle.ukc.ac.uk
15:01:05 265 myrtle.ukc.ac.uk 129.12.3.176 mx=-1 sort=-426
15:01:05 265 set transport remote_smtp
15:01:05 265 queued for remote_smtp transport: local_part = ~tdb
15:01:05 265 domain = myrtle.ukc.ac.uk
15:01:05 265 errors_to=NULL
15:01:05 265 domain_data=NULL localpart_data=NULL
15:01:05 265 routed by host_route router
15:01:05 265 envelope to: ~tdb@???
15:01:05 265 transport: remote_smtp
15:01:05 265 host myrtle.ukc.ac.uk [129.12.3.176]
15:01:05 265 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
15:01:05 265 After routing:
15:01:05 265 Local deliveries:
15:01:05 265 Remote deliveries:
15:01:05 265 ~tdb@???
15:01:05 265 Failed addresses:
15:01:05 265 Deferred addresses:
15:01:05 265 search_tidyup called
15:01:05 265 close MYSQL connection: maildb.cs.ukc.ac.uk/exim/exim
15:01:05 265 >>>>>>>>>>>>>>>> Remote deliveries >>>>>>>>>>>>>>>>
15:01:05 265 --------> ~tdb@??? <--------
15:01:05 265 search_tidyup called
15:01:05 266 changed uid/gid: remote delivery to ~tdb@??? with transport=remote_smtp
15:01:05 266 uid=15614 gid=29001 pid=266
15:01:05 266 auxiliary group list: <none>
15:01:05 265 set_process_info: 265 delivering 1H9N8v-00004B-Fw: waiting for a remote delivery subprocess to finish
15:01:05 265 selecting on subprocess pipes
15:01:05 266 set_process_info: 266 delivering 1H9N8v-00004B-Fw using remote_smtp
15:01:05 266 remote_smtp transport entered
15:01:05 266 ~tdb@???
15:01:05 266 myrtle.ukc.ac.uk in queue_smtp_domains? no (option unset)
15:01:05 266 checking status of myrtle.ukc.ac.uk
15:01:05 266 locking /cluster/BackupMX/var/exim/db/retry.lockfile
15:01:05 266 locked /cluster/BackupMX/var/exim/db/retry.lockfile
15:01:05 266 EXIM_DBOPEN(/cluster/BackupMX/var/exim/db/retry)
15:01:05 266 returned from EXIM_DBOPEN
15:01:05 266 opened hints database /cluster/BackupMX/var/exim/db/retry: flags=O_RDONLY
15:01:05 266 dbfn_read: key=T:myrtle.ukc.ac.uk:129.12.3.176
15:01:05 266 dbfn_read: key=T:myrtle.ukc.ac.uk:129.12.3.176:1H9N8v-00004B-Fw
15:01:05 266 no host retry record
15:01:05 266 no message retry record
15:01:05 266 myrtle.ukc.ac.uk [129.12.3.176] status = usable
15:01:05 266 129.12.3.176 in serialize_hosts? no (option unset)
15:01:05 266 delivering 1H9N8v-00004B-Fw to myrtle.ukc.ac.uk [129.12.3.176] (~tdb@???)
15:01:05 266 set_process_info: 266 delivering 1H9N8v-00004B-Fw to myrtle.ukc.ac.uk [129.12.3.176] (~tdb@???)
15:01:05 266 expanding: $primary_hostname
15:01:05 266 result: re.ukc.ac.uk
15:01:05 266 Connecting to myrtle.ukc.ac.uk [129.12.3.176]:25 ... connected
15:01:05 266 waiting for data on socket
15:01:05 266 read response data: size=70
15:01:05 266 SMTP<< 220 myrtle.ukc.ac.uk ESMTP Exim 4.60 Tue, 23 Jan 2007 15:01:05 +0000
15:01:05 266 129.12.3.176 in hosts_avoid_esmtp? no (option unset)
15:01:05 266 SMTP>> EHLO re.ukc.ac.uk
15:01:05 266 waiting for data on socket
15:01:05 266 read response data: size=123
15:01:05 266 SMTP<< 250-myrtle.ukc.ac.uk Hello exim at bes.ukc.ac.uk [129.12.4.20]
15:01:05 266 250-SIZE 52428800
15:01:05 266 250-PIPELINING
15:01:05 266 250-STARTTLS
15:01:05 266 250 HELP
15:01:05 266 129.12.3.176 in hosts_avoid_tls? no (option unset)
15:01:05 266 SMTP>> STARTTLS
15:01:05 266 waiting for data on socket
15:01:05 266 read response data: size=18
15:01:05 266 SMTP<< 220 TLS go ahead
15:01:05 266 Initialized TLS
15:01:05 266 Calling SSL_connect
15:01:05 266 SSL info: before/connect initialization
15:01:05 266 SSL info: before/connect initialization
15:01:05 266 SSL info: SSLv2/v3 write client hello A
15:01:05 266 SSL info: SSLv3 read server hello A
15:01:05 266 SSL info: SSLv3 read server certificate A
15:01:05 266 SSL info: SSLv3 read server done A
15:01:05 266 SSL info: SSLv3 write client key exchange A
15:01:05 266 SSL info: SSLv3 write change cipher spec A
15:01:05 266 SSL info: SSLv3 write finished A
15:01:05 266 SSL info: SSLv3 flush data
15:01:05 266 SSL info: SSLv3 read finished A
15:01:05 266 SSL info: SSL negotiation finished successfully
15:01:05 266 SSL info: SSL negotiation finished successfully
15:01:05 266 SSL_connect succeeded
15:01:05 266 Cipher: TLSv1:AES256-SHA:256
15:01:05 266 SMTP>> EHLO re.ukc.ac.uk
15:01:05 266 tls_do_write(ffbfca80, 19)
15:01:05 266 SSL_write(SSL, ffbfca80, 19)
15:01:05 266 outbytes=19 error=0
15:01:05 266 waiting for data on socket
15:01:05 266 Calling SSL_read(28b8e0, ffbfce80, 4096)
15:01:05 266 read response data: size=109
15:01:05 266 SMTP<< 250-myrtle.ukc.ac.uk Hello exim at bes.ukc.ac.uk [129.12.4.20]
15:01:05 266 250-SIZE 52428800
15:01:05 266 250-PIPELINING
15:01:05 266 250 HELP
15:01:05 266 using PIPELINING
15:01:05 266 129.12.3.176 in hosts_require_auth? no (option unset)
15:01:05 266 SMTP>> MAIL FROM:<root@???> SIZE=1216
15:01:05 266 SMTP>> RCPT TO:<~tdb@???>
15:01:05 266 SMTP>> DATA
15:01:05 266 tls_do_write(ffbfca80, 78)
15:01:05 266 SSL_write(SSL, ffbfca80, 78)
15:01:05 266 outbytes=78 error=0
15:01:05 266 waiting for data on socket
15:01:05 266 Calling SSL_read(28b8e0, ffbfce80, 4096)
15:01:05 266 read response data: size=8
15:01:05 266 SMTP<< 250 OK
15:01:05 266 waiting for data on socket
15:01:05 266 Calling SSL_read(28b8e0, ffbfce80, 4096)
15:01:05 266 read response data: size=14
15:01:05 266 SMTP<< 250 Accepted
15:01:05 266 waiting for data on socket
15:01:05 266 Calling SSL_read(28b8e0, ffbfce80, 4096)
15:01:05 266 read response data: size=56
15:01:05 266 SMTP<< 354 Enter message, ending with "." on a line by itself
15:01:05 266 SMTP>> writing message and terminating "."
15:01:05 266 writing data block fd=7 size=196 timeout=300
15:01:05 266 tls_do_write(2848d8, 196)
15:01:05 266 SSL_write(SSL, 2848d8, 196)
15:01:05 266 outbytes=196 error=0
15:01:05 266 waiting for data on socket
15:01:05 266 Calling SSL_read(28b8e0, ffbfce80, 4096)
15:01:05 266 read response data: size=28
15:01:05 266 SMTP<< 250 OK id=1H9N8z-0002dD-Lk
15:01:05 266 journalling ~tdb@???
15:01:05 266 ok=1 send_quit=1 send_rset=0 continue_more=0 yield=0 first_address is NULL
15:01:05 266 129.12.3.176 in hosts_nopass_tls? no (option unset)
15:01:05 266 transport_check_waiting entered
15:01:05 266 sequence=1 local_max=500 global_max=-1
15:01:05 266 locking /cluster/BackupMX/var/exim/db/wait-remote_smtp.lockfile
15:01:05 266 locked /cluster/BackupMX/var/exim/db/wait-remote_smtp.lockfile
15:01:05 266 EXIM_DBOPEN(/cluster/BackupMX/var/exim/db/wait-remote_smtp)
15:01:05 266 returned from EXIM_DBOPEN
15:01:05 266 opened hints database /cluster/BackupMX/var/exim/db/wait-remote_smtp: flags=O_RDWR
15:01:05 266 dbfn_read: key=myrtle.ukc.ac.uk
15:01:05 266 no messages waiting for myrtle.ukc.ac.uk
15:01:05 266 SMTP>> QUIT
15:01:05 266 tls_do_write(ffbfca80, 6)
15:01:05 266 SSL_write(SSL, ffbfca80, 6)
15:01:05 266 outbytes=6 error=0
15:01:05 266 tls_close(): shutting down SSL
15:01:05 266 SSL info: SSL negotiation finished successfully
15:01:05 266 set_process_info: 266 delivering 1H9N8v-00004B-Fw: just tried myrtle.ukc.ac.uk [129.12.3.176] for ~tdb@???: result OK
15:01:05 266 Leaving remote_smtp transport
15:01:05 266 set_process_info: 266 delivering 1H9N8v-00004B-Fw (just run remote_smtp for ~tdb@??? in subprocess)
15:01:05 266 search_tidyup called
15:01:05 265 reading pipe for subprocess 266 (not ended)
15:01:05 265 read() yielded 149
15:01:05 265 Z0 item read
15:01:05 265 remote delivery process 266 ended
15:01:05 265 set_process_info: 265 delivering 1H9N8v-00004B-Fw
15:01:05 265 post-process ~tdb@??? (0)
15:01:05 265 ~tdb@??? delivered
15:01:05 265 tdb@???: children all complete
15:01:05 265 LOG: MAIN
15:01:05 265 => ~tdb@??? <tdb@???> R=host_route T=remote_smtp H=myrtle.ukc.ac.uk [129.12.3.176] X=TLSv1:AES256-SHA:256
15:01:05 265 >>>>>>>>>>>>>>>> deliveries are done >>>>>>>>>>>>>>>>
15:01:05 265 changed uid/gid: post-delivery tidying
15:01:05 265 uid=15614 gid=29001 pid=265
15:01:05 265 auxiliary group list: <none>
15:01:05 265 set_process_info: 265 tidying up after delivering 1H9N8v-00004B-Fw
15:01:05 265 Processing retry items
15:01:05 265 Succeeded addresses:
15:01:05 265 ~tdb@???: no retry items
15:01:05 265 tdb@???: no retry items
15:01:05 265 tdb@???: no retry items
15:01:05 265 Failed addresses:
15:01:05 265 Deferred addresses:
15:01:05 265 end of retry processing
15:01:05 265 LOG: MAIN
15:01:05 265 Completed
15:01:05 265 end delivery of 1H9N8v-00004B-Fw
15:01:05 265 search_tidyup called
15:01:05 265 search_tidyup called
15:01:05 265 >>>>>>>>>>>>>>>> Exim pid=265 terminating with rc=0 >>>>>>>>>>>>>>>>
