On 2012-05-20 11:01, Janne Snabb wrote:
> I am unsure how to debug this further (I am not familiar with any of
> these TLS libraries) but will be happy to assist.
I put "#define EXIM_GNUTLS_LIBRARY_LOG_LEVEL 9" in src/tls-gnu.c and got
some additional output, see below.
Additionally I noticed that I can reproduce this issue also on Debian
"sid" with GnuTLS 2.12.19-1.
--
Janne Snabb / EPIPE Communications
snabb@??? -
http://epipe.com/
$ sudo /opt/exim/bin/exim -bd -d-all+tls
Exim version 4.80_RC2 uid=0 gid=0 pid=4003 D=8000000
Berkeley DB: Berkeley DB 5.1.25: (January 28, 2011)
Support for: iconv() GnuTLS DKIM
Lookups (built-in): lsearch wildlsearch nwildlsearch iplsearch dbm dbmjz
dbmnz dnsdb
Authenticators:
Routers: accept dnslookup ipliteral manualroute queryprogram redirect
Transports: appendfile autoreply pipe smtp
Fixed never_users: 0
Size of off_t: 8
Compiler: GCC [4.6.3]
Library version: GnuTLS: Compile: 2.12.14
Runtime: 2.12.14
Library version: PCRE: Compile: 8.12PCRE_PRERELEASE
Runtime: 8.12 2011-01-15
WHITELIST_D_MACROS unset
TRUSTED_CONFIG_LIST unset
configuration file is /opt/exim/configure
log selectors = 00000ffc 00212001
cwd=/home/snabb/src/exim-4.80_RC2 3 args: /opt/exim/bin/exim -bd -d-all+tls
trusted user
admin user
4003 listening on all interfaces (IPv4) port 25
4003 listening on all interfaces (IPv4) port 443
4003 listening on all interfaces (IPv4) port 587
4003 pid written to /opt/exim/spool/exim-daemon.pid
4003 LOG: MAIN
4003 exim 4.80_RC2 daemon started: pid=4003, no queue runs, listening
for SMTP on port 25 (IPv4) port 587 (IPv4) and for SMTPS on port 443 (IPv4)
4003 daemon running with uid=115 gid=127 euid=115 egid=127
4003 Listening...
4003 Connection request from 127.0.0.1 port 35030
4003 1 SMTP accept process running
4003 Listening...
4011 Process 4011 is handling incoming connection from [127.0.0.1]
4011 initialising GnuTLS as a server
4011 GnuTLS global init required.
4011 initialising GnuTLS server session
4011 GnuTLS<4>: REC[0x1213b00]: Allocating epoch #0
4011
4011 Expanding various TLS configuration options for session credentials.
4011 certificate file = /opt/exim/exim.crt
4011 key file = /opt/exim/exim.key
4011 GnuTLS<2>: ASSERT: x509_b64.c:453
4011
4011 GnuTLS<2>: Could not find '-----BEGIN RSA PRIVATE KEY'
4011
4011 GnuTLS<2>: ASSERT: x509_b64.c:453
4011
4011 GnuTLS<2>: Could not find '-----BEGIN DSA PRIVATE KEY'
4011
4011 GnuTLS<2>: ASSERT: privkey.c:387
4011
4011 GnuTLS<2>: Falling back to PKCS #8 key decoding
4011
4011 TLS: cert/key registered
4011 TLS: tls_verify_certificates not set or empty, ignoring
4011 Initialising GnuTLS server params.
4011 GnuTLS tells us that for D-H PK, NORMAL is 2432 bits.
4011 read D-H parameters from file "/opt/exim/spool/gnutls-params-2432"
4011 initialized server D-H parameters
4011 GnuTLS using default session cipher/priority "NORMAL"
4011 TLS: a client certificate will not be requested.
4011 GnuTLS<2>: ASSERT: gnutls_constate.c:695
4011
4011 GnuTLS<4>: REC[0x1213b00]: Allocating epoch #1
4011
4011 GnuTLS<4>: REC[0x1213b00]: Expected Packet[0] Handshake(22) with
length: 1
4011
4011 GnuTLS<4>: REC[0x1213b00]: Received Packet[0] Handshake(22) with
length: 157
4011
4011 GnuTLS<4>: REC[0x1213b00]: Decrypted Packet[0] Handshake(22) with
length: 157
4011
4011 GnuTLS<3>: HSK[0x1213b00]: CLIENT HELLO was received [157 bytes]
4011
4011 GnuTLS<3>: HSK[0x1213b00]: Client's version: 3.1
4011
4011 GnuTLS<2>: ASSERT: gnutls_db.c:238
4011
4011 GnuTLS<2>: EXT[0x1213b00]: Parsing extension 'SERVER NAME/0' (14
bytes)
4011
4011 Received TLS SNI "localhost" (unused for certificate selection)
4011 GnuTLS<2>: EXT[0x1213b00]: Parsing extension 'SESSION TICKET/35'
(0 bytes)
4011
4011 GnuTLS<3>: HSK[0x1213b00]: Received safe renegotiation CS
4011
4011 GnuTLS<3>: HSK[0x1213b00]: Removing ciphersuite: DHE_DSS_ARCFOUR_SHA1
4011
4011 GnuTLS<3>: HSK[0x1213b00]: Removing ciphersuite:
DHE_DSS_3DES_EDE_CBC_SHA1
4011
4011 GnuTLS<3>: HSK[0x1213b00]: Removing ciphersuite:
DHE_DSS_AES_128_CBC_SHA1
4011
4011 GnuTLS<3>: HSK[0x1213b00]: Removing ciphersuite:
DHE_DSS_AES_256_CBC_SHA1
4011
4011 GnuTLS<3>: HSK[0x1213b00]: Removing ciphersuite:
DHE_DSS_CAMELLIA_128_CBC_SHA1
4011
4011 GnuTLS<3>: HSK[0x1213b00]: Removing ciphersuite:
DHE_DSS_CAMELLIA_256_CBC_SHA1
4011
4011 GnuTLS<3>: HSK[0x1213b00]: Keeping ciphersuite:
DHE_RSA_3DES_EDE_CBC_SHA1
4011
4011 GnuTLS<3>: HSK[0x1213b00]: Keeping ciphersuite:
DHE_RSA_AES_128_CBC_SHA1
4011
4011 GnuTLS<3>: HSK[0x1213b00]: Keeping ciphersuite:
DHE_RSA_AES_256_CBC_SHA1
4011
4011 GnuTLS<3>: HSK[0x1213b00]: Keeping ciphersuite:
DHE_RSA_CAMELLIA_128_CBC_SHA1
4011
4011 GnuTLS<3>: HSK[0x1213b00]: Keeping ciphersuite:
DHE_RSA_CAMELLIA_256_CBC_SHA1
4011
4011 GnuTLS<3>: HSK[0x1213b00]: Keeping ciphersuite: RSA_ARCFOUR_SHA1
4011
4011 GnuTLS<3>: HSK[0x1213b00]: Keeping ciphersuite: RSA_ARCFOUR_MD5
4011
4011 GnuTLS<3>: HSK[0x1213b00]: Keeping ciphersuite: RSA_3DES_EDE_CBC_SHA1
4011
4011 GnuTLS<3>: HSK[0x1213b00]: Keeping ciphersuite: RSA_AES_128_CBC_SHA1
4011
4011 GnuTLS<3>: HSK[0x1213b00]: Keeping ciphersuite: RSA_AES_256_CBC_SHA1
4011
4011 GnuTLS<3>: HSK[0x1213b00]: Keeping ciphersuite:
RSA_CAMELLIA_128_CBC_SHA1
4011
4011 GnuTLS<3>: HSK[0x1213b00]: Keeping ciphersuite:
RSA_CAMELLIA_256_CBC_SHA1
4011
4011 GnuTLS<3>: HSK[0x1213b00]: Selected cipher suite:
DHE_RSA_CAMELLIA_256_CBC_SHA1
4011
4011 GnuTLS<3>: HSK[0x1213b00]: Selected Compression Method: NULL
4011
4011 GnuTLS<3>: HSK[0x1213b00]: Safe renegotiation succeeded
4011
4011 GnuTLS<2>: EXT[0x1213b00]: Sending extension SAFE RENEGOTIATION (1
bytes)
4011
4011 GnuTLS<3>: HSK[0x1213b00]: SessionID:
f58b3839e6e576898566c4edcda0bea947ef1746f3da42b8925207ee21d6d272
4011
4011 GnuTLS<3>: HSK[0x1213b00]: SERVER HELLO was sent [81 bytes]
4011
4011 GnuTLS<3>: HSK[0x1213b00]: CERTIFICATE was sent [455 bytes]
4011
4011 GnuTLS<3>: HSK[0x1213b00]: signing handshake data: using RSA-SHA1
4011
4011 GnuTLS<3>: HSK[0x1213b00]: SERVER KEY EXCHANGE was sent [749 bytes]
4011
4011 GnuTLS<3>: HSK[0x1213b00]: SERVER HELLO DONE was sent [4 bytes]
4011
4011 GnuTLS<4>: REC[0x1213b00]: Sending Packet[0] Handshake(22) with
length: 81
4011
4011 GnuTLS<4>: REC[0x1213b00]: Sent Packet[1] Handshake(22) with
length: 86
4011
4011 GnuTLS<4>: REC[0x1213b00]: Sending Packet[1] Handshake(22) with
length: 455
4011
4011 GnuTLS<4>: REC[0x1213b00]: Sent Packet[2] Handshake(22) with
length: 460
4011
4011 GnuTLS<4>: REC[0x1213b00]: Sending Packet[2] Handshake(22) with
length: 749
4011
4011 GnuTLS<4>: REC[0x1213b00]: Sent Packet[3] Handshake(22) with
length: 754
4011
4011 GnuTLS<4>: REC[0x1213b00]: Sending Packet[3] Handshake(22) with
length: 4
4011
4011 GnuTLS<4>: REC[0x1213b00]: Sent Packet[4] Handshake(22) with length: 9
4011
4011 GnuTLS<2>: ASSERT: gnutls_buffers.c:640
4011
4011 GnuTLS<2>: ASSERT: gnutls_record.c:969
4011
4011 GnuTLS<2>: ASSERT: gnutls_handshake.c:3061
4011
4011 LOG: MAIN
4011 TLS error on connection from localhost [127.0.0.1]
(gnutls_handshake): A TLS packet with unexpected length was received.
4003 child 4011 ended: status=0x0
4003 normal exit, 0
4003 0 SMTP accept processes now running
4003 Listening...