Re: [exim] "503 AUTH command used when not advertised" probl…

Top Page
Delete this message
Reply to this message
Author: Chad Leigh -- Shire.Net LLC
Date:  
To: Exim User's Mailing List
Subject: Re: [exim] "503 AUTH command used when not advertised" problem

On Sep 1, 2004, at 6:30 PM, Fred Viles wrote:

> On 1 Sep 2004 at 11:55, Chad Leigh -- Shire.Net LLC wrote about
>     "Re: [exim] "503 AUTH command used w":

>
> | On Sep 1, 2004, at 12:38 AM, Peter Savitch wrote:
> |
> | > EHLO (not HELO) must be given by client before AUTH.
>
> and after STARTTLS.
>
> | > That is, AUTH command could not be used unless advertised (through
> | > EHLO,
> | > according to auth_advertise, etc). This behavior was hardened in
> Exim
> | > 4.20 and is not an option.
> | >
> | > First, check you confs once again for correct advertising.
> |
> | It advertises it and the client does an EHLO but then the client
> tries
> | a HELO so something is not working in the conversation or something.
>
> A successfull STARTTLS resets the session as if it were a new
> connection (which it is, in a sense). The EHLO and response from
> that preceded the STARTTLS negotiation are not applicable any more.
> After successfull negotiation, the server returns a new welcome
> banner and the client sends a fresh HELO/EHLO.
>
> Your client is choosing to send HELO instead of EHLO. That is not in
> exim's control.
>


I did a test on my 4.10 server, which basically has the exact same
config (local domains and stuff are of course different) using the same
level of debug. A mail from the same client (Mail.app on OS X 10.3.5)
did the EHLO -- STARTTLS -- EHLO. It did not do a HELO like on the
broken server. I also noticed that the amount of debug info in the
"good" server's STARTTLS command was a lot more. Much more SSL stuff.

A test on the broken server with Mulbery shows that it gives the EHLO
and a STARTTLS. Then Mulbery reports back "TCP/IP -- Connection reset
by remote host while sending 'EHLO' command to smtp server."

Given the above "facts", I think the broken server has a broken TLS
cert or maybe it is using a different version of openssl or something.
Something caused by the underlying change from Mandrake to gentoo. The
clients aren't broken -- they do the right things. The Mail.app that
issues the HELO after the STARTTLS I think is falling back to HELO
after the STARTTLS fails to finish.

There are no SSL or TLS errors in the debug log I posted earlier, but
it looks shorter and has less SSL feedback than the one from my 4.10
server when doing the same test from the same client against it.


I will experiment more and report back if I fix it.

In case anyone wants to compare the debug log for when Mulbery hits it
versus the one I posted earlier when Mail.app hits it, here it is: (and
after that is an excerpt from the 4.10 server doing its TSL stuff --
same level of debug, but one is a 4.22 (broken one) and one is 4.10 so
there could be some differences based on that)

broken server (4.22) with Mulbery:

17055 Connection request from 24.189.126.227 port 1180
17055 1 SMTP accept process running
17055 Listening...
17336 sender_fullhost = [24.189.126.227]
17336 sender_rcvhost = [24.189.126.227]
17336 Process 17336 is handling incoming connection from
[24.189.126.227]
17336 checking for IP options
17336 no IP options found
17336 host in host_lookup? no (option unset)
17336 set_process_info: 17336 handling incoming connection from
[24.189.126.227]
17336 host in host_reject_connection? no (option unset)
17336 host in sender_unqualified_hosts? no (option unset)
17336 host in recipient_unqualified_hosts? no (option unset)
17336 host in helo_verify_hosts? no (option unset)
17336 host in helo_try_verify_hosts? no (option unset)
17336 host in helo_accept_junk_hosts? no (option unset)
17336 SMTP>> 220 mail.object.com ESMTP Exim 4.22 Wed, 01 Sep 2004
19:34:30 -0600
17336 Process 17336 is ready for new message
17336 smtp_setup_msg entered
17336 SMTP<< ???i?????9??8??5??????
17336 LOG: smtp_syntax_error MAIN
17336 SMTP syntax error in
"\200\202\001\003\001?i???\020??9??8??5??\026??\023??"
H=[24.189.126.227] NULL character(s) present (shown as '?')
17336 SMTP>> 501 NULL characters are not allowed in SMTP commands
17336 SMTP>> 421 mail.object.com lost input connection
17336 LOG: smtp_connection MAIN
17336 SMTP connection from [24.189.126.227] lost (error: Connection
reset by peer)
17336 search_tidyup called
17055 child 17336 ended: status=0x100
17055 0 SMTP accept processes now running
17055 Listening...
17055 Connection request from 24.189.126.227 port 1181
17055 1 SMTP accept process running
17055 Listening...
17342 sender_fullhost = [24.189.126.227]
17342 sender_rcvhost = [24.189.126.227]
17342 Process 17342 is handling incoming connection from
[24.189.126.227]
17342 checking for IP options
17342 no IP options found
17342 host in host_lookup? no (option unset)
17342 set_process_info: 17342 handling incoming connection from
[24.189.126.227]
17342 host in host_reject_connection? no (option unset)
17342 host in sender_unqualified_hosts? no (option unset)
17342 host in recipient_unqualified_hosts? no (option unset)
17342 host in helo_verify_hosts? no (option unset)
17342 host in helo_try_verify_hosts? no (option unset)
17342 host in helo_accept_junk_hosts? no (option unset)
17342 SMTP>> 220 mail.object.com ESMTP Exim 4.22 Wed, 01 Sep 2004
19:34:58 -0600
17342 Process 17342 is ready for new message
17342 smtp_setup_msg entered
17342 SMTP<< EHLO [10.0.1.3]
17342 [10.0.1.3] in helo_lookup_domains? no (end of list)
17342 sender_fullhost = ([10.0.1.3]) [24.189.126.227]
17342 sender_rcvhost = [24.189.126.227] (helo=[10.0.1.3])
17342 set_process_info: 17342 handling incoming connection from
([10.0.1.3]) [24.189.126.227]
17342 host in pipelining_advertise_hosts? yes (matched "*")
17342 host in auth_advertise_hosts? yes (matched "*")
17342 host in tls_advertise_hosts? yes (matched "*")
17342 SMTP>> 250-mail.object.com Hello [10.0.1.3] [24.189.126.227]
17342 250-SIZE 52428800
17342 250-PIPELINING
17342 250-AUTH PLAIN LOGIN
17342 250-STARTTLS
17342 250 HELP
17342 SMTP<< STARTTLS
17342 tls_certificate file /usr/local/etc/exim_key_cert
17342 tls_privatekey file /usr/local/etc/exim_key_cert
17342 Initialized TLS
17342 host in tls_verify_hosts? no (option unset)
17342 host in tls_try_verify_hosts? no (option unset)
17342 SMTP>> 220 TLS go ahead
17342 Calling SSL_accept
17342 SSL_accept was successful
17055 child 17342 ended: status=0xb
17055 0 SMTP accept processes now running
17055 Listening...


Segment of good 4.10 server showing the TLS stuff from Mail.app

SMTP<< STARTTLS
tls_certificate file /usr/local/etc/exim_key_cert
tls_privatekey file /usr/local/etc/exim_key_cert
Initialised TLS
host in tls_verify_hosts? no (option unset)
host in tls_try_verify_hosts? no (option unset)
SMTP>> 220 TLS go ahead

Calling SSL_accept
SSL info: before/accept initialization
SSL info: before/accept initialization
SSL info: SSLv3 read client hello A
SSL info: SSLv3 write server hello A
SSL info: SSLv3 write certificate A
SSL info: SSLv3 write server done A
SSL info: SSLv3 flush data
SSL info: SSLv3 read client key exchange A
SSL info: SSLv3 read finished A
SSL info: SSLv3 write change cipher spec A
SSL info: SSLv3 write finished A
SSL info: SSLv3 flush data
SSL info: SSL negotiation finished successfully
SSL info: SSL negotiation finished successfully
SSL_accept was successful
Cipher: TLSv1:RC4-SHA:128
Shared ciphers:
RC4-SHA:RC4-MD5:DES-CBC3-SHA:DES-CBC-SHA:EXP-RC4-MD5:EXP-DES-CBC-SHA:
EXP-RC2-CBC-MD5:NULL-MD5:EDH-RSA-DES-CBC3-SHA:EDH-RSA-DES-CBC-SHA:EXP-
EDH-RSA-DES-CBC-SHA:EDH-DSS-DES-CBC3-SHA:EDH-DSS-DES-CBC-SHA:EXP-EDH-
DSS-DES-CBC-SHA:ADH-RC4-MD5:ADH-DES-CBC3-SHA:ADH-DES-CBC-SHA:EXP-ADH-
RC4-MD5:EXP-ADH-DES-CBC-SHA
sender_fullhost = [67.161.247.57]
sender_rcvhost = [67.161.247.57]
set_process_info: 23999 handling incoming TLS connection from
[67.161.247.57]
TLS active
Calling SSL_read(80ce900, 80ec000, 4096)
SMTP<< EHLO [192.168.99.66]
[192.168.99.66] in helo_lookup_domains? no (end of list)
sender_fullhost = ([192.168.99.66]) [67.161.247.57]
sender_rcvhost = [67.161.247.57] (helo=[192.168.99.66])
set_process_info: 23999 handling TLS incoming connection from
([192.168.99.66]) [67.161.247.57]
host in auth_advertise_hosts? yes (matched "*")
tls_do_write(80cfa30, 129)
SSL_write(SSL, 80cfa30, 129)
outbytes=129 error=0
SMTP>> 250-hobbiton.shire.net Hello [192.168.99.66] [67.161.247.57]

250-SIZE 52428800
250-PIPELINING
250-AUTH PLAIN LOGIN
250 HELP
Calling SSL_read(80ce900, 80ec000, 4096)