On Wed, 2007-05-16 at 15:11 +0100, Graeme Fowler wrote:
> On Wed, 2007-05-16 at 09:07 -0500, Michael Sullivan wrote:
> > Here's another transaction that theoretically should work even if
> > catherine doesn't have a public MX record:
> <snip>
>
> 1. Please keep the quoting to a minimum, guys.
>
> 2. run "exim -d+all-memory -bhc 127.0.0.1" and hand-craft the same SMTP
> session. Then you'll see all the debug output, and see where in your
> ACLs or routers that the verification fails.
>
> Graeme
catherine exim # exim -d+all-memory -bhc 127.0.0.1
09:17:14 10580 Exim version 4.67 uid=0 gid=0 pid=10580 D=fffdffff
Berkeley DB: Sleepycat Software: Berkeley DB 4.3.29: (September 6,
2005)
Support for: crypteq iconv() PAM Perl TCPwrappers OpenSSL
Content_Scanning Old_Demime
Lookups: lsearch wildlsearch nwildlsearch iplsearch cdb dbm dbmnz
dsearch ldap ldapdn ldapm mysql passwd
Authenticators: cram_md5 cyrus_sasl plaintext spa
Routers: accept dnslookup ipliteral manualroute queryprogram redirect
Transports: appendfile/maildir/mailstore autoreply pipe smtp
Fixed never_users: 0
Size of off_t: 4
09:17:14 10580 changed uid/gid: forcing real = effective
09:17:14 10580 uid=0 gid=0 pid=10580
09:17:14 10580 auxiliary group list: <none>
09:17:14 10580 seeking password data for user "root": cache not
available
09:17:14 10580 getpwnam() succeeded uid=0 gid=0
09:17:14 10580 configuration file is /etc/exim/exim.conf
09:17:14 10580 log selectors = 00000ffc 00212001
09:17:14 10580 trusted user
09:17:14 10580 admin user
09:17:14 10580 changed uid/gid: privilege not needed
09:17:14 10580 uid=8 gid=12 pid=10580
09:17:14 10580 auxiliary group list: 12
09:17:14 10580 originator: uid=0 gid=0 login=root name=root
09:17:14 10580 sender address = root@???
09:17:14 10580 sender_fullhost = [127.0.0.1]
09:17:14 10580 sender_rcvhost = [127.0.0.1]
**** SMTP testing session as if from host 127.0.0.1
**** but without any ident (RFC 1413) callback.
**** This is not for real!
09:17:14 10580 host in hosts_connection_nolog? no (option unset)
09:17:14 10580 LOG: smtp_connection MAIN
09:17:14 10580 SMTP connection from [127.0.0.1]
09:17:14 10580 host in host_lookup? yes (matched "*")
09:17:14 10580 looking up host name for 127.0.0.1
09:17:14 10580 DNS lookup of 1.0.0.127.in-addr.arpa (PTR) succeeded
09:17:14 10580 IP address lookup yielded localhost
09:17:14 10580 gethostbyname looked up these IP addresses:
09:17:14 10580 name=localhost.localdomain address=127.0.0.1
09:17:14 10580 checking addresses for localhost
09:17:14 10580 127.0.0.1 OK
09:17:14 10580 sender_fullhost = localhost [127.0.0.1]
09:17:14 10580 sender_rcvhost = localhost ([127.0.0.1])
09:17:14 10580 set_process_info: 10580 handling incoming connection from
localhost [127.0.0.1]
09:17:14 10580 host in host_reject_connection? no (option unset)
09:17:14 10580 host in sender_unqualified_hosts? no (option unset)
09:17:14 10580 host in recipient_unqualified_hosts? no (option unset)
09:17:14 10580 host in helo_verify_hosts? no (option unset)
09:17:14 10580 host in helo_try_verify_hosts? no (option unset)
09:17:14 10580 host in helo_accept_junk_hosts? no (option unset)
09:17:14 10580 expanding: $smtp_active_hostname ESMTP Exim
$version_number $tod_full
09:17:14 10580 result: catherine.espersunited.com ESMTP Exim 4.67
Wed, 16 May 2007 09:17:14 -0500
09:17:14 10580 SMTP>> 220 catherine.espersunited.com ESMTP Exim 4.67
Wed, 16 May 2007 09:17:14 -0500
220 catherine.espersunited.com ESMTP Exim 4.67 Wed, 16 May 2007 09:17:14
-0500
09:17:14 10580 smtp_setup_msg entered
helo test
09:17:30 10580 SMTP<< helo test
09:17:30 10580 sender_fullhost = localhost (test) [127.0.0.1]
09:17:30 10580 sender_rcvhost = localhost ([127.0.0.1] helo=test)
09:17:30 10580 set_process_info: 10580 handling incoming connection from
localhost (test) [127.0.0.1]
250 catherine.espersunited.com Hello localhost [127.0.0.1]
09:17:30 10580 SMTP>> 250 catherine.espersunited.com Hello localhost
[127.0.0.1]
mail from: michael@localhost
09:17:43 10580 SMTP<< mail from: michael@localhost
09:17:43 10580 SMTP>> 250 OK
250 OK
rcpt to: michael@localhost
09:18:03 10580 SMTP<< rcpt to: michael@localhost
09:18:03 10580 using ACL "acl_check_rcpt"
09:18:03 10580 processing "accept"
09:18:03 10580 check hosts = :
09:18:03 10580 host in ":"? no (end of list)
09:18:03 10580 accept: condition test failed
09:18:03 10580 processing "deny"
09:18:03 10580 check domains = +local_domains
09:18:03 10580 localhost in "@ : espersunited.com :
catherine.espersunited.com localhost.localdomain"? no (end of list)
09:18:03 10580 localhost in "+local_domains"? no (end of list)
09:18:03 10580 deny: condition test failed
09:18:03 10580 processing "deny"
09:18:03 10580 check domains = !+local_domains
09:18:03 10580 cached no match for +local_domains
09:18:03 10580 cached lookup data = NULL
09:18:03 10580 localhost in "!+local_domains"? yes (end of list)
09:18:03 10580 check local_parts = ^[./|] : ^.*[@%!] : ^.*/\\.\\./
09:18:03 10580 expanding: ^[./|] : ^.*[@%!] : ^.*/\\.\\./
09:18:03 10580 result: ^[./|] : ^.*[@%!] : ^.*/\.\./
09:18:03 10580 michael in "^[./|] : ^.*[@%!] : ^.*/\.\./"? no (end of
list)
09:18:03 10580 deny: condition test failed
09:18:03 10580 processing "accept"
09:18:03 10580 check local_parts = postmaster
09:18:03 10580 michael in "postmaster"? no (end of list)
09:18:03 10580 accept: condition test failed
09:18:03 10580 processing "require"
09:18:03 10580 check verify = sender
09:18:03 10580 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
09:18:03 10580 Verifying michael@localhost
09:18:03 10580 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
09:18:03 10580 Considering michael@localhost
09:18:03 10580 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
09:18:03 10580 routing michael@localhost
09:18:03 10580 --------> dnslookup router <--------
09:18:03 10580 local_part=michael domain=localhost
09:18:03 10580 checking domains
09:18:03 10580 localhost in "@ : espersunited.com :
catherine.espersunited.com localhost.localdomain"? no (end of list)
09:18:03 10580 localhost in "! +local_domains"? yes (end of list)
09:18:03 10580 calling dnslookup router
09:18:03 10580 dnslookup router called for michael@localhost
09:18:03 10580 domain = localhost
09:18:03 10580 DNS lookup of localhost (MX) gave HOST_NOT_FOUND
09:18:03 10580 returning DNS_NOMATCH
09:18:03 10580 dnslookup router declined for michael@localhost
09:18:03 10580 "more" is false: skipping remaining routers
09:18:03 10580 no more routers
09:18:03 10580 ----------- end verify ------------
09:18:03 10580 require: condition test failed
09:18:03 10580 LOG: MAIN REJECT
09:18:03 10580 H=localhost (test) [127.0.0.1] sender verify fail for
<michael@localhost>: Unrouteable address
09:18:03 10580 SMTP>> 550-Verification failed for <michael@localhost>
550-Verification failed for <michael@localhost>
09:18:03 10580 SMTP>> 550-Unrouteable address
550-Unrouteable address
09:18:03 10580 SMTP>> 550 Sender verify failed
550 Sender verify failed
09:18:03 10580 LOG: MAIN REJECT
09:18:03 10580 H=localhost (test) [127.0.0.1] F=<michael@localhost>
rejected RCPT michael@localhost: Sender verify failed
^]
09:18:20 10580 SMTP<< ?
09:18:20 10580 LOG: smtp_syntax_error MAIN
09:18:20 10580 SMTP syntax error in "\035" H=localhost (test)
[127.0.0.1] unrecognized command
09:18:20 10580 SMTP>> 500 unrecognized command
500 unrecognized command
quit
09:18:28 10580 SMTP<< quit
09:18:28 10580 SMTP>> 221 catherine.espersunited.com closing connection
221 catherine.espersunited.com closing connection
09:18:28 10580 LOG: smtp_connection MAIN
09:18:28 10580 SMTP connection from localhost (test) [127.0.0.1]
closed by QUIT
09:18:28 10580 search_tidyup called
09:18:28 10580 >>>>>>>>>>>>>>>> Exim pid=10580 terminating with rc=0
>>>>>>>>>>>>>>>>
