TLS handshake error

Previous Topic Next Topic
 
classic Classic list List threaded Threaded
13 messages Options
Reply | Threaded
Open this post in threaded view
|

TLS handshake error

Ralf Hildebrandt
From my log:

May  8 10:08:06 mail-ausfall postfix/qmgr[20518]: 3C25D23FC64: from=<[hidden email]>, size=31290, nrcpt=1 (queue active)
May  8 10:08:06 mail-ausfall postfix/smtp[21663]: 3C25D23FC64: Cannot start TLS: handshake failure
May  8 10:08:06 mail-ausfall postfix/smtp[21663]: 3C25D23FC64: to=<[hidden email]>, relay=mpibmail.RZ-Berlin.mpg.de[141.14.128.174]:25, delay=0.34, delays=0.1/0/0.16/0.08, dsn=2.0.0, status=sent (250 Ok: queued as EDDDE5700E)

Using s_client I get:

# openssl s_client -starttls smtp -CAfile
/etc/ssl/certs/ca-certificates.crt -connect mpibmail.RZ-Berlin.mpg.de:25
CONNECTED(00000003)
depth=0 /C=DE/ST=Berlin/L=Berlin/O=Max-Planck-Institute for Human Development/OU=MPIB/CN=mpibmail.rz-berlin.mpg.de/emailAddress=[hidden email]
verify error:num=18:self signed certificate
verify return:1
depth=0 /C=DE/ST=Berlin/L=Berlin/O=Max-Planck-Institute for Human Development/OU=MPIB/CN=mpibmail.rz-berlin.mpg.de/emailAddress=[hidden email]
verify return:1
---
Certificate chain
 0 s:/C=DE/ST=Berlin/L=Berlin/O=Max-Planck-Institute for Human
Development/OU=MPIB/CN=mpibmail.rz-berlin.mpg.de/emailAddress=[hidden email]
   i:/C=DE/ST=Berlin/L=Berlin/O=Max-Planck-Institute for Human
Development/OU=MPIB/CN=mpibmail.rz-berlin.mpg.de/emailAddress=[hidden email]
---
Server certificate
-----BEGIN CERTIFICATE-----
... snip ...
-----END CERTIFICATE-----
subject=/C=DE/ST=Berlin/L=Berlin/O=Max-Planck-Institute for Human Development/OU=MPIB/CN=mpibmail.rz-berlin.mpg.de/emailAddress=[hidden email]
issuer=/C=DE/ST=Berlin/L=Berlin/O=Max-Planck-Institute for Human Development/OU=MPIB/CN=mpibmail.rz-berlin.mpg.de/emailAddress=[hidden email]
---
Acceptable client certificate CA names
/C=AU/ST=QLD/O=Mincom Pty. Ltd./OU=CS/CN=SSLeay demo server
---
SSL handshake has read 1739 bytes and written 363 bytes
---
New, TLSv1/SSLv3, Cipher is DHE-RSA-AES256-SHA
Server public key is 1024 bit
Compression: NONE
Expansion: NONE
SSL-Session:
    Protocol  : TLSv1
    Cipher    : DHE-RSA-AES256-SHA
    Session-ID: 00C57001F1A97F8B42283FEB44A1E042E6A3347B3492C6D5D27927E52D5CD600
    Session-ID-ctx:
    Master-Key: CFDFCCB1291DC18825D47476058C582F7248AFEAE5DBE83FD9B3880C1A52FE694F0A1711341BD791D3F4AF49B6DA2D78
    Key-Arg   : None
    Start Time: 1210252689
    Timeout   : 300 (sec)
    Verify return code: 18 (self signed certificate)
---
250 8BITMIME
QUIT
DONE

So it's self signed, but why do I get a "Cannot start TLS: handshake
failure" ?

--
Ralf Hildebrandt ([hidden email])          [hidden email]
Postfix - Einrichtung, Betrieb und Wartung       Tel. +49 (0)30-450 570-155
http://www.arschkrebs.de
Ich habe hier Windows 2000 spontan f�llt mir dazu die Szene aus das
"Leben des Brian" ein, in der der Mitgefangene im Kerker Brian als
G�nstling bezeichnet, weil er vom Kerkermeister angespuckt wurde.
Reply | Threaded
Open this post in threaded view
|

Re: TLS handshake error

Ralf Hildebrandt
* Ralf Hildebrandt <[hidden email]>:
> From my log:
>
> May  8 10:08:06 mail-ausfall postfix/qmgr[20518]: 3C25D23FC64: from=<[hidden email]>, size=31290, nrcpt=1 (queue active)
> May  8 10:08:06 mail-ausfall postfix/smtp[21663]: 3C25D23FC64: Cannot start TLS: handshake failure
> May  8 10:08:06 mail-ausfall postfix/smtp[21663]: 3C25D23FC64: to=<[hidden email]>, relay=mpibmail.RZ-Berlin.mpg.de[141.14.128.174]:25, delay=0.34, delays=0.1/0/0.16/0.08, dsn=2.0.0, status=sent (250 Ok: queued as EDDDE5700E)
...
> So it's self signed, but why do I get a "Cannot start TLS: handshake
> failure" ?

I increased the log level to 2 and now I get:

May  8 15:25:21 mail-ausfall postfix/smtp[27774]: setting up TLS connection to mpibmail.RZ-Berlin.mpg.de[141.14.128.174]:25
May  8 15:25:21 mail-ausfall postfix/smtp[27774]: mpibmail.RZ-Berlin.mpg.de[141.14.128.174]:25: TLS cipher list "ALL:+RC4:@STRENGTH"
May  8 15:25:21 mail-ausfall postfix/smtp[27774]: Untrusted TLS connection established to mpibmail.RZ-Berlin.mpg.de[141.14.128.174]:25: TLSv1 with cipher DHE-RSA-AES256-SHA (256/256 bits)
May  8 15:25:21 mail-ausfall postfix/smtp[27774]: 737C223FC2B: to=<[hidden email]>, relay=mpibmail.RZ-Berlin.mpg.de[141.14.128.174]:25, delay=0.3,
delays=0.09/0/0.18/0.03, dsn=2.0.0, status=sent (250 Ok: queued as 03C395715D)

WTF? It's working now? Argh!


--
Ralf Hildebrandt ([hidden email])          [hidden email]
Postfix - Einrichtung, Betrieb und Wartung       Tel. +49 (0)30-450 570-155
http://www.arschkrebs.de
If you were an SCO employee, would you feel at least a little
concerned that your boss is aparently dilusional? I know I would.
Reply | Threaded
Open this post in threaded view
|

Re: TLS handshake error

Victor Duchovni
In reply to this post by Ralf Hildebrandt
On Thu, May 08, 2008 at 03:19:26PM +0200, Ralf Hildebrandt wrote:

> From my log:
>
> May  8 10:08:06 mail-ausfall postfix/qmgr[20518]: 3C25D23FC64: from=<[hidden email]>, size=31290, nrcpt=1 (queue active)
> May  8 10:08:06 mail-ausfall postfix/smtp[21663]: 3C25D23FC64: Cannot start TLS: handshake failure
> May  8 10:08:06 mail-ausfall postfix/smtp[21663]: 3C25D23FC64: to=<[hidden email]>, relay=mpibmail.RZ-Berlin.mpg.de[141.14.128.174]:25, delay=0.34, delays=0.1/0/0.16/0.08, dsn=2.0.0, status=sent (250 Ok: queued as EDDDE5700E)

This is you sending,  a different issue and a different site. You should
start a new mail thread for this. Using the unreleased "smtp-finger",
which uses the same Postfix TLS client code as the Postfix SMTP client,
I get (the other side is running Postfix also, so there is little reason
to expect this to fail, do report more detailed logging, more error
information was likely logged by the SMTP client with the same pid,
but without the queue-id which is not known to the TLS client library):

smtp-finger: initializing the client-side TLS engine
smtp-finger: Connected to 141.14.128.174[141.14.128.174]:25
smtp-finger: < 220 mpibmail.rz-berlin.mpg.de ESMTP Postfix
smtp-finger: > EHLO hqmtabh2.ms.com
smtp-finger: < 250-mpibmail.rz-berlin.mpg.de
smtp-finger: < 250-PIPELINING
smtp-finger: < 250-SIZE 102400000
smtp-finger: < 250-VRFY
smtp-finger: < 250-ETRN
smtp-finger: < 250-STARTTLS
smtp-finger: < 250-AUTH NTLM LOGIN PLAIN GSSAPI OTP DIGEST-MD5 CRAM-MD5
smtp-finger: < 250-AUTH=NTLM LOGIN PLAIN GSSAPI OTP DIGEST-MD5 CRAM-MD5
smtp-finger: < 250 8BITMIME
smtp-finger: > STARTTLS
smtp-finger: < 220 Ready to start TLS
smtp-finger: setting up TLS connection to 141.14.128.174[141.14.128.174]:25
smtp-finger: 141.14.128.174[141.14.128.174]:25: TLS cipher list "ALL:+RC4:@STRENGTH:!eNULL"
smtp-finger: 141.14.128.174[141.14.128.174]:25: certificate verification depth=0 verify=0 subject=/C=DE/ST=Berlin/L=Berlin/O=Max-Planck-Institute for Human Development/OU=MPIB/CN=mpibmail.rz-berlin.mpg.de/emailAddress=[hidden email]
smtp-finger: certificate verification failed for 141.14.128.174[141.14.128.174]:25: self-signed certificate
smtp-finger: 141.14.128.174[141.14.128.174]:25: certificate verification depth=0 verify=1 subject=/C=DE/ST=Berlin/L=Berlin/O=Max-Planck-Institute for Human Development/OU=MPIB/CN=mpibmail.rz-berlin.mpg.de/emailAddress=[hidden email]
smtp-finger: 141.14.128.174[141.14.128.174]:25 sha1 fingerprint DD:62:BE:A1:E3:5A:F1:F6:69:D1:19:85:77:95:38:E5:15:BE:76:5D
smtp-finger: Untrusted TLS connection established to 141.14.128.174[141.14.128.174]:25: TLSv1 with cipher DHE-RSA-AES256-SHA (256/256 bits)
---
Certificate chain
 0 s:/C=DE/ST=Berlin/L=Berlin/O=Max-Planck-Institute for Human Development/OU=MPIB/CN=mpibmail.rz-berlin.mpg.de/emailAddress=[hidden email]
   i:/C=DE/ST=Berlin/L=Berlin/O=Max-Planck-Institute for Human Development/OU=MPIB/CN=mpibmail.rz-berlin.mpg.de/emailAddress=[hidden email]
-----BEGIN CERTIFICATE-----
MIIC9zCCAmACCQDxbx2yUS/UqDANBgkqhkiG9w0BAQUFADCBvzELMAkGA1UEBhMC
REUxDzANBgNVBAgTBkJlcmxpbjEPMA0GA1UEBxMGQmVybGluMTMwMQYDVQQKEypN
YXgtUGxhbmNrLUluc3RpdHV0ZSBmb3IgSHVtYW4gRGV2ZWxvcG1lbnQxDTALBgNV
BAsTBE1QSUIxIjAgBgNVBAMTGW1waWJtYWlsLnJ6LWJlcmxpbi5tcGcuZGUxJjAk
BgkqhkiG9w0BCQEWF21hbnRlQGZoaS1iZXJsaW4ubXBnLmRlMB4XDTA3MDcwNjEw
MzMxNVoXDTE3MDcwMzEwMzMxNVowgb8xCzAJBgNVBAYTAkRFMQ8wDQYDVQQIEwZC
ZXJsaW4xDzANBgNVBAcTBkJlcmxpbjEzMDEGA1UEChMqTWF4LVBsYW5jay1JbnN0
aXR1dGUgZm9yIEh1bWFuIERldmVsb3BtZW50MQ0wCwYDVQQLEwRNUElCMSIwIAYD
VQQDExltcGlibWFpbC5yei1iZXJsaW4ubXBnLmRlMSYwJAYJKoZIhvcNAQkBFhdt
YW50ZUBmaGktYmVybGluLm1wZy5kZTCBnzANBgkqhkiG9w0BAQEFAAOBjQAwgYkC
gYEA9DLVfJERm5Xma78th46UXWv4ZKM868eTlKQYH5ejf3QW5if+p8IrUjQWpzR6
VtUKuuAEx71mQg/FbfM9oH5X9MKxYpWaJVw/nPaU63jSbnQ5simvVSzdaeLdma3N
pChxsvLVmPsYCTUjYdg5UfUiVERtHeR+3c03dLwc6MWtBRUCAwEAATANBgkqhkiG
9w0BAQUFAAOBgQAcZDUBFrwEJcH0tWIcwJoBpoL0ypHwPJNGFda6dvwDHNjoXp9n
13rUA0RHchsIK3FjoqaJdZdYeSHUsne7B95kyGy0jiCvwXzzFKxyChPTSnGtAYr5
S9pqg8zaptgy1OWZ2zbTkvW8peZol/TCIEEGDzLnTydZXw14tLzwv0PdbA==
-----END CERTIFICATE-----
smtp-finger: > QUIT
smtp-finger: < 221 Bye

--
        Viktor.

Disclaimer: off-list followups get on-list replies or get ignored.
Please do not ignore the "Reply-To" header.

To unsubscribe from the postfix-users list, visit
http://www.postfix.org/lists.html or click the link below:
<mailto:[hidden email]?body=unsubscribe%20postfix-users>

If my response solves your problem, the best way to thank me is to not
send an "it worked, thanks" follow-up. If you must respond, please put
"It worked, thanks" in the "Subject" so I can delete these quickly.
Reply | Threaded
Open this post in threaded view
|

Re: TLS handshake error

Victor Duchovni
In reply to this post by Ralf Hildebrandt
On Thu, May 08, 2008 at 03:31:38PM +0200, Ralf Hildebrandt wrote:

> WTF? It's working now? Argh!

The other side was briefly misconfigured? They have a load-balancer
behind that IP address and some systems are misconfigured? Firewalls
messing with traffic? Bit errors in switches/routers along the
network path? ...

--
        Viktor.

Disclaimer: off-list followups get on-list replies or get ignored.
Please do not ignore the "Reply-To" header.

To unsubscribe from the postfix-users list, visit
http://www.postfix.org/lists.html or click the link below:
<mailto:[hidden email]?body=unsubscribe%20postfix-users>

If my response solves your problem, the best way to thank me is to not
send an "it worked, thanks" follow-up. If you must respond, please put
"It worked, thanks" in the "Subject" so I can delete these quickly.
Reply | Threaded
Open this post in threaded view
|

Re: TLS handshake error

Ralf Hildebrandt
In reply to this post by Victor Duchovni
* Victor Duchovni <[hidden email]>:

> On Thu, May 08, 2008 at 03:19:26PM +0200, Ralf Hildebrandt wrote:
>
> > From my log:
> >
> > May  8 10:08:06 mail-ausfall postfix/qmgr[20518]: 3C25D23FC64: from=<[hidden email]>, size=31290, nrcpt=1 (queue active)
> > May  8 10:08:06 mail-ausfall postfix/smtp[21663]: 3C25D23FC64: Cannot start TLS: handshake failure
> > May  8 10:08:06 mail-ausfall postfix/smtp[21663]: 3C25D23FC64: to=<[hidden email]>, relay=mpibmail.RZ-Berlin.mpg.de[141.14.128.174]:25, delay=0.34, delays=0.1/0/0.16/0.08, dsn=2.0.0, status=sent (250 Ok: queued as EDDDE5700E)
>
> This is you sending,  a different issue and a different site. You should
> start a new mail thread for this.

I did!

> Using the unreleased "smtp-finger", which uses the same Postfix TLS
> client code as the Postfix SMTP client, I get (the other side is
> running Postfix also, so there is little reason to expect this to fail,
> do report more detailed logging, more error information was likely
> logged by the SMTP client with the same pid, but without the queue-id
> which is not known to the TLS client library):

Nothing in the log (at smtp_tls_loglevel=1)

May  8 10:08:06 mail-ausfall postfix/smtp[21663]: setting up TLS connection to mpibmail.RZ-Berlin.mpg.de[141.14.128.174]:25
May  8 10:08:06 mail-ausfall postfix/lmtp[23270]: 9A27F23FC6C: to=<[hidden email]>, relay=127.0.0.1[127.0.0.1]:10025, delay=3.7, delays=2.8/0/0.01/0.96, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as 3C25D23FC64)
May  8 10:08:06 mail-ausfall postfix/qmgr[20518]: 9A27F23FC6C: removed
May  8 10:08:06 mail-ausfall postfix/smtp[21663]: certificate verification failed for mpibmail.rz-berlin.mpg.de[141.14.128.174]:25: self-signed certificate
May  8 10:08:06 mail-ausfall postfix/smtp[21663]: SSL_connect error to mpibmail.RZ-Berlin.mpg.de[141.14.128.174]:25: -1
May  8 10:08:06 mail-ausfall postfix/smtp[21663]: 3C25D23FC64: Cannot start TLS: handshake failure
May  8 10:08:06 mail-ausfall postfix/smtp[21663]: Host offered STARTTLS: [mpibmail.RZ-Berlin.mpg.de]
May  8 10:08:06 mail-ausfall postfix/smtp[21663]: 3C25D23FC64: to=<[hidden email]>, relay=mpibmail.RZ-Berlin.mpg.de[141.14.128.174]:25, delay=0.34, delays=0.1/0/0.16/0.08, dsn=2.0.0, status=sent (250 Ok: queued as EDDDE5700E)
May  8 10:08:06 mail-ausfall postfix/qmgr[20518]: 3C25D23FC64: removed

That was all. I then set smtp_tls_loglevel=2, and strange enough --
NOW it seems to work (see my other post).

--
Ralf Hildebrandt ([hidden email])          [hidden email]
Postfix - Einrichtung, Betrieb und Wartung       Tel. +49 (0)30-450 570-155
http://www.arschkrebs.de
Bei Produkten von Siemens muss ich immer an "Asterix in Korsika" denken:
"Bring Wein und Wurst, aber nicht von dem Zeug f?r die Kunden!"
Reply | Threaded
Open this post in threaded view
|

Re: TLS handshake error

Ralf Hildebrandt
In reply to this post by Victor Duchovni
* Victor Duchovni <[hidden email]>:
> On Thu, May 08, 2008 at 03:31:38PM +0200, Ralf Hildebrandt wrote:
>
> > WTF? It's working now? Argh!
>
> The other side was briefly misconfigured?

For weeks on end? I just got around fixing all the TLS issues I found,
and that problem had been active for months!

> They have a load-balancer behind that IP address and some systems are
> misconfigured?

AHA, that could be. Well, I'll be in touch with the postmistress soon.

--
Ralf Hildebrandt ([hidden email])          [hidden email]
Postfix - Einrichtung, Betrieb und Wartung       Tel. +49 (0)30-450 570-155
http://www.arschkrebs.de
Veröffentlichung genehmigt durch die Zensurbehörde des Ministeriums für
Meinungssicherheit (MeiSi) gemäß des Gesetzes zum Schutze der
öffentlichen Meinungsfreiheit und zum Schutze des Pluralismus.
Reply | Threaded
Open this post in threaded view
|

Re: TLS handshake error

Victor Duchovni
On Thu, May 08, 2008 at 04:08:47PM +0200, Ralf Hildebrandt wrote:

> * Victor Duchovni <[hidden email]>:
> > On Thu, May 08, 2008 at 03:31:38PM +0200, Ralf Hildebrandt wrote:
> >
> > > WTF? It's working now? Argh!
> >
> > The other side was briefly misconfigured?
>
> For weeks on end? I just got around fixing all the TLS issues I found,
> and that problem had been active for months!
>
> > They have a load-balancer behind that IP address and some systems are
> > misconfigured?
>
> AHA, that could be. Well, I'll be in touch with the postmistress soon.

Did all deliveries experience the issue, or just some? All all deliveries
succeeding now? The load-balancer theory is not entirely plausible, I
get a consistent 220 banner from this IP:

    220 mpibmail.rz-berlin.mpg.de ESMTP Postfix

and no handshake problems... What problem rate did you see?

--
        Viktor.

Disclaimer: off-list followups get on-list replies or get ignored.
Please do not ignore the "Reply-To" header.

To unsubscribe from the postfix-users list, visit
http://www.postfix.org/lists.html or click the link below:
<mailto:[hidden email]?body=unsubscribe%20postfix-users>

If my response solves your problem, the best way to thank me is to not
send an "it worked, thanks" follow-up. If you must respond, please put
"It worked, thanks" in the "Subject" so I can delete these quickly.
Reply | Threaded
Open this post in threaded view
|

Re: TLS handshake error

Ralf Hildebrandt
* Victor Duchovni <[hidden email]>:

> > AHA, that could be. Well, I'll be in touch with the postmistress soon.
>
> Did all deliveries experience the issue, or just some? All all deliveries
> succeeding now? The load-balancer theory is not entirely plausible, I
> get a consistent 220 banner from this IP:
>
>     220 mpibmail.rz-berlin.mpg.de ESMTP Postfix
>
> and no handshake problems... What problem rate did you see?

I just did:
# zfgrep  -h "SSL_connect error to mpibmail.RZ-Berlin.mpg.de" /var/log/OLD/2008-04-*/mail.log.gz |wc -l
    125
   
# zfgrep  -h "TLS connection established to mpibmail.RZ-Berlin.mpg.de" /var/log/OLD/2008-04-*/mail.log.gz |wc -l
    192

Hmm

--
Ralf Hildebrandt ([hidden email])          [hidden email]
Postfix - Einrichtung, Betrieb und Wartung       Tel. +49 (0)30-450 570-155
http://www.arschkrebs.de
To do the actual install you have to be root, but none of the normal
build should require that. Don't take the name of root in vain.
- /usr/src/linux/README
Reply | Threaded
Open this post in threaded view
|

Re: TLS handshake error

Ralf Hildebrandt
In reply to this post by Victor Duchovni
> Did all deliveries experience the issue, or just some? All all deliveries
> succeeding now? The load-balancer theory is not entirely plausible, I
> get a consistent 220 banner from this IP:

The other side reports in it's log (don't ask me why every line is
duplicated!):

> > May  8 15:59:16 mpibmail postfix/smtpd[8784]: [ID 197553 mail.info] connect from mail-ausfall.charite.de[193.175.70.131]
> > May  8 15:59:16 mpibmail postfix/smtpd[8784]: [ID 197553 mail.info] connect from mail-ausfall.charite.de[193.175.70.131]
> > May  8 15:59:16 mpibmail postfix/smtpd[8784]: [ID 197553 mail.info] setting up TLS connection from mail-ausfall.charite.de[193.175.70.131]
> > May  8 15:59:16 mpibmail postfix/smtpd[8784]: [ID 197553 mail.info] setting up TLS connection from mail-ausfall.charite.de[193.175.70.131]
> > May  8 15:59:16 mpibmail postfix/smtpd[8784]: [ID 197553 mail.info] certificate verification failed for mail-ausfall.charite.de: num=20:unable to get local issuer certificate
> > May  8 15:59:16 mpibmail postfix/smtpd[8784]: [ID 197553 mail.info] certificate verification failed for mail-ausfall.charite.de: num=20:unable to get local issuer certificate
> > May  8 15:59:16 mpibmail postfix/smtpd[8784]: [ID 197553 mail.info] certificate verification failed for mail-ausfall.charite.de: num=27:certificate not trusted
> > May  8 15:59:16 mpibmail postfix/smtpd[8784]: [ID 197553 mail.info] certificate verification failed for mail-ausfall.charite.de: num=27:certificate not trusted
> > May  8 15:59:16 mpibmail postfix/smtpd[8784]: [ID 197553 mail.info] certificate verification failed for mail-ausfall.charite.de: num=21:unable to verify the first certificate
> > May  8 15:59:16 mpibmail postfix/smtpd[8784]: [ID 197553 mail.info] certificate verification failed for mail-ausfall.charite.de: num=21:unable  to verify the first certificate
> > May  8 15:59:16 mpibmail postfix/smtpd[8784]: [ID 197553 mail.info] SSL_accept error from mail-ausfall.charite.de[193.175.70.131]: -1
> > May  8 15:59:16 mpibmail postfix/smtpd[8784]: [ID 197553 mail.info] SSL_accept error from mail-ausfall.charite.de[193.175.70.131]: -1
> > May  8 15:59:16 mpibmail postfix/smtpd[8784]: [ID 197553 mail.info] lost connection after STARTTLS from mail-ausfall.charite.de[193.175.70.131]
> > May  8 15:59:16 mpibmail postfix/smtpd[8784]: [ID 197553 mail.info] disconnect from mail-ausfall.charite.de[193.175.70.131]
> > May  8 15:59:16 mpibmail postfix/smtpd[8784]: [ID 197553 mail.info] lost connection after STARTTLS from mail-ausfall.charite.de[193.175.70.131]
> > May  8 15:59:16 mpibmail postfix/smtpd[8784]: [ID 197553 mail.info] disconnect from mail-ausfall.charite.de[193.175.70.131]

Ha, next problem: "May  8 15:59:16" -- I don't even see a connection
then. Maybe their clock is off :(

My most recent entry is:

May  8 16:07:28 mail-ausfall postfix/smtp[1132]: setting up TLS connection to mpibmail.RZ-Berlin.mpg.de[141.14.128.174]:25
May  8 16:07:28 mail-ausfall postfix/smtp[1132]: mpibmail.RZ-Berlin.mpg.de[141.14.128.174]:25: TLS cipher list "ALL:+RC4:@STRENGTH"
May  8 16:07:28 mail-ausfall postfix/smtp[1132]: looking for session smtp:141.14.128.174:25:mpibmail.rz-berlin.mpg.de&p=0&c=ALL:+RC4:@STRENGTH in smtp cache
May  8 16:07:28 mail-ausfall postfix/tlsmgr[27723]: lookup smtp session id=smtp:141.14.128.174:25:mpibmail.rz-berlin.mpg.de&p=0&c=ALL:+RC4:@STRENGTH
May  8 16:07:28 mail-ausfall postfix/tlsmgr[27723]: read smtp TLS cache entry smtp:141.14.128.174:25:mpibmail.rz-berlin.mpg.de&p=0&c=ALL:+RC4:@STRENGTH: time=121025 3920 [data 889 bytes]
May  8 16:07:28 mail-ausfall postfix/smtp[1132]: reloaded session smtp:141.14.128.174:25:mpibmail.rz-berlin.mpg.de&p=0&c=ALL:+RC4:@STRENGTH from smtp cache
May  8 16:07:28 mail-ausfall postfix/qmgr[27718]: 5FA0223FC6F: removed
May  8 16:07:28 mail-ausfall postfix/smtp[1132]: SSL_connect:before/connect initialization
May  8 16:07:28 mail-ausfall postfix/smtp[1132]: SSL_connect:SSLv3 write client hello A
May  8 16:07:28 mail-ausfall postfix/smtp[1132]: SSL_connect:SSLv3 read server hello A
May  8 16:07:28 mail-ausfall postfix/smtp[1132]: mpibmail.rz-berlin.mpg.de[141.14.128.174]:25: certificate verification depth=0 verify=0 subject=/C=DE/ST=Berlin/L=Berlin/O=Max-Planck-Institute for Human Development/OU=MPIB/CN=mpibmail.rz-berlin.mpg.de/emailAddress=[hidden email]
May  8 16:07:28 mail-ausfall postfix/smtp[1132]: certificate verification failed for mpibmail.rz-berlin.mpg.de[141.14.128.174]:25: self-signed certificate
May  8 16:07:28 mail-ausfall postfix/smtp[1132]: mpibmail.rz-berlin.mpg.de[141.14.128.174]:25: certificate verification depth=0 verify=1 subject=/C=DE/ST=Berlin/L=B erlin/O=Max-Planck-Institute for Human Development/OU=MPIB/CN=mpibmail.rz-berlin.mpg.de/emailAddress=[hidden email]
May  8 16:07:28 mail-ausfall postfix/smtp[1132]: SSL_connect:SSLv3 read server certificate A
May  8 16:07:28 mail-ausfall postfix/smtp[1132]: SSL_connect:SSLv3 read server key exchange A
May  8 16:07:28 mail-ausfall postfix/smtp[1132]: SSL_connect:SSLv3 read server certificate request A
May  8 16:07:28 mail-ausfall postfix/smtp[1132]: SSL_connect:SSLv3 read server done A
May  8 16:07:28 mail-ausfall postfix/smtp[1132]: SSL_connect:SSLv3 write client certificate A
May  8 16:07:28 mail-ausfall postfix/smtp[1132]: SSL_connect:SSLv3 write client key exchange A
May  8 16:07:28 mail-ausfall postfix/smtp[1132]: SSL_connect:SSLv3 write certificate verify A
May  8 16:07:28 mail-ausfall postfix/smtp[1132]: SSL_connect:SSLv3 write change cipher spec A
May  8 16:07:28 mail-ausfall postfix/smtp[1132]: SSL_connect:SSLv3 write finished A
May  8 16:07:28 mail-ausfall postfix/smtp[1132]: SSL_connect:SSLv3 flush data
May  8 16:07:28 mail-ausfall postfix/smtp[1132]: SSL_connect error to mpibmail.RZ-Berlin.mpg.de[141.14.128.174]:25: -1
May  8 16:07:28 mail-ausfall postfix/smtp[1132]: remove session smtp:141.14.128.174:25:mpibmail.rz-berlin.mpg.de&p=0&c=ALL:+RC4:@STRENGTH from client cache
May  8 16:07:28 mail-ausfall postfix/tlsmgr[27723]: delete smtp session id=smtp:141.14.128.174:25:mpibmail.rz-berlin.mpg.de&p=0&c=ALL:+RC4:@STRENGTH
May  8 16:07:28 mail-ausfall postfix/smtp[1132]: 6FC6A23FC64: Cannot start TLS: handshake failure
May  8 16:07:28 mail-ausfall postfix/smtp[1132]: Host offered STARTTLS: [mpibmail.RZ-Berlin.mpg.de]

--
Ralf Hildebrandt ([hidden email])          [hidden email]
Postfix - Einrichtung, Betrieb und Wartung       Tel. +49 (0)30-450 570-155
http://www.arschkrebs.de
In my opinion M$ is a lot better at making money than it is at making good
operating systems.                                       -- Linus Torvalds
Reply | Threaded
Open this post in threaded view
|

Re: TLS handshake error

Ralf Hildebrandt
* Ralf Hildebrandt <[hidden email]>:

> My most recent entry is:

I called them. The solution:

They use a greylisting proxy which distributes the SMTP connections to
a farm of servers.

In my particular case the recipient domain is hosted by 3 hosts in the
backend. One of these is probably misconfigured.

--
Ralf Hildebrandt ([hidden email])          [hidden email]
Postfix - Einrichtung, Betrieb und Wartung       Tel. +49 (0)30-450 570-155
http://www.arschkrebs.de
You step in the stream,
But the water has moved on.
This page is not here.
Reply | Threaded
Open this post in threaded view
|

Re: TLS handshake error

Victor Duchovni
In reply to this post by Ralf Hildebrandt
On Thu, May 08, 2008 at 04:22:32PM +0200, Ralf Hildebrandt wrote:

> I just did:
> # zfgrep  -h "SSL_connect error to mpibmail.RZ-Berlin.mpg.de" /var/log/OLD/2008-04-*/mail.log.gz |wc -l
>     125
>    
> # zfgrep  -h "TLS connection established to mpibmail.RZ-Berlin.mpg.de" /var/log/OLD/2008-04-*/mail.log.gz |wc -l
>     192

So the problem was "intermittent" (and relatively frequent). What is the
full logging footprint of a failed delivery (all messages from smtp[pid]
after previous delivery through the end of the delivery that exhibits the
TLS handshake failure)?

Were the errors clustered or randomly distributed? Can you report the
date/time values for all success failure cases in chronological order:

        YYYY/MM/DD HH:MM:SS OK
        YYYY/MM/DD HH:MM:SS FAIL
        YYYY/MM/DD HH:MM:SS OK
        ...

What version of OpenSSL is your Postfix using? Is it your own OpenSSL
build, or a stock distribution version? What happens if you try "s_client"
a few times, do any fail? What version of OpenSSL is s_client using?

--
        Viktor.

Disclaimer: off-list followups get on-list replies or get ignored.
Please do not ignore the "Reply-To" header.

To unsubscribe from the postfix-users list, visit
http://www.postfix.org/lists.html or click the link below:
<mailto:[hidden email]?body=unsubscribe%20postfix-users>

If my response solves your problem, the best way to thank me is to not
send an "it worked, thanks" follow-up. If you must respond, please put
"It worked, thanks" in the "Subject" so I can delete these quickly.
Reply | Threaded
Open this post in threaded view
|

Re: TLS handshake error

Victor Duchovni
In reply to this post by Ralf Hildebrandt
On Thu, May 08, 2008 at 04:29:43PM +0200, Ralf Hildebrandt wrote:

> > > May  8 15:59:16 mpibmail postfix/smtpd[8784]: [ID 197553 mail.info] setting up TLS connection from mail-ausfall.charite.de[193.175.70.131]
> > > May  8 15:59:16 mpibmail postfix/smtpd[8784]: [ID 197553 mail.info] certificate verification failed for mail-ausfall.charite.de: num=20:unable to get local issuer certificate

They are asking for client certs (I wonder why) and your SMTP client is
configured with client certs (I wonder why). While the problem may be
elsewhere, you should probably have "smtp_tls_cert_file = " (empty)
and only configure client certs for specific transports that deliver
mail to sites which require you to present a specific certificate.

Sending client certs just asks for trouble (more things to go wrong).

Of course the problem can also be a data-dependent glitch in the proxy
you mentioned in a later message.

--
        Viktor.

Disclaimer: off-list followups get on-list replies or get ignored.
Please do not ignore the "Reply-To" header.

To unsubscribe from the postfix-users list, visit
http://www.postfix.org/lists.html or click the link below:
<mailto:[hidden email]?body=unsubscribe%20postfix-users>

If my response solves your problem, the best way to thank me is to not
send an "it worked, thanks" follow-up. If you must respond, please put
"It worked, thanks" in the "Subject" so I can delete these quickly.
Reply | Threaded
Open this post in threaded view
|

Re: TLS handshake error

Ralf Hildebrandt
* Victor Duchovni <[hidden email]>:

> They are asking for client certs (I wonder why) and your SMTP client is
> configured with client certs (I wonder why). While the problem may be
> elsewhere, you should probably have "smtp_tls_cert_file = " (empty)
> and only configure client certs for specific transports that deliver
> mail to sites which require you to present a specific certificate.

Fixed.
 
> Sending client certs just asks for trouble (more things to go wrong).

Yes, I've seen that when I used:
smtpd_tls_ask_ccert = yes
 
> Of course the problem can also be a data-dependent glitch in the proxy
> you mentioned in a later message.

:)

--
Ralf Hildebrandt ([hidden email])          [hidden email]
Postfix - Einrichtung, Betrieb und Wartung       Tel. +49 (0)30-450 570-155
http://www.arschkrebs.de
"The computer programmer is a creator of universes for which he alone
is responsible. Universes of virtually unlimited complexity can be
created in the form of computer programs."-Joseph Weizenbaum