Bug#348046: exim4-daemon-heavy: TLS delivery attempts fail with: (gnutls_handshake): A TLS packet with unexpected length was received.

[Andrew McGlashan]

Marc Haber wrote:
> After thinking for a while, why did your incredimail not complain
> about the server not presenting a certificate?

It was dropping out with the error as given already with no hint of any 
certificate issue.  I have my own ca.crt certificate installed in the 
trusted root in order to stop questions about a certificate that I already 
trust (or others made by myself).

> Please try again and give gnutls-serv the same certificate that your
> exim also uses.
>
> For reference, you might want to try openssl:

Tried this:
# gnutls-serv -d 5 -p 588 \
  --x509certfile /etc/exim4/exim.crt \
  --x509keyfile /etc/exim4/exim.key

Failed in the same manner, IM gave immediate error and quit trying to send.

On my Debian box:

Echo Server ready. Listening to port '588'.

|<4>| REC[80738b0]: V2 packet received. Length: 76
|<4>| REC[80738b0]: Expected Packet[0] Handshake(22) with length: 1
|<4>| REC[80738b0]: Received Packet[0] Handshake(22) with length: 76
|<4>| REC[80738b0]: Decrypted Packet[0] Handshake(22) with length: 76
|<3>| HSK[80738b0]: CLIENT HELLO(v2) was received [76 bytes]
|<3>| HSK[80738b0]: SSL 2.0 Hello: Client's version: 3.1
|<3>| HSK[80738b0]: Parsing a version 2.0 client hello.
|<2>| ASSERT: gnutls_handshake.c:2674
|<3>| HSK[80738b0]: Removing ciphersuite: ANON_DH_ARCFOUR_MD5
|<2>| ASSERT: gnutls_handshake.c:2674
|<3>| HSK[80738b0]: Removing ciphersuite: ANON_DH_3DES_EDE_CBC_SHA1
|<2>| ASSERT: gnutls_handshake.c:2674
|<3>| HSK[80738b0]: Removing ciphersuite: ANON_DH_AES_128_CBC_SHA1
|<3>| HSK[80738b0]: Removing ciphersuite: PSK_SHA_ARCFOUR_SHA1
|<3>| HSK[80738b0]: Removing ciphersuite: PSK_SHA_3DES_EDE_CBC_SHA1
|<3>| HSK[80738b0]: Removing ciphersuite: PSK_SHA_AES_128_CBC_SHA1
|<3>| HSK[80738b0]: Removing ciphersuite: DHE_PSK_SHA_ARCFOUR_SHA1
|<3>| HSK[80738b0]: Removing ciphersuite: DHE_PSK_SHA_3DES_EDE_CBC_SHA1
|<3>| HSK[80738b0]: Removing ciphersuite: DHE_PSK_SHA_AES_128_CBC_SHA1
|<3>| HSK[80738b0]: Removing ciphersuite: SRP_SHA_3DES_EDE_CBC_SHA1
|<3>| HSK[80738b0]: Removing ciphersuite: SRP_SHA_AES_128_CBC_SHA1
|<3>| HSK[80738b0]: Removing ciphersuite: SRP_SHA_DSS_3DES_EDE_CBC_SHA1
|<3>| HSK[80738b0]: Keeping ciphersuite: SRP_SHA_RSA_3DES_EDE_CBC_SHA1
|<3>| HSK[80738b0]: Removing ciphersuite: SRP_SHA_DSS_AES_128_CBC_SHA1
|<3>| HSK[80738b0]: Keeping ciphersuite: SRP_SHA_RSA_AES_128_CBC_SHA1
|<3>| HSK[80738b0]: Removing ciphersuite: DHE_DSS_ARCFOUR_SHA1
|<3>| HSK[80738b0]: Removing ciphersuite: DHE_DSS_3DES_EDE_CBC_SHA1
|<3>| HSK[80738b0]: Removing ciphersuite: DHE_DSS_AES_128_CBC_SHA1
|<2>| ASSERT: gnutls_handshake.c:2674
|<3>| HSK[80738b0]: Removing ciphersuite: DHE_RSA_3DES_EDE_CBC_SHA1
|<2>| ASSERT: gnutls_handshake.c:2674
|<3>| HSK[80738b0]: Removing ciphersuite: DHE_RSA_AES_128_CBC_SHA1
|<2>| ASSERT: gnutls_handshake.c:2664
|<3>| HSK[80738b0]: Removing ciphersuite: RSA_EXPORT_ARCFOUR_40_MD5
|<3>| HSK[80738b0]: Keeping ciphersuite: RSA_ARCFOUR_SHA1
|<3>| HSK[80738b0]: Keeping ciphersuite: RSA_ARCFOUR_MD5
|<3>| HSK[80738b0]: Keeping ciphersuite: RSA_3DES_EDE_CBC_SHA1
|<3>| HSK[80738b0]: Keeping ciphersuite: RSA_AES_128_CBC_SHA1
|<3>| HSK[80738b0]: Selected cipher suite: RSA_ARCFOUR_MD5
|<2>| ASSERT: gnutls_db.c:327
|<2>| ASSERT: gnutls_db.c:247
|<3>| HSK[80738b0]: SessionID: 
dd9ee262aef8cf92e30193819a8a13ea830a19326bf476e36260acac5c605c97
|<3>| HSK[80738b0]: SERVER HELLO was send [74 bytes]
|<4>| REC[80738b0]: Sending Packet[0] Handshake(22) with length: 74
|<4>| REC[80738b0]: Sent Packet[1] Handshake(22) with length: 79
|<3>| HSK[80738b0]: CERTIFICATE was send [916 bytes]
|<4>| REC[80738b0]: Sending Packet[1] Handshake(22) with length: 916
|<4>| REC[80738b0]: Sent Packet[2] Handshake(22) with length: 921
|<3>| HSK[80738b0]: CERTIFICATE REQUEST was send [9 bytes]
|<4>| REC[80738b0]: Sending Packet[2] Handshake(22) with length: 9
|<4>| REC[80738b0]: Sent Packet[3] Handshake(22) with length: 14
|<3>| HSK[80738b0]: SERVER HELLO DONE was send [4 bytes]
|<4>| REC[80738b0]: Sending Packet[3] Handshake(22) with length: 4
|<4>| REC[80738b0]: Sent Packet[4] Handshake(22) with length: 9
|<2>| ASSERT: gnutls_buffers.c:289
|<2>| ASSERT: gnutls_buffers.c:1087
|<2>| ASSERT: gnutls_handshake.c:949
|<2>| ASSERT: gnutls_buffers.c:565
|<2>| ASSERT: gnutls_record.c:891
|<2>| ASSERT: gnutls_buffers.c:1087
|<2>| ASSERT: gnutls_handshake.c:949
|<2>| ASSERT: gnutls_handshake.c:2463
Error in handshake
Error: A TLS packet with unexpected length was received.
|<4>| REC: Sending Alert[2|22] - Record overflow
|<4>| REC[80738b0]: Sending Packet[4] Alert(21) with length: 2
|<4>| REC[80738b0]: Sent Packet[5] Alert(21) with length: 7
|<2>| ASSERT: gnutls_record.c:242



> openssl s_server -cert /etc/exim4/tls/certs/exim.crt -key
> /etc/exim4/tls/key/exim.key -accept 588 -debug

Using openssl:
# openssl s_server \
   -cert /etc/exim4/exim.crt \
   -key /etc/exim4/exim.key \
   -accept 588 -debug

Causes IM to continually be stuck at 'connecting' at the 'securing' point.

Last lines shown on Linux console [putty]:

  -----BEGIN SSL SESSION PARAMETERS-----
  MHUCAQECAgMBBAIABAQgE3hoE42fCVtNzS+IIc4qomwaLjHyA9LsHCXJkjcmmYYE
   data removed
  BqEGAgRHKbLBogQCAgEspAYEBAEAAAA=
  -----END SSL SESSION PARAMETERS-----
  Shared 
ciphers:RC4-MD5:RC4-SHA:DES-CBC3-SHA:DES-CBC-SHA:EXP-RC4-MD5:EXP-RC2-CBC-MD5:EDH-DSS-DES- 
CBC3-SHA:EDH-DSS-DES-CBC-SHA
  CIPHER is RC4-MD5


Okay.... then I hit enter on the putty session and more data appeared, so I 
continued to hit enter until I saw this:

  read from 0x80d0b50 [0x80c5538] (5 bytes => 0 (0x0))
  ERROR
  shutting down SSL
  CONNECTION CLOSED
  ACCEPT


Then, IM fails again with "Failed to connect to the outgoing server, 
'myserver'. Please try again later.
 - "Socket Error: (0) The operation completed successfully.


Kind Regards
AndrewM