Hi,
In our postfix server, we see
SSL_accept error from hgrs-mail01.hgrs.tld.dom[161.x.y.z]: 0
Nov 16 08:54:52 ernesto postfix2cc/smtpd[18662]: warning: TLS library
problem: 18662:error:140943E8:SSL
routines:SSL3_READ_BYTES:reason(1000):s3_pkt.c:1053:SSL alert number 0:
This error message apparently means that the client aborted the handshake
just after receiving the server certificate (see step 14 in the upper half
of the wireshark sessions screenshot - a successful handshake example in the
lower part - there step 17 is how it would continue)
If anybody is interested, I am happy to bilaterally send the .pcap files for
the wireshark session and a screenshot of such wireshark sessions.
The domino-side log can be found below.
One hypothesis is that there is a Lotus Notes Domino bug (LO41163:
IMPROPERLY BUILDING CERT CHAIN WHEN FOREIGN HOST PRESENTS JUST LEAF CERT)
but the problem continued even when not just the leaf but also the leaf +
intermediate or incl. root respectively were sent by the postfix server. So
there must also be another problem.
Any hints how to do a client certificate authentication TLS-handshake
between IBM's v8.51 as the client and openssl on the server side would be
highly appreciated.
Many thanks in advance
Ralf
15.11.2011 14:36:07 [2114:0011-176C] SMTPClient: Connection successful
> Checking keyfile certificates:
15.11.2011 14:36:07.45 [2114:0011-176C] SSLCheckCertChain> Valid certificate
chain received
15.11.2011 14:36:07.45 [2114:0011-176C] int_MapSSLError> Mapping SSL error 0
to 0
15.11.2011 14:36:07.45 [2114:0011-176C] SSL_Handshake> Enter
15.11.2011 14:36:07.45 [2114:0011-176C] SSL_Handshake> Current Cipher 0x0000
(Unknown Cipher)
15.11.2011 14:36:07.45 [2114:0011-176C] SSL_Handshake> SSL Undetermined
attempt
15.11.2011 14:36:07.45 [2114:0011-176C] SSLAdvanceHandshake Enter> Processed
: 0 State: 4
15.11.2011 14:36:07.45 [2114:0011-176C] SSLAdvanceHandshake Enter> Processed
: SSL_hello_request
15.11.2011 14:36:07.45 [2114:0011-176C] SSLAdvanceHandshake calling
SSLPrepareAndQueueMessage> SSLEncodeClientHello
15.11.2011 14:36:07.45 [2114:0011-176C] SSLAdvanceHandshake Exit> State : 5
15.11.2011 14:36:07.45 [2114:0011-176C] S_Write> Enter len = 102
Xmt buffer:
...001 '......'
15.11.2011 14:36:07.45 [2114:0011-176C] S_Write> Switching Endpoint to sync
15.11.2011 14:36:07.45 [2114:0011-176C] S_Write> Posting a nti_snd for 102
bytes
15.11.2011 14:36:07.45 [2114:0011-176C] SSL_EncryptData> SSL not init exit
15.11.2011 14:36:07.45 [2114:0011-176C] S_Write> Switching Endpoint to async
15.11.2011 14:36:07.45 [2114:0011-176C] SSL_EncryptDataCleanup> SSL not init
exit
15.11.2011 14:36:07.45 [2114:0011-176C] S_Write> nti_done return 102 bytes
rc = 0
15.11.2011 14:36:07.45 [2114:0011-176C] S_Write> Exit, wrote 102 bytes
15.11.2011 14:36:07.45 [2114:0011-176C] S_Read> Enter len = 5
15.11.2011 14:36:07.45 [2114:0011-176C] S_Read> Switching Endpoint to sync
15.11.2011 14:36:07.45 [2114:0011-176C] S_Read> Posting a nti_rcv for 5
bytes
15.11.2011 14:36:07.45 [2114:0011-176C] SSL_RcvSetup> SSL not init exit
15.11.2011 14:36:07.47 [2114:0011-176C] S_Read> Switching Endpoint to async
15.11.2011 14:36:07.47 [2114:0011-176C] S_Read> nti_done return 5 bytes rc =
0
Rcv buffer:
00000000: 0000 0000 00 '.....'
15.11.2011 14:36:07.47 [2114:0011-176C] S_Read> Exit, read 5 bytes
15.11.2011 14:36:07.47 [2114:0011-176C] S_Read> Enter len = 74
15.11.2011 14:36:07.47 [2114:0011-176C] S_Read> Switching Endpoint to sync
15.11.2011 14:36:07.47 [2114:0011-176C] S_Read> Posting a nti_rcv for 74
bytes
15.11.2011 14:36:07.47 [2114:0011-176C] SSL_RcvSetup> SSL not init exit
15.11.2011 14:36:07.47 [2114:0011-176C] S_Read> Switching Endpoint to async
15.11.2011 14:36:07.47 [2114:0011-176C] S_Read> nti_done return 74 bytes rc
= 0
Rcv buffer:
-- 64 (0x0040) bytes of 0 --
15.11.2011 14:36:07.47 [2114:0011-176C] S_Read> Exit, read 74 bytes
15.11.2011 14:36:07.47 [2114:0011-176C] SSLProcessProtocolMessage> Record
Content: 22
15.11.2011 14:36:07.47 [2114:0011-176C] SSLProcessHandshakeMessage Enter>
Message: 2 State: 5 Key Exchange: 0 Cipher: 0x0000 (Unknown Cipher)
15.11.2011 14:36:07.47 [2114:0011-176C] SSLProcessHandshakeMessage Enter>
Message: SSL_server_hello
15.11.2011 14:36:07.47 [2114:0011-176C] SSLProcessHandshakeMessage Exit>
Message: 2 State: 5 Key Exchange: 1 Cipher: 0x0004 (RSA_WITH_RC4_128_MD5)
15.11.2011 14:36:07.47 [2114:0011-176C] SSLAdvanceHandshake Enter> Processed
: 2 State: 5
15.11.2011 14:36:07.47 [2114:0011-176C] SSLAdvanceHandshake Enter> Processed
: SSL_server_hello
15.11.2011 14:36:07.47 [2114:0011-176C] SSLAdvanceHandshake Exit> State : 8
15.11.2011 14:36:07.47 [2114:0011-176C] SSL_Handshake> After handshake
state= 8 Status= -5000
15.11.2011 14:36:07.47 [2114:0011-176C] SSL_Handshake> Exit Status = -5000
15.11.2011 14:36:07.47 [2114:0011-176C] int_MapSSLError> Mapping SSL error
-5000 to 4176
15.11.2011 14:36:07.47 [2114:0011-176C] SSL_Handshake> Enter
15.11.2011 14:36:07.47 [2114:0011-176C] SSL_Handshake> Current Cipher 0x0004
(RSA_WITH_RC4_128_MD5)
15.11.2011 14:36:07.47 [2114:0011-176C] S_Read> Enter len = 5
15.11.2011 14:36:07.47 [2114:0011-176C] S_Read> Switching Endpoint to sync
15.11.2011 14:36:07.47 [2114:0011-176C] S_Read> Posting a nti_rcv for 5
bytes
15.11.2011 14:36:07.47 [2114:0011-176C] SSL_RcvSetup> SSL not init exit
15.11.2011 14:36:07.47 [2114:0011-176C] S_Read> Switching Endpoint to async
15.11.2011 14:36:07.47 [2114:0011-176C] S_Read> nti_done return 5 bytes rc =
0
Rcv buffer:
00000000: 0002 4600 03 '...F.'
15.11.2011 14:36:07.47 [2114:0011-176C] S_Read> Exit, read 5 bytes
15.11.2011 14:36:07.47 [2114:0011-176C] S_Read> Enter len = 2866
15.11.2011 14:36:07.47 [2114:0011-176C] S_Read> Switching Endpoint to sync
15.11.2011 14:36:07.47 [2114:0011-176C] S_Read> Posting a nti_rcv for 2866
bytes
15.11.2011 14:36:07.47 [2114:0011-176C] SSL_RcvSetup> SSL not init exit
15.11.2011 14:36:07.47 [2114:0011-176C] S_Read> Switching Endpoint to async
15.11.2011 14:36:07.47 [2114:0011-176C] S_Read> nti_done return 2866 bytes
rc = 0
Rcv buffer:
-- 2864 (0x0B30) bytes of 0 --
15.11.2011 14:36:07.47 [2114:0011-176C] S_Read> Exit, read 2866 bytes
15.11.2011 14:36:07.47 [2114:0011-176C] SSLProcessProtocolMessage> Record
Content: 22
15.11.2011 14:36:07.47 [2114:0011-176C] SSLProcessHandshakeMessage Enter>
Message: 11 State: 8 Key Exchange: 1 Cipher: 0x0004 (RSA_WITH_RC4_128_MD5)
15.11.2011 14:36:07.47 [2114:0011-176C] SSLProcessHandshakeMessage Enter>
Message: SSL_certificate
15.11.2011 14:36:07.47 [2114:0011-176C] SSLCheckCertChain> Valid certificate
chain received
15.11.2011 14:36:07.47 [2114:0011-176C] SSLProcessHandshakeMessage Exit>
Message: 11 State: 8 Key Exchange: 1 Cipher: 0x0004 (RSA_WITH_RC4_128_MD5)
15.11.2011 14:36:07.47 [2114:0011-176C] SSLAdvanceHandshake Enter> Processed
: 11 State: 8
15.11.2011 14:36:07.47 [2114:0011-176C] SSLAdvanceHandshake Enter> Processed
: SSL_certificate
15.11.2011 14:36:07.47 [2114:0011-176C] SSLAdvanceHandshake Exit> State : 9
15.11.2011 14:36:07.48 [2114:0011-176C] SSL_Handshake> After handshake2
state 9
15.11.2011 14:36:07.48 [2114:0011-176C] SSL_Handshake> Exit Status = -5000
15.11.2011 14:36:07.48 [2114:0011-176C] int_MapSSLError> Mapping SSL error
-5000 to 4176
15.11.2011 14:36:07.48 [2114:0011-176C] SSL_Handshake> Enter
15.11.2011 14:36:07.48 [2114:0011-176C] SSL_Handshake> Current Cipher 0x0004
(RSA_WITH_RC4_128_MD5)
15.11.2011 14:36:07.48 [2114:0011-176C] S_Read> Enter len = 5
15.11.2011 14:36:07.48 [2114:0011-176C] S_Read> Switching Endpoint to sync
15.11.2011 14:36:07.48 [2114:0011-176C] S_Read> Posting a nti_rcv for 5
bytes
15.11.2011 14:36:07.48 [2114:0011-176C] SSL_RcvSetup> SSL not init exit
15.11.2011 14:36:07.48 [2114:0011-176C] S_Read> Switching Endpoint to async
15.11.2011 14:36:07.48 [2114:0011-176C] S_Read> nti_done return 5 bytes rc =
0
Rcv buffer:
00000000: 000B 2E0B 00 '.....'
15.11.2011 14:36:07.48 [2114:0011-176C] S_Read> Exit, read 5 bytes
15.11.2011 14:36:07.48 [2114:0011-176C] S_Read> Enter len = 13
15.11.2011 14:36:07.48 [2114:0011-176C] S_Read> Switching Endpoint to sync
15.11.2011 14:36:07.48 [2114:0011-176C] S_Read> Posting a nti_rcv for 13
bytes
15.11.2011 14:36:07.48 [2114:0011-176C] SSL_RcvSetup> SSL not init exit
15.11.2011 14:36:07.48 [2114:0011-176C] S_Read> Switching Endpoint to async
15.11.2011 14:36:07.48 [2114:0011-176C] S_Read> nti_done return 13 bytes rc
= 0
Rcv buffer:
00000000: 30CF 0482 A0B7 0203 0201 0202 2D 'O0..7 ......-'
15.11.2011 14:36:07.48 [2114:0011-176C] S_Read> Exit, read 13 bytes
15.11.2011 14:36:07.48 [2114:0011-176C] SSLProcessProtocolMessage> Record
Content: 22
15.11.2011 14:36:07.48 [2114:0011-176C] SSLProcessHandshakeMessage Enter>
Message: 13 State: 9 Key Exchange: 1 Cipher: 0x0004 (RSA_WITH_RC4_128_MD5)
15.11.2011 14:36:07.48 [2114:0011-176C] SSLProcessHandshakeMessage Enter>
Message: SSL_certificate_request
>> 15.11.2011 14:36:07.48 [2114:0011-176C] SSLSendAlert> Sending an alert of
0x0 level 0x2
15.11.2011 14:36:07.48 [2114:0011-176C] SSLProcessHandshakeMessage Exit>
Message: 13 State: 2 Key Exchange: 1 Cipher: 0x0004 (RSA_WITH_RC4_128_MD5)
15.11.2011 14:36:07.48 [2114:0011-176C] SSL_Handshake> Changing SSL status
from 5890 to -5000 to flush write queue
15.11.2011 14:36:07.48 [2114:0011-176C] SSL_Handshake> After handshake2
state 2
15.11.2011 14:36:07.48 [2114:0011-176C] SSL_Handshake> Exit Status = -5000
15.11.2011 14:36:07.48 [2114:0011-176C] int_MapSSLError> Mapping SSL error
-5000 to 4176
15.11.2011 14:36:07.48 [2114:0011-176C] SSL_Handshake> Enter
15.11.2011 14:36:07.48 [2114:0011-176C] SSL_Handshake> Current Cipher 0x0004
(RSA_WITH_RC4_128_MD5)
15.11.2011 14:36:07.48 [2114:0011-176C] S_Write> Enter len = 7
Xmt buffer:
00000000: 0315 0000 0202 00 '.......'
15.11.2011 14:36:07.48 [2114:0011-176C] S_Write> Switching Endpoint to sync
15.11.2011 14:36:07.48 [2114:0011-176C] S_Write> Posting a nti_snd for 7
bytes
15.11.2011 14:36:07.48 [2114:0011-176C] SSL_EncryptData> SSL not init exit
15.11.2011 14:36:07.48 [2114:0011-176C] S_Write> Switching Endpoint to async
15.11.2011 14:36:07.48 [2114:0011-176C] SSL_EncryptDataCleanup> SSL not init
exit
15.11.2011 14:36:07.48 [2114:0011-176C] S_Write> nti_done return 7 bytes rc
= 0
15.11.2011 14:36:07.48 [2114:0011-176C] S_Write> Exit, wrote 7 bytes
15.11.2011 14:36:07.48 [2114:0011-176C] SSL_Handshake> After handshake2
state 2
15.11.2011 14:36:07.48 [2114:0011-176C] SSL_Handshake> SSL Error: 5890
15.11.2011 14:36:07.48 [2114:0011-176C] int_MapSSLError> Mapping SSL error
5890 to 4171
15.11.2011 14:36:07.48 [2114:0011-176C] SSL_EncryptData> SSL not init exit
15.11.2011 14:36:07.48 [2114:0011-176C] SSL_EncryptDataCleanup> SSL not init
exit
15.11.2011 14:36:07.48 [2114:0011-176C] SSL_RcvSetup> SSL not init exit
15.11.2011 14:36:07.48 [2114:0011-176C] SSL_Poll> Enter
15.11.2011 14:36:07.48 [2114:0011-176C] SSL_Poll> Exit
...
See also http://article.gmane.org/gmane.mail.postfix.user/225249
______________________________________________________________________
OpenSSL Project http://www.openssl.org
User Support Mailing List openssl-users@openssl.org
Automated List Manager majord...@openssl.org
