Discussion:
TLS library problem: decryption failed or bad record mac
(too old to reply)
Jairsinho Ramirez Ruiz
2007-03-19 04:45:31 UTC
Permalink
I am trying to get TLS work on Solaris 10 (sparc). I've compiled
Postfix 2.3.8 with Cyrus SASL 2.1.22, OpenLdap 2.3.34 and OpenSSL
0.9.8e (with and whitout zlib), however I cannot get TLS work. I've
tried compiling all libraries as static and shared. Everything works
fine (SASL, LDAP lookups, etc) even can start tls session, however on
the TLS proccess(?) something is not working, 'cause I get the
following error:

Mar 15 18:50:03 zonebox postfix/smtpd[3638]: [ID 197553 mail.info]
SSL3 alert write:fatal:bad record mac
Mar 15 18:50:03 zonebox postfix/smtpd[3638]: [ID 197553 mail.info]
SSL_accept:error in SSLv3 read certificate verify A
Mar 15 18:50:03 zonebox postfix/smtpd[3638]: [ID 197553 mail.info]
SSL_accept error from unknown[x.x.x.x]: -1
Mar 15 18:50:03 zonebox postfix/smtpd[3638]: [ID 947731 mail.warning]
warning: TLS library problem: 3638:error:1408F119:SSL
routines:SSL3_GET_RECORD:decryption failed or bad record
mac:s3_pkt.c:422:
Mar 15 18:50:03 zonebox postfix/smtpd[3638]: [ID 197553 mail.info]
lost connection after STARTTLS from unknown[x.x.x.x]

I've tried with Thundebird client and Outlook with no luck, but if
performing a test wit openssl everything seems to work fine. I am
sending you the full log and also the output of the test with opensl.

Dou you have any clue about this?
Thank you in advanced.

=== MAIN.CF ===

smtpd_tls_security_level = may
smtpd_tls_auth_only = no
smtpd_tls_key_file = /etc/postfix/postfix.key
smtpd_tls_cert_file = /etc/postfix/postfix.pem
smtpd_tls_CAfile = /etc/postfix/primary.pem
smtpd_tls_loglevel = 3
smtpd_tls_received_header = yes
smtpd_tls_session_cache_timeout = 3600s
smtpd_tls_random_source = dev:/dev/urandom

=== CAN START TLS SESSION ===

$ telnet localhost 25
Trying 127.0.0.1...
Connected to ..
Escape character is '^]'.
220 zonebox ESMTP Postfix ready at Fri, 16 Mar 2007 11:19:32 -0600 (CST)
EHLO localhost
250-zonebox
250-PIPELINING
250-SIZE 10485760
250-VRFY
250-ETRN
250-STARTTLS
250-AUTH PLAIN LOGIN
250-ENHANCEDSTATUSCODES
250-8BITMIME
250 DSN
STARTTLS
220 2.0.0 Ready to start TLS


=== LOG USING THUNDERBIRD OR OUTLOOK ===

Mar 16 11:21:07 zonebox postfix/smtpd[4343]: [ID 197553 mail.info]
connect from unknown[x.x.x.x]
Mar 16 11:21:07 zonebox postfix/smtpd[4343]: [ID 197553 mail.info ]
setting up TLS connection from unknown[x.x.x.x]
Mar 16 11:21:07 zonebox postfix/smtpd[4343]: [ID 197553 mail.info]
SSL_accept:before/accept initialization
Mar 16 11:21:07 zonebox postfix/smtpd[4343]: [ID 197553 mail.info]
read from 00108280 [00114D28] (11 bytes => -1 (0xFFFFFFFF))
Mar 16 11:21:07 zonebox postfix/smtpd[4343]: [ID 197553 mail.info]
SSL_accept:error in SSLv2/v3 read client hello A
Mar 16 11:21:07 zonebox postfix/smtpd[4343]: [ID 197553 mail.info]
read from 00108280 [00114D28] (11 bytes => 11 (0xB))
Mar 16 11:21:07 zonebox postfix/smtpd[4343]: [ID 197553 mail.info]
0000 16 03 01 00 93 01 00 00|8f 03 01 ........ ..
Mar 16 11:21:07 zonebox postfix/smtpd[4343]: [ID 197553 mail.info]
read from 00108280 [00114D33] (141 bytes => -1 (0xFFFFFFFF))
Mar 16 11:21:07 zonebox postfix/smtpd[4343]: [ID 197553 mail.info]
SSL_accept:error in SSLv3 read client hello B
Mar 16 11:21:07 zonebox last message repeated 1 time
Mar 16 11:21:07 zonebox postfix/smtpd[4343]: [ID 197553 mail.info]
read from 00108280 [00114D33] (141 bytes => 141 (0x8D))
Mar 16 11:21:07 zonebox postfix/smtpd[4343]: [ID 197553 mail.info]
0000 00 01 3f b3 53 b8 1e 56|0a fc 65 3d 76 1d 63 3f ..?.S..V ..e=
v.c?
Mar 16 11:21:07 zonebox postfix/smtpd[4343]: [ID 197553 mail.info]
0010 59 66 fe 77 06 57 9d f7|36 fd d1 66 b4 c1 a1 bf Yf.w.W.. 6...
... (more HEX)
Mar 16 11:21:07 zonebox postfix/smtpd[4343]: [ID 197553 mail.info]
008c - <SPACES/NULLS>
Mar 16 11:21:07 zonebox postfix/smtpd[4343]: [ID 197553 mail.info]
SSL_accept:SSLv3 read client hello B
Mar 16 11:21:07 zonebox postfix/smtpd[4343]: [ID 197553 mail.info]
SSL_accept:SSLv3 write server hello A
Mar 16 11:21:07 zonebox postfix/smtpd[4343]: [ID 197553 mail.info]
SSL_accept:SSLv3 write certificate A
Mar 16 11:21:07 zonebox postfix/smtpd[4343]: [ID 197553 mail.info]
SSL_accept:SSLv3 write key exchange A
Mar 16 11:21:07 zonebox postfix/smtpd[4343]: [ID 197553 mail.info]
SSL_accept:SSLv3 write server done A
Mar 16 11:21:07 zonebox postfix/smtpd[4343]: [ID 197553 mail.info]
write to 00108280 [00122E58] (3908 bytes => 3908 (0xF44))
Mar 16 11:21:07 zonebox postfix/smtpd[4343]: [ID 197553 mail.info]
0000 16 03 01 00 4a 02 00 00|46 03 01 45 fa d2 03 a2 ....J...
F..E....
Mar 16 11:21:07 zonebox postfix/smtpd[4343]: [ID 197553 mail.info]
0010 cb 52 32 67 58 34 c9 07|57 54 48 3c cb b3 06 ef .R2gX4..
WTH<....
... (more HEX)
Mar 16 11:21:07 zonebox postfix/smtpd[4343]: [ID 197553 mail.info]
0f40 0e .
Mar 16 11:21:07 zonebox postfix/smtpd[4343]: [ID 197553 mail.info]
0f41 - <SPACES/NULLS>
Mar 16 11:21:07 zonebox postfix/smtpd[4343]: [ID 197553 mail.info]
SSL_accept:SSLv3 flush data
Mar 16 11:21:07 zonebox postfix/smtpd[4343]: [ID 197553 mail.info]
read from 00108280 [00114D28] (5 bytes => -1 (0xFFFFFFFF))
Mar 16 11:21:07 zonebox postfix/smtpd[4343]: [ID 197553 mail.info]
SSL_accept:error in SSLv3 read client certificate A
Mar 16 11:21:08 zonebox postfix/smtpd[4343]: [ID 197553 mail.info]
read from 00108280 [00114D28] (5 bytes => 5 (0x5))
Mar 16 11:21:08 zonebox postfix/smtpd[4343]: [ID 197553 mail.info]
0000 16 03 01 00 86 .....
Mar 16 11:21:08 zonebox postfix/smtpd[4343]: [ID 197553 mail.info]
read from 00108280 [00114D2D] (134 bytes => -1 (0xFFFFFFFF))
Mar 16 11:21:08 zonebox postfix/smtpd[4343]: [ID 197553 mail.info]
SSL_accept:error in SSLv3 read client certificate A
Mar 16 11:21:08 zonebox postfix/smtpd[4343]: [ID 197553 mail.info]
read from 00108280 [00114D2D] (134 bytes => 134 (0x86))
Mar 16 11:21:08 zonebox postfix/smtpd[4343]: [ID 197553 mail.info]
0000 10 00 00 82 00 80 91 a5|4a de 1d 7e 3f 97 d3 a8 ........
... (more HEX)
Mar 16 11:21:08 zonebox postfix/smtpd[4343]: [ID 197553 mail.info]
0080 54 cd d4 e3 e3 89 T.....
Mar 16 11:21:08 zonebox postfix/smtpd[4343]: [ID 197553 mail.info]
SSL_accept:SSLv3 read client key exchange A
Mar 16 11:21:08 zonebox postfix/smtpd[4343]: [ID 197553 mail.info]
read from 00108280 [00114D28] (5 bytes => -1 (0xFFFFFFFF))
Mar 16 11:21:08 zonebox postfix/smtpd[4343]: [ID 197553 mail.info]
SSL_accept:error in SSLv3 read certificate verify A
Mar 16 11:21:08 zonebox postfix/smtpd[4343]: [ID 197553 mail.info]
read from 00108280 [00114D28] (5 bytes => 5 (0x5))
Mar 16 11:21:08 zonebox postfix/smtpd[4343]: [ID 197553 mail.info]
0000 14 03 01 00 01 .....
Mar 16 11:21:08 zonebox postfix/smtpd[4343]: [ID 197553 mail.info]
read from 00108280 [00114D2D] (1 bytes => -1 (0xFFFFFFFF))
Mar 16 11:21:08 zonebox postfix/smtpd[4343]: [ID 197553 mail.info]
SSL_accept:error in SSLv3 read certificate verify A
Mar 16 11:21:08 zonebox postfix/smtpd[4343]: [ID 197553 mail.info]
read from 00108280 [00114D2D] (1 bytes => 1 (0x1))
Mar 16 11:21:08 zonebox postfix/smtpd[4343]: [ID 197553 mail.info]
0000 01 .
Mar 16 11:21:08 zonebox postfix/smtpd[4343]: [ID 197553 mail.info]
read from 00108280 [00114D28] (5 bytes => -1 (0xFFFFFFFF))
Mar 16 11:21:08 zonebox postfix/smtpd[4343]: [ID 197553 mail.info]
SSL_accept:error in SSLv3 read certificate verify A
Mar 16 11:21:08 zonebox postfix/smtpd[4343]: [ID 197553 mail.info]
read from 00108280 [00114D28] (5 bytes => 5 (0x5))
Mar 16 11:21:08 zonebox postfix/smtpd[4343]: [ID 197553 mail.info]
0000 16 03 01 00 30 ....0
Mar 16 11:21:08 zonebox postfix/smtpd[4343]: [ID 197553 mail.info]
read from 00108280 [00114D2D] (48 bytes => -1 (0xFFFFFFFF))
Mar 16 11:21:08 zonebox postfix/smtpd[4343]: [ID 197553 mail.info]
SSL_accept:error in SSLv3 read certificate verify A
Mar 16 11:21:08 zonebox postfix/smtpd[4343]: [ID 197553 mail.info]
read from 00108280 [00114D2D] (48 bytes => 48 (0x30))
Mar 16 11:21:08 zonebox postfix/smtpd[4343]: [ID 197553 mail.info]
0000 5f de aa 57 d6 9e 5f cb|38 07 7f 92 25 ad 7f 10 _..W.._. 8.
... (more HEX)
Mar 16 11:21:08 zonebox postfix/smtpd[4343]: [ID 197553 mail.info]
write to 00108280 [00122E58] (7 bytes => 7 (0x7))
Mar 16 11:21:08 zonebox postfix/smtpd[4343]: [ID 197553 mail.info]
0000 15 03 01 00 02 02 14 .......
Mar 16 11:21:08 zonebox postfix/smtpd[4343]: [ID 197553 mail.info]
SSL3 alert write:fatal:bad record mac
Mar 16 11:21:08 zonebox postfix/smtpd[4343]: [ID 197553 mail.info]
SSL_accept:error in SSLv3 read certificate verify A
Mar 16 11:21:08 zonebox postfix/smtpd[4343]: [ID 197553 mail.info]
SSL_accept error from unknown[x.x.x.x]: -1
Mar 16 11:21:08 zonebox postfix/smtpd[4343]: [ID 947731 mail.warning]
warning: TLS library problem: 4343:error:1408F119:SSL routines
:SSL3_GET_RECORD:decryption failed or bad record mac:s3_pkt.c:422:
Mar 16 11:21:08 zonebox postfix/smtpd[4343]: [ID 197553 mail.info]
lost connection after STARTTLS from unknown[x.x.x.x]
Mar 16 11:21:08 zonebox postfix/smtpd[4343]: [ID 197553 mail.info]
disconnect from unknown[x.x.x.x]

=== TESTING WITH OPENSSL ===

$ openssl s_client -connect localhost:25 -starttls smtp
CONNECTED(00000003)
depth=1 /C=xx/ST=xxxx/L=xxxx/O=xxxx/OU=xxxx/CN=xxxx
verify error:num=19:self signed certificate in certificate chain
verify return:0
---
Certificate chain
0 s:/C=xx/ST=xxxx/O=xxxx/OU=xxxx/CN=xxxx/emailAddress=xxxx
i:/C=xx/ST=xxxx/L=xxxx/O=xxxx/OU=xxxx/CN=xxxx
1 s:/C=xx/ST=xxxx/O=xxxx/OU=xxxx/CN=xxxx/emailAddress=xxxx
i:/C=xx/ST=xxxx/L=xxxx/O=xxxx/OU=xxxx/CN=xxxx
---
Server certificate
-----BEGIN CERTIFICATE-----
MIIF8jCCA9qgAwIBAgIBCjANBgkqhkiG9w0BAQQFADCBrjELMAkGA1UEBhMCTVgx
... (more base64)
6HbAc2tAbphbBEYXtpEpySR04d2eLbjXnBvEEnEEnaGmsGwNKJw=
-----END CERTIFICATE-----
subject=/C=xx/ST=xxxx/O=xxxx/OU=xxxx/CN=xxxx/emailAddress=xxxx
issuer=/C=xx/ST=xxxx/L=xxxx/O=xxxx/OU=xxxx/CN=xxxx
---
No client certificate CA names sent
---
SSL handshake has read 4223 bytes and written 357 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:
CF3B96C5D357C03520E697FEE99A6EBE138A3A6E061D74CB6E644A190A05E808
Session-ID-ctx:
Master-Key:
2954BBB964C816B40922AF8A8E169C0DB4D58AD4FF8773440F0B11A87AD474EC32B9CEB3D5E716678A674BFAA51CD357
Key-Arg : None
Start Time: 1174066021
Timeout : 300 (sec)
Verify return code: 19 (self signed certificate in certificate chain)
---
250 DSN

=== LOG USING OPENSSL ===
Mar 16 11:27:01 zonebox postfix/smtpd[4354]: [ID 197553 mail.info]
initializing the server-side TLS engine
Mar 16 11:27:01 zonebox postfix/smtpd[4354]: [ID 197553 mail.info]
connect from localhost[127.0.0.1]
Mar 16 11:27:01 zonebox postfix/smtpd[4354]: [ID 197553 mail.info]
setting up TLS connection from localhost[ 127.0.0.1]
Mar 16 11:27:01 zonebox postfix/smtpd[4354]: [ID 197553 mail.info]
SSL_accept:before/accept initialization
Mar 16 11:27:01 zonebox postfix/smtpd[4354]: [ID 197553 mail.info]
read from 00104638 [00114D28] (11 bytes => -1 (0xFFFFFFFF))
Mar 16 11:27:01 zonebox postfix/smtpd[4354]: [ID 197553 mail.info]
SSL_accept:error in SSLv2/v3 read client hello A
Mar 16 11:27:01 zonebox postfix/smtpd[4354]: [ID 197553 mail.info]
read from 00104638 [00114D28] (11 bytes => 11 (0xB))
Mar 16 11:27:01 zonebox postfix/smtpd[4354]: [ID 197553 mail.info]
0000 80 7a 01 03 01 00 51 .z....Q
Mar 16 11:27:01 zonebox postfix/smtpd[4354]: [ID 197553 mail.info]
0007 - <SPACES/NULLS>
Mar 16 11:27:01 zonebox postfix/smtpd[4354]: [ID 197553 mail.info]
read from 00104638 [00114D33] (113 bytes => -1 (0xFFFFFFFF))
Mar 16 11:27:01 zonebox postfix/smtpd[4354]: [ID 197553 mail.info]
SSL_accept:error in SSLv2/v3 read client hello B
Mar 16 11:27:01 zonebox postfix/smtpd[4354]: [ID 197553 mail.info]
read from 00104638 [00114D33] (113 bytes => 113 (0x71))
Mar 16 11:27:01 zonebox postfix/smtpd[4354]: [ID 197553 mail.info]
0000 00 00 39 00 00 38 00 00|35 00 00 16 00 00 13 00 ..9..8.. 5.
... (more HEX)
Mar 16 11:27:01 zonebox postfix/smtpd[4354]: [ID 197553 mail.info]
0070 a8 .
Mar 16 11:27:01 zonebox postfix/smtpd[4354]: [ID 197553 mail.info]
SSL_accept:SSLv3 read client hello A
Mar 16 11:27:01 zonebox postfix/smtpd[4354]: [ID 197553 mail.info]
SSL_accept:SSLv3 write server hello A
Mar 16 11:27:01 zonebox postfix/smtpd[4354]: [ID 197553 mail.info]
SSL_accept:SSLv3 write certificate A
Mar 16 11:27:01 zonebox postfix/smtpd[4354]: [ID 197553 mail.info]
SSL_accept:SSLv3 write key exchange A
Mar 16 11:27:01 zonebox postfix/smtpd[4354]: [ID 197553 mail.info]
SSL_accept:SSLv3 write server done A
Mar 16 11:27:01 zonebox postfix/smtpd[4354]: [ID 197553 mail.info]
write to 00104638 [00122E58] (3908 bytes => 3908 (0xF44))
... (more HEX)
Mar 16 11:27:01 zonebox postfix/smtpd[4354]: [ID 197553 mail.info]
0f40 0e .
Mar 16 11:27:01 zonebox postfix/smtpd[4354]: [ID 197553 mail.info]
0f41 - <SPACES/NULLS>
Mar 16 11:27:01 zonebox postfix/smtpd[4354]: [ID 197553 mail.info]
SSL_accept:SSLv3 flush data
Mar 16 11:27:01 zonebox postfix/smtpd[4354]: [ID 197553 mail.info]
read from 00104638 [00114D28] (5 bytes => -1 (0xFFFFFFFF))
Mar 16 11:27:01 zonebox postfix/smtpd[4354]: [ID 197553 mail.info]
SSL_accept:error in SSLv3 read client certificate A
Mar 16 11:27:01 zonebox last message repeated 1 time
Mar 16 11:27:01 zonebox postfix/smtpd[4354]: [ID 197553 mail.info]
read from 00104638 [00114D28] (5 bytes => 5 (0x5))
Mar 16 11:27:01 zonebox postfix/smtpd[4354]: [ID 197553 mail.info]
0000 16 03 01 00 86 .....
Mar 16 11:27:01 zonebox postfix/smtpd[4354]: [ID 197553 mail.info]
read from 00104638 [00114D2D] (134 bytes => -1 (0xFFFFFFFF))
Mar 16 11:27:01 zonebox postfix/smtpd[4354]: [ID 197553 mail.info]
SSL_accept:error in SSLv3 read client certificate A
Mar 16 11:27:01 zonebox postfix/smtpd[4354]: [ID 197553 mail.info]
read from 00104638 [00114D2D] (134 bytes => 134 (0x86))
Mar 16 11:27:01 zonebox postfix/smtpd[4354]: [ID 197553 mail.info]
0000 10 00 00 82 00 80 27 3c|1d 3b 33 94 e9 83 e3 83 ......'< .;
... (more HEX)
Mar 16 11:27:01 zonebox postfix/smtpd[4354]: [ID 197553 mail.info]
0080 b2 c0 62 b7 88 5a ..b..Z
Mar 16 11:27:01 zonebox postfix/smtpd[4354]: [ID 197553 mail.info]
SSL_accept:SSLv3 read client key exchange A
Mar 16 11:27:01 zonebox postfix/smtpd[4354]: [ID 197553 mail.info]
read from 00104638 [00114D28] (5 bytes => -1 (0xFFFFFFFF))
Mar 16 11:27:01 zonebox postfix/smtpd[4354]: [ID 197553 mail.info]
SSL_accept:error in SSLv3 read certificate verify A
Mar 16 11:27:01 zonebox postfix/smtpd[4354]: [ID 197553 mail.info]
read from 00104638 [00114D28] (5 bytes => 5 (0x5))
Mar 16 11:27:01 zonebox postfix/smtpd[4354]: [ID 197553 mail.info]
0000 14 03 01 00 01 .....
Mar 16 11:27:01 zonebox postfix/smtpd[4354]: [ID 197553 mail.info]
read from 00104638 [00114D2D] (1 bytes => -1 (0xFFFFFFFF))
Mar 16 11:27:01 zonebox postfix/smtpd[4354]: [ID 197553 mail.info]
SSL_accept:error in SSLv3 read certificate verify A
Mar 16 11:27:01 zonebox postfix/smtpd[4354]: [ID 197553 mail.info]
read from 00104638 [00114D2D] (1 bytes => 1 (0x1))
Mar 16 11:27:01 zonebox postfix/smtpd[4354]: [ID 197553 mail.info]
0000 01 .
Mar 16 11:27:01 zonebox postfix/smtpd[4354]: [ID 197553 mail.info]
read from 00104638 [00114D28] (5 bytes => -1 (0xFFFFFFFF))
Mar 16 11:27:01 zonebox postfix/smtpd[4354]: [ID 197553 mail.info]
SSL_accept:error in SSLv3 read certificate verify A
Mar 16 11:27:01 zonebox postfix/smtpd[4354]: [ID 197553 mail.info]
read from 00104638 [00114D28] (5 bytes => 5 (0x5))
Mar 16 11:27:01 zonebox postfix/smtpd[4354]: [ID 197553 mail.info]
0000 16 03 01 00 30 ....0
Mar 16 11:27:01 zonebox postfix/smtpd[4354]: [ID 197553 mail.info]
read from 00104638 [00114D2D] (48 bytes => -1 (0xFFFFFFFF))
Mar 16 11:27:01 zonebox postfix/smtpd[4354]: [ID 197553 mail.info]
SSL_accept:error in SSLv3 read certificate verify A
Mar 16 11:27:01 zonebox postfix/smtpd[4354]: [ID 197553 mail.info]
read from 00104638 [00114D2D] (48 bytes => 48 (0x30))
Mar 16 11:27:01 zonebox postfix/smtpd[4354]: [ID 197553 mail.info]
0000 e8 09 0b e7 64 19 02 92|52 2d 19 85 56 92 eb e5 ....d... R-
... (more HEX)
Mar 16 11:27:01 zonebox postfix/smtpd[4354]: [ID 197553 mail.info]
SSL_accept:SSLv3 read finished A
Mar 16 11:27:01 zonebox postfix/smtpd[4354]: [ID 197553 mail.info]
SSL_accept:SSLv3 write change cipher spec A
Mar 16 11:27:01 zonebox postfix/smtpd[4354]: [ID 197553 mail.info]
SSL_accept:SSLv3 write finished A
Mar 16 11:27:01 zonebox postfix/smtpd[4354]: [ID 197553 mail.info]
write to 00104638 [00122E58] (59 bytes => 59 (0x3B))
Mar 16 11:27:01 zonebox postfix/smtpd[4354]: [ID 197553 mail.info]
0000 14 03 01 00 01 01 16 03|01 00 30 2c dd 95 f5 b1 ........ ..
... (more HEX)
Mar 16 11:27:01 zonebox postfix/smtpd[4354]: [ID 197553 mail.info]
SSL_accept:SSLv3 flush data
Mar 16 11:27:01 zonebox postfix/smtpd[4354]: [ID 197553 mail.info] TLS
connection established from localhost[127.0.0.1]: TLSv1 with cipher
DHE-RSA-AES256-SHA (256/256 bits)
Mar 16 11:30:21 zonebox postfix/smtpd[4354]: [ID 197553 mail.info]
disconnect from localhost[127.0.0.1]
Victor Duchovni
2007-03-19 05:50:37 UTC
Permalink
Post by Jairsinho Ramirez Ruiz
I am trying to get TLS work on Solaris 10 (sparc). I've compiled
Postfix 2.3.8 with Cyrus SASL 2.1.22, OpenLdap 2.3.34 and OpenSSL
0.9.8e (with and whitout zlib), however I cannot get TLS work. I've
tried compiling all libraries as static and shared. Everything works
fine (SASL, LDAP lookups, etc) even can start tls session, however on
the TLS proccess(?) something is not working, 'cause I get the
If the machine is reachable from the Internet, please provide its IP
address or host name. Otherwise, post the URL of a tcpdump capture
(full packets using "-s 0") of a failed session. Also Post "ldd" output
for smtpd.

Describe in detail the network path between the client and server.
Post by Jairsinho Ramirez Ruiz
Mar 15 18:50:03 zonebox postfix/smtpd[3638]: [ID 947731 mail.warning]
warning: TLS library problem: 3638:error:1408F119:SSL
routines:SSL3_GET_RECORD:decryption failed or bad record
=== MAIN.CF ===
"postconf -n" output is preferred. If all else failes, build OpenSSL
0.9.8e with "-g", install without stripping the symbol table, and run
smtpd under a debugger. Set break-points in ssl3_get_record() at lines
360, 386, 403 and 410. Report which one set:

decryption_failed_or_bad_record_mac = 1;

$ grep -n decryption_failed_or_bad_record_mac s3_pkt.c
243: int decryption_failed_or_bad_record_mac = 0;
360: decryption_failed_or_bad_record_mac = 1;
386: decryption_failed_or_bad_record_mac = 1;
403: decryption_failed_or_bad_record_mac = 1;
410: decryption_failed_or_bad_record_mac = 1;
414: if (decryption_failed_or_bad_record_mac)

Line 360 is trouble decrypting the payload, 386 is overly large payload,
403 is overly short payload, and 410 is an incorrect MAC (corrupted
payload). Report the value of s->method->ssl3_enc->mac (should be a
pointer to a named function, report the name). Report
s->enc_read_ctx->cipher->nid.
--
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:***@postfix.org?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.
Jairsinho Ramirez Ruiz
2007-03-20 19:56:21 UTC
Permalink
Post by Victor Duchovni
Post by Jairsinho Ramirez Ruiz
I am trying to get TLS work on Solaris 10 (sparc). I've compiled
Postfix 2.3.8 with Cyrus SASL 2.1.22, OpenLdap 2.3.34 and OpenSSL
0.9.8e (with and whitout zlib), however I cannot get TLS work. I've
tried compiling all libraries as static and shared. Everything works
fine (SASL, LDAP lookups, etc) even can start tls session, however on
the TLS proccess(?) something is not working, 'cause I get the
If the machine is reachable from the Internet, please provide its IP
address or host name. Otherwise, post the URL of a tcpdump capture
(full packets using "-s 0") of a failed session. Also Post "ldd" output
for smtpd.
U can find the info here: http://www.jairsinho.com/tls/

I did the dump using ethereal on the client side and usign tcpdump
on server side.
Post by Victor Duchovni
Describe in detail the network path between the client and server.
Both the client and server are on the same network and switch.
Post by Victor Duchovni
Post by Jairsinho Ramirez Ruiz
Mar 15 18:50:03 zonebox postfix/smtpd[3638]: [ID 947731 mail.warning]
warning: TLS library problem: 3638:error:1408F119:SSL
routines:SSL3_GET_RECORD:decryption failed or bad record
=== MAIN.CF ===
"postconf -n" output is preferred. If all else failes, build OpenSSL
0.9.8e with "-g", install without stripping the symbol table, and run
smtpd under a debugger. Set break-points in ssl3_get_record() at lines
decryption_failed_or_bad_record_mac = 1;
$ grep -n decryption_failed_or_bad_record_mac s3_pkt.c
243: int decryption_failed_or_bad_record_mac = 0;
360: decryption_failed_or_bad_record_mac = 1;
386: decryption_failed_or_bad_record_mac = 1;
403: decryption_failed_or_bad_record_mac = 1;
410: decryption_failed_or_bad_record_mac = 1;
414: if (decryption_failed_or_bad_record_mac)
Line 360 is trouble decrypting the payload, 386 is overly large payload,
403 is overly short payload, and 410 is an incorrect MAC (corrupted
payload). Report the value of s->method->ssl3_enc->mac (should be a
pointer to a named function, report the name). Report
s->enc_read_ctx->cipher->nid.
I'm trying to find out how to debug with Sun Studio 11, but at
least I could find that decryption_failed_or_bad_record_mac sets to 1
in line 360, the value of s->method->ssl3_enc->mac is -15768360 and
the value of s->enc_read_ctx->cipher->nid is 427.

Thank you in advanced.
Victor Duchovni
2007-03-20 20:38:07 UTC
Permalink
Post by Jairsinho Ramirez Ruiz
Post by Victor Duchovni
Line 360 is trouble decrypting the payload, 386 is overly large payload,
403 is overly short payload, and 410 is an incorrect MAC (corrupted
payload). Report the value of s->method->ssl3_enc->mac (should be a
pointer to a named function, report the name). Report
s->enc_read_ctx->cipher->nid.
I'm trying to find out how to debug with Sun Studio 11, but at
least I could find that decryption_failed_or_bad_record_mac sets to 1
in line 360, the value of s->method->ssl3_enc->mac is -15768360 and
the value of s->enc_read_ctx->cipher->nid is 427.
So the cipher negotiated between client and server is AES-256-CBC,
which you show working with openssl s_client:

crypto/objects/obj_mac.h:
#define NID_aes_256_cbc 427

and yet you suggest that decryption (line 360) rather than the MAC
verification fails, which suggests that the decrypted data is incorrectly
padded, which happens when it was corrupted in transit or the key is wrong.

Please do provide the raw (not decoded) PCAP files. (Even with decoded
files why on earth provide PDF and not plain text?)
--
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:***@postfix.org?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.
Jairsinho Ramirez Ruiz
2007-03-20 21:18:42 UTC
Permalink
Thank you Victor,
Post by Victor Duchovni
Please do provide the raw (not decoded) PCAP files. (Even with decoded
files why on earth provide PDF and not plain text?)
Sorry, this is because my ethereal is failing to export txt files. The
raw pcap files are now on server.

Saludos.
Victor Duchovni
2007-03-20 21:50:00 UTC
Permalink
Post by Jairsinho Ramirez Ruiz
Thank you Victor,
Post by Victor Duchovni
Please do provide the raw (not decoded) PCAP files. (Even with decoded
files why on earth provide PDF and not plain text?)
Sorry, this is because my ethereal is failing to export txt files. The
raw pcap files are now on server.
So the client and server agree on cipher 0x39: DHE-RSA-AES256-SHA
nothing too outlandish (Elliptic curves, Camellia, ...) and the
same as you report working with "openssl s_client".

The session ends with the client telling the server to switch to encrypted
mode, and sending 64 bytes of encrypted handshake verification data. The
server decrypts this and finds that it is incorrectly padded.

1 7 0.3010 (0.0000) C>S ChangeCipherSpec
Packet data[6]=
14 03 00 00 01 01


1 8 0.3010 (0.0000) C>S Handshake
Packet data[69]=
16 03 00 00 40 aa f1 d4 36 c2 d0 3a b1 e7 a0 a1
cc 6d 21 50 72 91 e1 6c eb 66 24 20 d9 a7 42 74
00 a4 f3 12 47 52 53 f8 2a ea e3 89 31 14 a4 43
1a d0 68 8a cb f2 8e 7b e0 86 68 00 c1 ff 79 0f
72 92 86 2a 0f

The server is unable to decrypt the client's handshake verification
packet, suggesting that the server and client arrived at different keys,
which suggests that the client's implementation of AES256 is busted.

Try:

smtpd_tls_exclude_ciphers = DHE-RSA-AES256-SHA DHE-DSS-AES256-SHA AES256-SHA

does that help?
--
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:***@postfix.org?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.
Jairsinho Ramirez Ruiz
2007-03-20 22:16:08 UTC
Permalink
No, it doesn't but:

smtpd_tls_exclude_ciphers = AES

does.

Received: from jags (using SSLv3 with cipher RC4-MD5 (128/128 bits))
(No client certificate requested) by zonebox (Postfix) with ESMTP id
6F257636F for <***@domain.com>; Tue, 20 Mar 2007 16:09:45 -0600 (CST)

Is this "as it should work"? or some bug in openssl/postfix?

Thank you.
Post by Victor Duchovni
Post by Jairsinho Ramirez Ruiz
Thank you Victor,
Post by Victor Duchovni
Please do provide the raw (not decoded) PCAP files. (Even with decoded
files why on earth provide PDF and not plain text?)
Sorry, this is because my ethereal is failing to export txt files. The
raw pcap files are now on server.
So the client and server agree on cipher 0x39: DHE-RSA-AES256-SHA
nothing too outlandish (Elliptic curves, Camellia, ...) and the
same as you report working with "openssl s_client".
The session ends with the client telling the server to switch to encrypted
mode, and sending 64 bytes of encrypted handshake verification data. The
server decrypts this and finds that it is incorrectly padded.
1 7 0.3010 (0.0000) C>S ChangeCipherSpec
Packet data[6]=
14 03 00 00 01 01
1 8 0.3010 (0.0000) C>S Handshake
Packet data[69]=
16 03 00 00 40 aa f1 d4 36 c2 d0 3a b1 e7 a0 a1
cc 6d 21 50 72 91 e1 6c eb 66 24 20 d9 a7 42 74
00 a4 f3 12 47 52 53 f8 2a ea e3 89 31 14 a4 43
1a d0 68 8a cb f2 8e 7b e0 86 68 00 c1 ff 79 0f
72 92 86 2a 0f
The server is unable to decrypt the client's handshake verification
packet, suggesting that the server and client arrived at different keys,
which suggests that the client's implementation of AES256 is busted.
smtpd_tls_exclude_ciphers = DHE-RSA-AES256-SHA DHE-DSS-AES256-SHA AES256-SHA
does that help?
--
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
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.
Victor Duchovni
2007-03-20 22:30:16 UTC
Permalink
Post by Jairsinho Ramirez Ruiz
Post by Victor Duchovni
smtpd_tls_exclude_ciphers = DHE-RSA-AES256-SHA DHE-DSS-AES256-SHA AES256-SHA
does that help?
smtpd_tls_exclude_ciphers = AES
does.
Received: from jags (using SSLv3 with cipher RC4-MD5 (128/128 bits))
(No client certificate requested) by zonebox (Postfix) with ESMTP id
Is this "as it should work"? or some bug in openssl/postfix?
This is almost certainly a bug in the *client* implementation of AES,
or all block ciphers (RC4 is a stream cipher). It would interesting to
exclude RC4 and see whether 3DES works or fails. Perhaps padding for
block algorithms is broken.

Postfix and OpenSSL have been using AES for many years and inter-operating
with a lot of systems. What software/version is the client, and how
new is the client's AES support? I would file a bug report against the
client software...
--
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:***@postfix.org?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.
Wietse Venema
2007-03-20 22:57:19 UTC
Permalink
Post by Victor Duchovni
This is almost certainly a bug in the *client* implementation of AES,
or all block ciphers (RC4 is a stream cipher). It would interesting to
exclude RC4 and see whether 3DES works or fails. Perhaps padding for
block algorithms is broken.
Postfix and OpenSSL have been using AES for many years and inter-operating
with a lot of systems. What software/version is the client, and how
new is the client's AES support? I would file a bug report against the
client software...
Urgent question:

Would this problem happen if Postfix did NOT override the OpenSSL
defaults? Said otherwise, is Postfix experiencing inter-operability
problems that EXIM, SENDMAIL, etc. would not have?

Wietse
Victor Duchovni
2007-03-20 23:21:23 UTC
Permalink
Post by Wietse Venema
Post by Victor Duchovni
This is almost certainly a bug in the *client* implementation of AES,
or all block ciphers (RC4 is a stream cipher). It would interesting to
exclude RC4 and see whether 3DES works or fails. Perhaps padding for
block algorithms is broken.
Postfix and OpenSSL have been using AES for many years and inter-operating
with a lot of systems. What software/version is the client, and how
new is the client's AES support? I would file a bug report against the
client software...
Would this problem happen if Postfix did NOT override the OpenSSL
defaults? Said otherwise, is Postfix experiencing inter-operability
problems that EXIM, SENDMAIL, etc. would not have?
No, the selected cipher is the best DEFAULT high grade cipher. The issue
appears to be a Solaris compiler optimization bug.
--
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:***@postfix.org?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.
Victor Duchovni
2007-03-20 23:25:27 UTC
Permalink
Post by Victor Duchovni
Post by Wietse Venema
Post by Victor Duchovni
This is almost certainly a bug in the *client* implementation of AES,
or all block ciphers (RC4 is a stream cipher). It would interesting to
exclude RC4 and see whether 3DES works or fails. Perhaps padding for
block algorithms is broken.
Postfix and OpenSSL have been using AES for many years and inter-operating
with a lot of systems. What software/version is the client, and how
new is the client's AES support? I would file a bug report against the
client software...
Would this problem happen if Postfix did NOT override the OpenSSL
defaults? Said otherwise, is Postfix experiencing inter-operability
problems that EXIM, SENDMAIL, etc. would not have?
No, the selected cipher is the best DEFAULT high grade cipher. The issue
appears to be a Solaris compiler optimization bug.
In other words, Sendmail, Exim, qmail, ... linked with the OpenSSL build
in question also will not inter-operate with correctly compiled systems.
(It is interesting that the compiler bug produces a cipher different
from AES, but one is still reversible, but not entirely suprising if
the bug maintains the Feistel construction, but with a different S-box).
--
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:***@postfix.org?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.
Victor Duchovni
2007-03-20 23:41:35 UTC
Permalink
Post by Victor Duchovni
Post by Victor Duchovni
Post by Wietse Venema
Would this problem happen if Postfix did NOT override the OpenSSL
defaults? Said otherwise, is Postfix experiencing inter-operability
problems that EXIM, SENDMAIL, etc. would not have?
No, the selected cipher is the best DEFAULT high grade cipher. The issue
appears to be a Solaris compiler optimization bug.
In other words, Sendmail, Exim, qmail, ... linked with the OpenSSL build
in question also will not inter-operate with correctly compiled systems.
(It is interesting that the compiler bug produces a cipher different
from AES, but one is still reversible, but not entirely suprising if
the bug maintains the Feistel construction, but with a different S-box).
This message has a link to the Sun Studio 11 patch:

http://www.mail-archive.com/openssl-***@openssl.org/msg21624.html

6353992 openssl-0.9.7i test fails in run-time under -xO3 -xdepend
--
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:***@postfix.org?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.
Jairsinho Ramirez Ruiz
2007-03-21 00:17:57 UTC
Permalink
After applying the Sun Studio 11 patches, AES is working:

Received: from jags using SSLv3 with cipher DHE-RSA-AES256-SHA
(256/256 bits)) (No client certificate requested) by zonebox (Postfix)
with ESMTP id 41BC663C1 for <***@domain.com>; Tue, 20 Mar 2007
18:13:07 -0600 (CST)

no need to tweak smtpd_tls_exclude_ciphers

Thank you.
Post by Jairsinho Ramirez Ruiz
smtpd_tls_exclude_ciphers = AES
does.
Received: from jags (using SSLv3 with cipher RC4-MD5 (128/128 bits))
(No client certificate requested) by zonebox (Postfix) with ESMTP id
Is this "as it should work"? or some bug in openssl/postfix?
Thank you.
Post by Victor Duchovni
Post by Jairsinho Ramirez Ruiz
Thank you Victor,
Post by Victor Duchovni
Please do provide the raw (not decoded) PCAP files. (Even with decoded
files why on earth provide PDF and not plain text?)
Sorry, this is because my ethereal is failing to export txt files. The
raw pcap files are now on server.
So the client and server agree on cipher 0x39: DHE-RSA-AES256-SHA
nothing too outlandish (Elliptic curves, Camellia, ...) and the
same as you report working with "openssl s_client".
The session ends with the client telling the server to switch to encrypted
mode, and sending 64 bytes of encrypted handshake verification data. The
server decrypts this and finds that it is incorrectly padded.
1 7 0.3010 (0.0000) C>S ChangeCipherSpec
Packet data[6]=
14 03 00 00 01 01
1 8 0.3010 (0.0000) C>S Handshake
Packet data[69]=
16 03 00 00 40 aa f1 d4 36 c2 d0 3a b1 e7 a0 a1
cc 6d 21 50 72 91 e1 6c eb 66 24 20 d9 a7 42 74
00 a4 f3 12 47 52 53 f8 2a ea e3 89 31 14 a4 43
1a d0 68 8a cb f2 8e 7b e0 86 68 00 c1 ff 79 0f
72 92 86 2a 0f
The server is unable to decrypt the client's handshake verification
packet, suggesting that the server and client arrived at different keys,
which suggests that the client's implementation of AES256 is busted.
smtpd_tls_exclude_ciphers = DHE-RSA-AES256-SHA DHE-DSS-AES256-SHA AES256-SHA
does that help?
--
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
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.
Victor Duchovni
2007-03-21 00:26:24 UTC
Permalink
Post by Jairsinho Ramirez Ruiz
Received: from jags using SSLv3 with cipher DHE-RSA-AES256-SHA
(256/256 bits)) (No client certificate requested) by zonebox (Postfix)
18:13:07 -0600 (CST)
no need to tweak smtpd_tls_exclude_ciphers
Thank you.
You're welcome. I forgot about the Solaris 10 compiler bug, until we
concluded this was a bug in the client's AES, but the odds of *both*
Outlook and T'bird botching AES seemed somewhat unlikely... Then I reread
your post and noticed Solaris 10... Moral:

Run "make test" when building your own OpenSSL.

The "test vectors" for the various ciphers are strong indications that
the code is compiled correctly.
--
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:***@postfix.org?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.
Jairsinho Ramirez Ruiz
2007-03-21 00:35:43 UTC
Permalink
I also forgot to mention I'm using Sun Studio 11, this would give you
a clue. Anyway, I'll keep this in mind, and won't despise "make test"
also.

Thank you for your help.

Saludos.
Post by Victor Duchovni
You're welcome. I forgot about the Solaris 10 compiler bug, until we
concluded this was a bug in the client's AES, but the odds of *both*
Outlook and T'bird botching AES seemed somewhat unlikely... Then I reread
Run "make test" when building your own OpenSSL.
The "test vectors" for the various ciphers are strong indications that
the code is compiled correctly.
Continue reading on narkive:
Loading...