Authentication unsuccessful relaying from Postfix to Microsoft ESMTP MAIL Service
Clive Standbridge
I'm trying in vain to relay external mail from postfix on a Debian
lenny machine to a Microsoft SMTP server on the Internet. I've been
reading and searching for days. I've tried numerous combinations of
settings although I'm note certain what they all do and am
experiencing information overload.
I am trying to migrate from one MS server to another.
OLDSERVER runs on port 25.
NEWSERVER runs on port 587. Supposedly it requires TLS but I'm not
certain of that (more later).
My existing, working, setup has postfix set up for "Internet with smarthost"
and the login credentials for OLDSERVER are in /etc/postfix/sasl_passwd.
I send mail from mutt to "/usr/sbin/sendmail -oem -oi" and it is duly
relayed by postfix.
When I change relayhost to NEWSERVER:587, the mail gets stuck in postfix.
In /var/log/mail.log I see "Authentication unsuccessful".
On the same machine I set up an account in IceDove to use NEWSERVER:587
for SMTP and it just works.
What's more, it works when "Secure Connection" is set to any of
"None", "TLS", "Use TLS if available". (That's why I cast doubt on the
TLS requirement above).
So my questions are:
* How can I fix this in Postfix?
* Can Postfix do this? Or do I need to change to something else e.g. Exim?
* What does IceDove do that Postfix doesn't?
The rest of this mail contains more detail.
I've tried with:
* smtp_sasl_security_options set to noanonymous and empty
* smtp_tls_security_level set to "may", "none", "encrypt" and not set.
* relayhost set to NEWSERVER:587 and [NEWSERVER]:587 in main.cf and
sasl_passwd (kept them in step and updated sasl_passwd.db each time)
(Sanitised) server information using ehlo command in telnet:
$ telnet NEWSERVER 587
Trying NEWSERVER-IPADDR...
Connected to NEWSERVER.
Escape character is '^]'.
220 NEWSERVER-OTHERNAME Microsoft ESMTP MAIL Service ready at Fri, 7 May 2010 14:43:28 +0100
ehlo
250-NEWSERVER-OTHERNAME Hello [MY-IPADDR]
250-SIZE 15360000
250-PIPELINING
250-DSN
250-ENHANCEDSTATUSCODES
250-STARTTLS
250-AUTH GSSAPI NTLM
250-8BITMIME
250-BINARYMIME
250 CHUNKING
$ telnet OLDSERVER 25
Trying OLDSERVER-IPADDR...
Connected to OLDSERVER.
Escape character is '^]'.
220 OLDSERVER-OTHERNAME Microsoft ESMTP MAIL Service, Version: 6.0.3790.3959 ready at Fri, 7 May 2010 15:44:25 +0200
ehlo
250-OLDSERVER-OTHERNAME Hello [MY-IPADDR]
250-TURN
250-SIZE
250-ETRN
250-PIPELINING
250-DSN
250-ENHANCEDSTATUSCODES
250-8bitmime
250-BINARYMIME
250-CHUNKING
250-VRFY
250-X-EXPS GSSAPI NTLM LOGIN
250-X-EXPS=LOGIN
250-AUTH GSSAPI NTLM LOGIN
250-AUTH=LOGIN
250-X-LINK2STATE
250-XEXCH50
250 OK
Here are some sanitised logs from when the problem occurs. These were
collected with the following settings:
relayhost = NEWSERVER:587
smtp_sasl_security_options = noanonymous
smtp_tls_security_level = may
(although it's the same for all the settings I tried, except there were
no SSL/TLS logs when smtp_tls_security_level = none).
/var/log/auth.log:
May 9 16:30:01 rimmer postfix/smtp[10643]: NTLM client step 1
May 9 16:30:01 rimmer postfix/smtp[10643]: NTLM client step 2
May 9 16:30:01 rimmer postfix/smtp[10643]: server flags: ff810205
May 9 16:30:01 rimmer postfix/smtp[10643]: server domain: NEWSERVER-NTDOMAIN
May 9 16:30:01 rimmer postfix/smtp[10643]: calculating NT response
/var/log/mail.log:
May 9 16:30:01 rimmer postfix/pickup[10629]: 57BC739B7: uid=1000 from=<MY-EMAIL-ADDRESS>
May 9 16:30:01 rimmer postfix/cleanup[10641]: 57BC739B7: resent-message-id=<20100509153001.GF3672@MY-MAILNAME>
May 9 16:30:01 rimmer postfix/cleanup[10641]: 57BC739B7: message-id=<20100509141642.GB3672@MY-MAILNAME>
May 9 16:30:01 rimmer postfix/qmgr[10630]: 57BC739B7: from=<MY-EMAIL-ADDRESS>, size=863, nrcpt=1 (queue active)
May 9 16:30:01 rimmer postfix/smtp[10643]: initializing the client-side TLS engine
May 9 16:30:01 rimmer postfix/tlsmgr[10644]: open smtp TLS cache btree:/var/lib/postfix/smtp_scache
May 9 16:30:01 rimmer postfix/tlsmgr[10644]: tlsmgr_cache_run_event: start TLS smtp session cache cleanup
May 9 16:30:01 rimmer postfix/smtp[10643]: setting up TLS connection to NEWSERVER[NEWSERVER-IPADDR]:587
May 9 16:30:01 rimmer postfix/smtp[10643]: NEWSERVER[NEWSERVER-IPADDR]:587: TLS cipher list "ALL:+RC4:@STRENGTH"
May 9 16:30:01 rimmer postfix/smtp[10643]: looking for session smtp:NEWSERVER-IPADDR:587:NEWSERVER-OTHERNAME&p=0&c=ALL:+RC4:@STRENGTH in smtp cache
May 9 16:30:01 rimmer postfix/tlsmgr[10644]: lookup smtp session id=smtp:NEWSERVER-IPADDR:587:NEWSERVER-OTHERNAME&p=0&c=ALL:+RC4:@STRENGTH
May 9 16:30:01 rimmer postfix/smtp[10643]: SSL_connect:before/connect initialization
May 9 16:30:01 rimmer postfix/smtp[10643]: SSL_connect:SSLv2/v3 write client hello A
May 9 16:30:01 rimmer postfix/smtp[10643]: SSL_connect:SSLv3 read server hello A
May 9 16:30:01 rimmer postfix/smtp[10643]: NEWSERVER[NEWSERVER-IPADDR]:587: certificate verification depth=2 verify=0 subject=/C=US/O=The Go Daddy Group, Inc./OU=Go Daddy Class 2 Certification Authority
May 9 16:30:01 rimmer postfix/smtp[10643]: certificate verification failed for NEWSERVER[NEWSERVER-IPADDR]:587: untrusted issuer /L=ValiCert Validation Network/O=ValiCert, Inc./OU=ValiCert Class 2 Policy Validation Authority/CN=http://www.valicert.com//emailAddress=in...@valicert.com
May 9 16:30:01 rimmer postfix/smtp[10643]: NEWSERVER[NEWSERVER-IPADDR]:587: certificate verification depth=2 verify=0 subject=/C=US/O=The Go Daddy Group, Inc./OU=Go Daddy Class 2 Certification Authority
May 9 16:30:01 rimmer postfix/smtp[10643]: NEWSERVER[NEWSERVER-IPADDR]:587: certificate verification depth=1 verify=1 subject=/C=US/ST=Arizona/L=Scottsdale/O=GoDaddy.com, Inc./OU=http://certificates.godaddy.com/repository/CN=Go Daddy Secure Certification Authority/serialNumber=07969287
May 9 16:30:01 rimmer postfix/smtp[10643]: NEWSERVER[NEWSERVER-IPADDR]:587: certificate verification depth=0 verify=1 subject=/O=*.NEWSERVER-DOMAIN/OU=Domain Control Validated/CN=*.NEWSERVER-DOMAIN
May 9 16:30:01 rimmer postfix/smtp[10643]: SSL_connect:SSLv3 read server certificate A
May 9 16:30:01 rimmer postfix/smtp[10643]: SSL_connect:SSLv3 read server done A
May 9 16:30:01 rimmer postfix/smtp[10643]: SSL_connect:SSLv3 write client key exchange A
May 9 16:30:01 rimmer postfix/smtp[10643]: SSL_connect:SSLv3 write change cipher spec A
May 9 16:30:01 rimmer postfix/smtp[10643]: SSL_connect:SSLv3 write finished A
May 9 16:30:01 rimmer postfix/smtp[10643]: SSL_connect:SSLv3 flush data
May 9 16:30:01 rimmer postfix/smtp[10643]: SSL_connect:SSLv3 read finished A
May 9 16:30:01 rimmer postfix/smtp[10643]: save session smtp:NEWSERVER-IPADDR:587:NEWSERVER-OTHERNAME&p=0&c=ALL:+RC4:@STRENGTH to smtp cache
May 9 16:30:01 rimmer postfix/tlsmgr[10644]: put smtp session id=smtp:NEWSERVER-IPADDR:587:NEWSERVER-OTHERNAME&p=0&c=ALL:+RC4:@STRENGTH [data 1383 bytes]
May 9 16:30:01 rimmer postfix/tlsmgr[10644]: write smtp TLS cache entry smtp:NEWSERVER-IPADDR:587:NEWSERVER-OTHERNAME&p=0&c=ALL:+RC4:@STRENGTH: time=1273419001 [data 1383 bytes]
May 9 16:30:01 rimmer postfix/smtp[10643]: Untrusted TLS connection established to NEWSERVER[NEWSERVER-IPADDR]:587: TLSv1 with cipher RC4-MD5 (128/128 bits)
May 9 16:30:06 rimmer postfix/smtp[10643]: 57BC739B7: to=<MY-EMAIL-ADDRESS>, relay=NEWSERVER[NEWSERVER-IPADDR]:587, delay=5.5, delays=0.03/0.03/5.4/0, dsn=4.7.3, status=deferred (SASL authentication failed; server NEWSERVER[NEWSERVER-IPADDR] said: 535 5.7.3 Authentication unsuccessful)
--
To UNSUBSCRIBE, email to debian-us...@lists.debian.org
with a subject of "unsubscribe". Trouble? Contact listm...@lists.debian.org
Archive: http://lists.debian.org/20100509160...@rimmer.esmertec.com
Celejar
Clive Standbridge <Clive.St...@myriadgroup.com> wrote:
> Hi,
>
> I'm trying in vain to relay external mail from postfix on a Debian
> lenny machine to a Microsoft SMTP server on the Internet. I've been
> reading and searching for days. I've tried numerous combinations of
> settings although I'm note certain what they all do and am
> experiencing information overload.
>
> I am trying to migrate from one MS server to another.
> OLDSERVER runs on port 25.
> NEWSERVER runs on port 587. Supposedly it requires TLS but I'm not
> certain of that (more later).
I don't have a solution, just one possibly helpful bit of advice: swaks
is the tool for troubleshooting this sort of thing. You have gotten
lots of useful information from Postfix and telnet, but I'd try using
swaks to communicate with the server with and without TLS, and you'll
see, for any combination of connection and authentication options
that you try, what works and what errors are received on failure.
Celejar
--
foffl.sourceforge.net - Feeds OFFLine, an offline RSS/Atom aggregator
mailmin.sourceforge.net - remote access via secure (OpenPGP) email
ssuds.sourceforge.net - A Simple Sudoku Solver and Generator
--
To UNSUBSCRIBE, email to debian-us...@lists.debian.org
with a subject of "unsubscribe". Trouble? Contact listm...@lists.debian.org
Archive: http://lists.debian.org/20100509132705....@gmail.com
Camaleón
> I'm trying in vain to relay external mail from postfix on a Debian lenny
> machine to a Microsoft SMTP server on the Internet. I've been reading
> and searching for days. I've tried numerous combinations of settings
> although I'm note certain what they all do and am experiencing
> information overload.
O.k. Then you need to setup Postfix SSL/TLS acting as client, not server.
(...)
> When I change relayhost to NEWSERVER:587, the mail gets stuck in
> postfix. In /var/log/mail.log I see "Authentication unsuccessful".
(...)
> So my questions are:
> * How can I fix this in Postfix?
Let's see the logs...
> * Can Postfix do this? Or do I need to change to something else e.g.
> Exim?
Yes, you can setup Postfix for this.
> * What does IceDove do that Postfix doesn't?
Logs will tell.
> The rest of this mail contains more detail.
>
> I've tried with:
> * smtp_sasl_security_options set to noanonymous and empty *
> smtp_tls_security_level set to "may", "none", "encrypt" and not set. *
> relayhost set to NEWSERVER:587 and [NEWSERVER]:587 in main.cf and
> sasl_passwd (kept them in step and updated sasl_passwd.db each time)
The doc you have to follow stands here:
http://www.postfix.org/SASL_README.html#client_sasl
> /var/log/mail.log:
(...)
> May 9 16:30:01 rimmer postfix/smtp[10643]: certificate verification failed for NEWSERVER[NEWSERVER-IPADDR]:587: untrusted issuer /L=ValiCert Validation Network/O=ValiCert, Inc./OU=ValiCert Class 2 Policy Validation Authority/CN=http://www.valicert.com//emailAddress=in...@valicert.com
Server replies that does not trust the issuer of that CA.
(...)
> May 9 16:30:01 rimmer postfix/smtp[10643]: Untrusted TLS connection established to NEWSERVER[NEWSERVER-IPADDR]:587: TLSv1 with cipher RC4-MD5 (128/128 bits)
I guess your are having problems with the certificate itself. It cannot
be verified by the remote server.
Note: I think Thunderbird uses its own SSL CA root certificates database...
Greetings,
--
Camaleón
--
To UNSUBSCRIBE, email to debian-us...@lists.debian.org
with a subject of "unsubscribe". Trouble? Contact listm...@lists.debian.org
Sven Joachim
> (...)
>
>> May 9 16:30:01 rimmer postfix/smtp[10643]: certificate verification failed for NEWSERVER[NEWSERVER-IPADDR]:587: untrusted issuer /L=ValiCert Validation Network/O=ValiCert, Inc./OU=ValiCert Class 2 Policy Validation Authority/CN=http://www.valicert.com//emailAddress=in...@valicert.com
>
> Server replies that does not trust the issuer of that CA.
I believe it's postfix itself which does not trust the CA because it
does not know it.
> (...)
>
>> May 9 16:30:01 rimmer postfix/smtp[10643]: Untrusted TLS connection established to NEWSERVER[NEWSERVER-IPADDR]:587: TLSv1 with cipher RC4-MD5 (128/128 bits)
>
> I guess your are having problems with the certificate itself. It cannot
> be verified by the remote server.
It's the other way around, postfix cannot verify the remote server's
certificate.
> Note: I think Thunderbird uses its own SSL CA root certificates database...
The problem with postfix is that it runs chrooted and the CA
certificates are not copied into the chroot. See #287795�.
Sven
� http://bugs.debian.org/cgi-bin/bugreport.cgi?bug=287795
--
To UNSUBSCRIBE, email to debian-us...@lists.debian.org
with a subject of "unsubscribe". Trouble? Contact listm...@lists.debian.org
Clive Standbridge
> O.k. Then you need to setup Postfix SSL/TLS acting as client, not
> server.
Oh that's what I thought I did. I only changed smtp_* settings, not
smtpd_* settings.
> > So my questions are:
> > * How can I fix this in Postfix?
>
> Let's see the logs...
I already posted excerpts from /var/log/auth.log and /var/log/mail.log
I'm not sure which other logs are relevant.
> > * Can Postfix do this? Or do I need to change to something else
> > * e.g.
> > Exim?
>
> Yes, you can setup Postfix for this.
That's good, thanks.
> > * What does IceDove do that Postfix doesn't?
>
> Logs will tell.
Again, not sure which logs.
> The doc you have to follow stands here:
>
> http://www.postfix.org/SASL_README.html#client_sasl
Thanks. In fact I've used those settings, and for my old server, they work.
> > /var/log/mail.log:
>
> (...)
>
> > May 9 16:30:01 rimmer postfix/smtp[10643]: certificate verification failed for NEWSERVER[NEWSERVER-IPADDR]:587: untrusted issuer /L=ValiCert Validation Network/O=ValiCert, Inc./OU=ValiCert Class 2 Policy Validation Authority/CN=http://www.valicert.com//emailAddress=in...@valicert.com
>
> Server replies that does not trust the issuer of that CA.
>
> (...)
>
> > May 9 16:30:01 rimmer postfix/smtp[10643]: Untrusted TLS connection established to NEWSERVER[NEWSERVER-IPADDR]:587: TLSv1 with cipher RC4-MD5 (128/128 bits)
>
> I guess your are having problems with the certificate itself. It
> cannot
> be verified by the remote server.
The TLS part seems to be sorted now (see my reply to Sven).
But the authentication still fails.
Thanks for your help,
Clive
--
To UNSUBSCRIBE, email to debian-us...@lists.debian.org
with a subject of "unsubscribe". Trouble? Contact listm...@lists.debian.org
Archive: http://lists.debian.org/20100509231...@rimmer.esmertec.com
Clive Standbridge
> certificates are not copied into the chroot. See #287795¹.
>
> Sven
>
> ¹ http://bugs.debian.org/cgi-bin/bugreport.cgi?bug=287795
Hi Sven,
Thanks for that suggestion. I had seen that bug and discounted it
because the patch is only effective if smtp_tls_CApath is set, and
mine wasn't set. But your mail prompted another look, and with both
smtp_tls_CApath = /etc/ssl/certs and applying the patch from #287795,
it banished the "certificate verification failed" and changed
"Untrusted TLS connection established" to "Trusted TLS connection
established".
So that's progress :-)
Unfortunately it's still failing to authenticate. From mail.log:
May 9 21:49:18 rimmer postfix/smtp[8121]: 5DE243A66: to=<MY-EMAIL-ADDRESS>, relay=NEWSERVER[NEWSERVER-IPADDR]:587, delay=5.5, delays=0.02/0.03/5.4/0, dsn=4.7.3, status=deferred (SASL authentication failed; server NEWSERVER[NEWSERVER-IPADDR] said: 535 5.7.3 Authentication unsuccessful)
Thanks,
Clive
--
To UNSUBSCRIBE, email to debian-us...@lists.debian.org
with a subject of "unsubscribe". Trouble? Contact listm...@lists.debian.org
Archive: http://lists.debian.org/20100509223...@rimmer.esmertec.com
Clive Standbridge
> is the tool for troubleshooting this sort of thing. You have gotten
> lots of useful information from Postfix and telnet, but I'd try using
> swaks to communicate with the server with and without TLS, and you'll
> see, for any combination of connection and authentication options
> that you try, what works and what errors are received on failure.
Hi Celejar,
Thanks for that advice. I will take a look at swaks.
I have run out of weekend now, so it may take a day or two.
--
Cheers,
Clive
--
To UNSUBSCRIBE, email to debian-us...@lists.debian.org
with a subject of "unsubscribe". Trouble? Contact listm...@lists.debian.org
Archive: http://lists.debian.org/20100509231...@rimmer.esmertec.com
Camaleón
(...)
>> > May 9 16:30:01 rimmer postfix/smtp[10643]: Untrusted TLS connection
>> > established to NEWSERVER[NEWSERVER-IPADDR]:587: TLSv1 with cipher
>> > RC4-MD5 (128/128 bits)
>>
>> I guess your are having problems with the certificate itself. It cannot
>> be verified by the remote server.
>
> The TLS part seems to be sorted now (see my reply to Sven). But the
> authentication still fails.
Then, put the "full" Postfix log again so we can check where (and why) it
stops now :-)
Greetings,
--
Camaleón
--
To UNSUBSCRIBE, email to debian-us...@lists.debian.org
with a subject of "unsubscribe". Trouble? Contact listm...@lists.debian.org
Clive Standbridge
attempts to reply vanished).
> > The TLS part seems to be sorted now (see my reply to Sven). But
> the
> > authentication still fails.
>
> Then, put the "full" Postfix log again so we can check where (and
> why)
> it stops now :-)
Ahem, good point.
The attachments contain the lines written to /var/log/auth.log and
/var/log/mail.log when the attempt to mail via NEWSERVER:587 failed,
also my /etc/postfix/main.cf (without comments).
--
Cheers,
Clive
Camaleón
> The attachments contain the lines written to /var/log/auth.log and
> /var/log/mail.log when the attempt to mail via NEWSERVER:587 failed,
> also my /etc/postfix/main.cf (without comments).
I see nothing about the failure. All seems to go fine, Postfix
establishes a connection with remote server and silently fails :-/
Put Postfix into a more verbose logging. In "main.cf":
***
debug_peer_level = 2
debug_peer_list = NEWSERVER
***
Reload Postfix and try again.
P.S. 1 - Check the more basic here: saslauth mechanisms being used for
authenticating and of course, a correct password in "/etc/postfix/
sasl_passwd" O:-)
P.S. 2 - Remember that "535 5.7.3 Authentication unsuccessful" is a
message coming from Exchange server -not Postfix- so it would be great if
you could review the logs from the MS server side.