i've an exim 4.64 server
Exim version 4.64 #1 built 07-Dec-2006 09:44:17
Copyright (c) University of Cambridge 2006
Berkeley DB: Berkeley DB 4.5.20: (October 25, 2006)
Support for: crypteq PAM TCPwrappers OpenSSL Content_Scanning
Old_Demime Experimental_DomainKeys
Lookups: lsearch wildlsearch nwildlsearch iplsearch cdb dbm dbmnz dsearch mysql
Authenticators: cram_md5 dovecot plaintext
Routers: accept dnslookup ipliteral manualroute queryprogram redirect
Transports: appendfile/maildir/mailstore/mbx autoreply lmtp pipe smtp
Fixed never_users: 0
Size of off_t: 8
Configuration file is /var/mailserver/exim/exim.conf
installed on,
mail.localdomain.com
i've verified that i can successfully:
(1) @ shell(mail.localdomain.com)
% exim -v snowcrash@???
--> message is RECEIVED in INBOX
(2) @ shell(mail.localdomain.com)
% exim -v snowcrash@???
--> message is RECEIVED in INBOX
(3) @ MUA(mail.localdomain.com)
from: snowcrash@???
to: snowcrash@???
--> message is RECEIVED in INBOX
but, if i,
(4) @ MUA(mail.localdomain.com)
from: snowcrash@???
to: snowcrash@???
the MUA reports,
waiting for Server Response
Authenticating to Server
and 'waits' there forever --
-- the message never gets sent/delivered.
in my exim log, with exim launched as,
exim ... -d+all
and config'd as,
log_selector = +all
i see only,
21:35:27 25737 Connection request from 192.168.1.6 port 55143
21:35:27 25737 interface address=192.168.1.5 port=25
21:35:27 25737 LOG: smtp_connection MAIN
21:35:27 25737 SMTP connection from [192.168.1.6]:55143
I=[192.168.1.5]:25 (TCP/IP connection count = 1)
21:35:27 25737 search_tidyup called
21:35:27 25737 1 SMTP accept process running
21:35:27 25737 Listening...
21:35:27 26417 sender_fullhost = [192.168.1.6]:55143
21:35:27 26417 sender_rcvhost = [192.168.1.6] (port=55143)
21:35:27 26417 Process 26417 is handling incoming connection from
[192.168.1.6]:55143
21:35:27 26417 checking for IP options
21:35:27 26417 no IP options found
21:35:27 26417 host in host_lookup? yes (matched "*")
21:35:27 26417 looking up host name for 192.168.1.6
;; res_querydomain(6.1.168.192.in-addr.arpa, <Nil>, 1, 12)
;; res_query(6.1.168.192.in-addr.arpa, 1, 12)
;; res_mkquery(0, 6.1.168.192.in-addr.arpa, 1, 12)
;; res_send()
;; ->>HEADER<<- opcode: QUERY, status: NOERROR, id: 13026
;; flags: rd; Ques: 1, Ans: 0, Auth: 0, Addit: 0
;; QUESTIONS:
;; 6.1.168.192.in-addr.arpa, type = PTR, class = IN
;; Querying server (# 1) address = 192.168.1.5
;; got answer:
;; ->>HEADER<<- opcode: QUERY, status: NOERROR, id: 13026
;; flags: qr aa rd ra; Ques: 1, Ans: 1, Auth: 1, Addit: 1
;; QUESTIONS:
;; 6.1.168.192.in-addr.arpa, type = PTR, class = IN
;; ANSWERS:
6.1.168.192.in-addr.arpa. 86400 IN PTR
desktop.localdomain.com.
;; AUTHORITY RECORDS:
1.168.192.in-addr.arpa. 86400 IN NS mail.localdomain.com.
;; ADDITIONAL RECORDS:
mail.localdomain.com. 86400 IN A 192.168.1.5
21:35:27 26417 DNS lookup of 6.1.168.192.in-addr.arpa (PTR) succeeded
21:35:27 26417 IP address lookup yielded desktop.localdomain.com
21:35:27 26417 gethostbyname looked up these IP addresses:
21:35:27 26417 name=desktop.localdomain.com address=192.168.1.6
21:35:27 26417 checking addresses for desktop.localdomain.com
21:35:27 26417 192.168.1.6 OK
21:35:27 26417 sender_fullhost = desktop.localdomain.com [192.168.1.6]:55143
21:35:27 26417 sender_rcvhost = desktop.localdomain.com ([192.168.1.6]:55143)
21:35:27 26417 set_process_info: 26417 handling incoming connection
from desktop.localdomain.com [192.168.1.6]:55143 I=[192.168.1.5]:25
21:35:27 26417 host in host_reject_connection? no (option unset)
21:35:27 26417 host in sender_unqualified_hosts? no (end of list)
21:35:27 26417 host in recipient_unqualified_hosts? no (end of list)
21:35:27 26417 host in helo_verify_hosts? no (option unset)
21:35:27 26417 host in helo_try_verify_hosts? yes (matched "*")
21:35:27 26417 host in helo_accept_junk_hosts? no (option unset)
21:35:27 26417 using ACL "acl_check_connect"
21:35:27 26417 processing "warn"
21:35:27 26417 expanding: $tod_epoch
21:35:27 26417 result: 1166160927
21:35:27 26417 check set acl_m2 = $tod_epoch
21:35:27 26417 = 1166160927
21:35:27 26417 warn: condition test succeeded
21:35:27 26417 processing "accept"
21:35:27 26417 check hosts = : +relay_from_hosts
21:35:27 26417 host in "192.168.1.0/28
:dbm;/var/mailserver/exim/domains.nearby.dbm"? yes (matched
"192.168.1.0/28")
21:35:27 26417 host in ": +relay_from_hosts"? yes (matched "+relay_from_hosts")
21:35:27 26417 accept: condition test succeeded
21:35:27 26417 expanding: $smtp_active_hostname ESMTP $tod_full
21:35:27 26417 result: mail.localdomain.com ESMTP Thu, 14 Dec 2006
21:35:27 -0800
21:35:27 26417 SMTP>> 220 mail.localdomain.com ESMTP Thu, 14 Dec 2006
21:35:27 -0800
21:35:27 26417 Process 26417 is ready for new message
21:35:27 26417 smtp_setup_msg entered
21:35:27 26417 SMTP<< EHLO [192.168.1.6]
21:35:27 26417 sender_fullhost = desktop.localdomain.com [192.168.1.6]:55143
21:35:27 26417 sender_rcvhost = desktop.localdomain.com ([192.168.1.6]:55143)
21:35:27 26417 set_process_info: 26417 handling incoming connection
from desktop.localdomain.com [192.168.1.6]:55143 I=[192.168.1.5]:25
21:35:27 26417 verifying EHLO/HELO argument "[192.168.1.6]"
21:35:27 26417 matched host address
21:35:27 26417 using ACL "acl_check_helo"
21:35:27 26417 processing "warn"
21:35:27 26417 expanding: $tod_epoch
21:35:27 26417 result: 1166160927
21:35:27 26417 check set acl_m2 = $tod_epoch
21:35:27 26417 = 1166160927
21:35:27 26417 warn: condition test succeeded
21:35:27 26417 processing "accept"
21:35:27 26417 check hosts = : +relay_from_hosts
21:35:27 26417 cached yes match for +relay_from_hosts
21:35:27 26417 cached lookup data = NULL
21:35:27 26417 host in ": +relay_from_hosts"? yes (matched
"+relay_from_hosts" - cached)
21:35:27 26417 accept: condition test succeeded
21:35:27 26417 host in pipelining_advertise_hosts? yes (matched "*")
21:35:27 26417 expanding: $tls_cipher
21:35:27 26417 result:
21:35:27 26417 expanding:
21:35:27 26417 result:
21:35:27 26417 condition: eq{$tls_cipher}{}
21:35:27 26417 result: true
21:35:27 26417 expanding:
21:35:27 26417 result:
21:35:27 26417 expanding: *
21:35:27 26417 result: *
21:35:27 26417 skipping: result is not used
21:35:27 26417 expanding: ${if eq{$tls_cipher}{}{}{*}}
21:35:27 26417 result:
21:35:27 26417 host in auth_advertise_hosts? no (end of list)
21:35:27 26417 host in tls_advertise_hosts? yes (matched "*")
21:35:27 26417 SMTP>> 250-mail.localdomain.com Hello
desktop.localdomain.com [192.168.1.6]
21:35:27 26417 250-SIZE 52428800
21:35:27 26417 250-8BITMIME
21:35:27 26417 250-PIPELINING
21:35:27 26417 250-STARTTLS
21:35:27 26417 250 HELP
21:35:27 26417 SMTP<< STARTTLS
21:35:27 26417 tls_certificate file
/var/mailserver/exim/mail.localdomain.com.cert.rsa.pem
21:35:27 26417 tls_privatekey file
/var/mailserver/exim/mail.localdomain.com.privkey.rsa.pem
21:35:27 26417 Initialized TLS
21:35:27 26417 host in tls_verify_hosts? no (option unset)
21:35:27 26417 host in tls_try_verify_hosts? yes (matched "*")
21:35:27 26417 SMTP>> 220 TLS go ahead
21:35:27 26417 Calling SSL_accept
21:35:27 26417 SSL info: before/accept initialization
21:35:27 26417 SSL info: before/accept initialization
21:35:27 26417 SSL info: SSLv3 read client hello A
21:35:27 26417 SSL info: SSLv3 write server hello A
21:35:27 26417 SSL info: SSLv3 write certificate A
21:35:27 26417 SSL info: SSLv3 write certificate request A
21:35:27 26417 SSL info: SSLv3 flush data
21:35:27 26417 SSL info: SSLv3 read client certificate A
21:35:27 26417 SSL info: SSLv3 read client key exchange A
21:35:27 26417 SSL info: SSLv3 read finished A
21:35:27 26417 SSL info: SSLv3 write change cipher spec A
21:35:27 26417 SSL info: SSLv3 write finished A
21:35:27 26417 SSL info: SSLv3 flush data
21:35:27 26417 SSL info: SSL negotiation finished successfully
21:35:27 26417 SSL info: SSL negotiation finished successfully
21:35:27 26417 SSL_accept was successful
21:35:27 26417 Cipher: TLSv1:AES256-SHA:256
21:35:27 26417 Shared ciphers:
DHE-RSA-AES256-SHA:DHE-DSS-AES256-SHA:AES256-SHA:EDH-RSA-DES-CBC3-SHA:EDH-DSS-DES-CBC3-SHA:DES-CBC3-SHA:DHE-RSA-AES128-SHA:DHE-DSS-AES128-SHA:AES128-SHA:RC4-SHA:RC4-MD5:EDH-RSA-DES-CBC-SHA:EDH-DSS-DES-CBC-SHA:DES-CBC-SHA:EXP-EDH-RSA-DES-CBC-SHA:EXP-EDH-DSS-DES-CBC-SHA:EXP-DES-CBC-SHA:EXP-RC2-CBC-MD5:EXP-RC4-MD5
21:35:27 26417 sender_fullhost = desktop.localdomain.com [192.168.1.6]:55143
21:35:27 26417 sender_rcvhost = desktop.localdomain.com ([192.168.1.6]:55143)
21:35:27 26417 set_process_info: 26417 handling incoming TLS
connection from desktop.localdomain.com [192.168.1.6]:55143
I=[192.168.1.5]:25
21:35:27 26417 TLS active
21:35:27 26417 Calling SSL_read(110d100, 1815a00, 4096)
21:35:27 26417 SMTP<< EHLO [192.168.1.6]
21:35:27 26417 sender_fullhost = desktop.localdomain.com [192.168.1.6]:55143
21:35:27 26417 sender_rcvhost = desktop.localdomain.com ([192.168.1.6]:55143)
21:35:27 26417 set_process_info: 26417 handling TLS incoming
connection from desktop.localdomain.com [192.168.1.6]:55143
I=[192.168.1.5]:25
21:35:27 26417 verifying EHLO/HELO argument "[192.168.1.6]"
21:35:27 26417 matched host address
21:35:27 26417 using ACL "acl_check_helo"
21:35:27 26417 processing "warn"
21:35:27 26417 expanding: $tod_epoch
21:35:27 26417 result: 1166160927
21:35:27 26417 check set acl_m2 = $tod_epoch
21:35:27 26417 = 1166160927
21:35:27 26417 warn: condition test succeeded
21:35:27 26417 processing "accept"
21:35:27 26417 check hosts = : +relay_from_hosts
21:35:27 26417 cached yes match for +relay_from_hosts
21:35:27 26417 cached lookup data = NULL
21:35:27 26417 host in ": +relay_from_hosts"? yes (matched
"+relay_from_hosts" - cached)
21:35:27 26417 accept: condition test succeeded
21:35:27 26417 host in pipelining_advertise_hosts? yes (matched "*")
21:35:27 26417 expanding: $tls_cipher
21:35:27 26417 result: TLSv1:AES256-SHA:256
21:35:27 26417 expanding:
21:35:27 26417 result:
21:35:27 26417 condition: eq{$tls_cipher}{}
21:35:27 26417 result: false
21:35:27 26417 expanding:
21:35:27 26417 result:
21:35:27 26417 skipping: result is not used
21:35:27 26417 expanding: *
21:35:27 26417 result: *
21:35:27 26417 expanding: ${if eq{$tls_cipher}{}{}{*}}
21:35:27 26417 result: *
21:35:27 26417 host in auth_advertise_hosts? yes (matched "*")
21:35:27 26417 expanding:
21:35:27 26417 result:
21:35:27 26417 expanding: $tls_cipher
21:35:27 26417 result: TLSv1:AES256-SHA:256
21:35:27 26417 condition: !eq{}{$tls_cipher}
21:35:27 26417 result: true
21:35:27 26417 expanding: ${if !eq{}{$tls_cipher}}
21:35:27 26417 result: true
21:35:27 26417 tls_do_write(1811010, 166)
21:35:27 26417 SSL_write(SSL, 1811010, 166)
21:35:27 26417 outbytes=166 error=0
21:35:27 26417 SMTP>> 250-mail.localdomain.com Hello
desktop.localdomain.com [192.168.1.6]
21:35:27 26417 250-SIZE 52428800
21:35:27 26417 250-8BITMIME
21:35:27 26417 250-PIPELINING
21:35:27 26417 250-AUTH PLAIN CRAM-MD5 DIGEST-MD5
21:35:27 26417 250 HELP
21:35:27 26417 Calling SSL_read(110d100, 1815a00, 4096)
21:35:27 26417 SMTP<< AUTH PLAIN
AGJsYWtlcnNAbWFpbC5wZ25ldHdvcmsubmV0AHRVbU8hMVJBVA==
21:35:27 26417 dovecot authentication
21:35:27 26417 received: VERSION 1 0
21:35:27 26417 received: SPID 26191
and nothing further. :-/
i'm stumped as to why the _other_ send tests are OK, but not the
self-to-self-via-MUA.
to my eye -- no doubt mistaken -- i see nothing wrong in the log
above. i know i've missed something.
any ideas?
thanks.
