[ emacs-jabber-Bugs-3527994 ] Problems with native gnutls

SourceForge Headquarters 225 Broadway Suite 1600 San Diego, CA 92101 +1 (858) 454-5900

Bugs item #3527994, was opened at 2012-05-18 11:17
Message generated for change (Comment added) made by legoscia
You can respond by visiting: 
https://sourceforge.net/tracker/?func=detail&atid=586350&aid=3527994&group_id=88346

Please note that this message will contain a full copy of the comment thread,
including the initial issue submission, for this request,
not just the latest update.
Category: None
Group: None
Status: Open
Resolution: None
Priority: 5
Private: No
Submitted By: Elias Pipping (pipping)
Assigned to: Nobody/Anonymous (nobody)
Summary: Problems with native gnutls

Initial Comment:
Ever since

commit f54c1b54b308f38caac66ae567e5f64f6adc631c
Author: Magnus Henoch <leg...@us...>
Date:   Tue May 15 22:39:43 2012 +0100

    Support native GnuTLS for STARTTLS
    [..]

I've found myself unable to connect to lavabit.com using starttls. Here's what I found in my message buffer:

gnutls.c: [0] (Emacs) fatal error: The TLS connection was non-properly terminated.
gnutls.el: (err=[-110] The TLS connection was non-properly terminated.) boot: (:priority NORMAL :hostname lavabit.com :loglevel 0 :min-prime-bits nil :trustfiles (/etc/ssl/certs/ca-certificates.crt) :crlfiles nil :keylist nil :verify-flags nil :verify-error t :verify-hostname-error t :callbacks nil)
gnutls.c: [0] (Emacs) fatal error: The specified session has been invalidated for some reason. [100 times]
ME...@la.../nil: connection lost: `connection broken by remote peer
'

(where i replaced my username with ME)

Here's the relevant part of my config:

(setq jabber-account-list '(("ME...@la..."
			     (:password . "PASSWORD")
			     (:network-server . "lavabit.com")
			     (:connection-type . starttls)
			     (:port . 5222)))

----------------------------------------------------------------------

>Comment By: Magnus Henoch (legoscia)
Date: 2012-05-30 13:53

Message:
Sorry about the delay in responding...

I'm seeing this myself on Mac OS X, with Emacs 24.1.50 and GnuTLS 2.12.11
from Macports; it worked on a Linux machine I have no access to at the
moment... Which OS and GnuTLS version are you using? Are you able to try
different ones?

I discovered that setting gnutls-log-level to 5 yields more log messages,
but they don't tell me very much; pasting here in case it makes the problem
obvious to someone:

gnutls.c: [1] (Emacs) allocating credentials
gnutls.c: [2] (Emacs) allocating x509 credentials
gnutls.c: [2] (Emacs) using default verification flags
gnutls.c: [1] (Emacs) gnutls callbacks
gnutls.c: [1] (Emacs) gnutls_init
gnutls.c: [4] REC[0x11c53de00]: Allocating epoch #0

gnutls.c: [1] (Emacs) got non-default priority string: NORMAL
gnutls.c: [1] (Emacs) setting the priority string
gnutls.c: [2] ASSERT: gnutls_constate.c:695

gnutls.c: [4] REC[0x11c53de00]: Allocating epoch #1

gnutls.c: [3] HSK[0x11c53de00]: Keeping ciphersuite:
DHE_RSA_AES_128_CBC_SHA1

gnutls.c: [3] HSK[0x11c53de00]: Keeping ciphersuite:
DHE_RSA_AES_128_CBC_SHA256

gnutls.c: [3] HSK[0x11c53de00]: Keeping ciphersuite:
DHE_RSA_CAMELLIA_128_CBC_SHA1

gnutls.c: [3] HSK[0x11c53de00]: Keeping ciphersuite:
DHE_RSA_AES_256_CBC_SHA1

gnutls.c: [3] HSK[0x11c53de00]: Keeping ciphersuite:
DHE_RSA_AES_256_CBC_SHA256

gnutls.c: [3] HSK[0x11c53de00]: Keeping ciphersuite:
DHE_RSA_CAMELLIA_256_CBC_SHA1

gnutls.c: [3] HSK[0x11c53de00]: Keeping ciphersuite:
DHE_RSA_3DES_EDE_CBC_SHA1

gnutls.c: [3] HSK[0x11c53de00]: Keeping ciphersuite:
DHE_DSS_AES_128_CBC_SHA1

gnutls.c: [3] HSK[0x11c53de00]: Keeping ciphersuite:
DHE_DSS_AES_128_CBC_SHA256

gnutls.c: [3] HSK[0x11c53de00]: Keeping ciphersuite:
DHE_DSS_CAMELLIA_128_CBC_SHA1

gnutls.c: [3] HSK[0x11c53de00]: Keeping ciphersuite:
DHE_DSS_AES_256_CBC_SHA1

gnutls.c: [3] HSK[0x11c53de00]: Keeping ciphersuite:
DHE_DSS_AES_256_CBC_SHA256

gnutls.c: [3] HSK[0x11c53de00]: Keeping ciphersuite:
DHE_DSS_CAMELLIA_256_CBC_SHA1

gnutls.c: [3] HSK[0x11c53de00]: Keeping ciphersuite:
DHE_DSS_3DES_EDE_CBC_SHA1

gnutls.c: [3] HSK[0x11c53de00]: Keeping ciphersuite: DHE_DSS_ARCFOUR_SHA1

gnutls.c: [3] HSK[0x11c53de00]: Keeping ciphersuite: RSA_AES_128_CBC_SHA1

gnutls.c: [3] HSK[0x11c53de00]: Keeping ciphersuite:
RSA_AES_128_CBC_SHA256

gnutls.c: [3] HSK[0x11c53de00]: Keeping ciphersuite:
RSA_CAMELLIA_128_CBC_SHA1

gnutls.c: [3] HSK[0x11c53de00]: Keeping ciphersuite: RSA_AES_256_CBC_SHA1

gnutls.c: [3] HSK[0x11c53de00]: Keeping ciphersuite:
RSA_AES_256_CBC_SHA256

gnutls.c: [3] HSK[0x11c53de00]: Keeping ciphersuite:
RSA_CAMELLIA_256_CBC_SHA1

gnutls.c: [3] HSK[0x11c53de00]: Keeping ciphersuite: RSA_3DES_EDE_CBC_SHA1

gnutls.c: [3] HSK[0x11c53de00]: Keeping ciphersuite: RSA_ARCFOUR_SHA1

gnutls.c: [3] HSK[0x11c53de00]: Keeping ciphersuite: RSA_ARCFOUR_MD5

gnutls.c: [2] EXT[0x11c53de00]: Sending extension SAFE RENEGOTIATION (1
bytes)

gnutls.c: [2] EXT[SIGA]: sent signature algo (4.2) DSA-SHA256

gnutls.c: [2] EXT[SIGA]: sent signature algo (4.1) RSA-SHA256

gnutls.c: [2] EXT[SIGA]: sent signature algo (2.1) RSA-SHA1

gnutls.c: [2] EXT[SIGA]: sent signature algo (2.2) DSA-SHA1

gnutls.c: [2] EXT[0x11c53de00]: Sending extension SIGNATURE ALGORITHMS (10
bytes)

gnutls.c: [3] HSK[0x11c53de00]: CLIENT HELLO was sent [112 bytes]

gnutls.c: [6] BUF[HSK]: Inserted 112 bytes of Data

gnutls.c: [7] HWRITE: enqueued 112. Total 112 bytes.

gnutls.c: [7] HWRITE FLUSH: 112 bytes in buffer.

gnutls.c: [4] REC[0x11c53de00]: Sending Packet[0] Handshake(22) with
length: 112

gnutls.c: [7] WRITE: enqueued 117 bytes for 0xb. Total 117 bytes.

gnutls.c: [4] REC[0x11c53de00]: Sent Packet[1] Handshake(22) with length:
117

gnutls.c: [7] HWRITE: wrote 112 bytes, 0 bytes left.

gnutls.c: [7] WRITE FLUSH: 117 bytes in buffer.

gnutls.c: [7] WRITE: wrote 117 bytes, 0 bytes left.

gnutls.c: [7] READ: -1 returned from 0xb, errno=35 gerrno=0

gnutls.c: [1] (Emacs) non-fatal error: Resource temporarily unavailable,
try again.
gnutls.c: [7] READ: Got 0 bytes from 0xb

gnutls.c: [7] READ: read 0 bytes from 0xb

gnutls.c: [2] ASSERT: gnutls_buffers.c:640

gnutls.c: [2] ASSERT: gnutls_record.c:969

gnutls.c: [2] ASSERT: gnutls_handshake.c:2762

gnutls.c: [6] BUF[HSK]: Cleared Data from buffer

gnutls.c: [0] (Emacs) fatal error: A TLS packet with unexpected length was
received.
gnutls.c: [4] REC: Sending Alert[2|22] - Record overflow

gnutls.c: [4] REC[0x11c53de00]: Sending Packet[1] Alert(21) with length: 2

gnutls.c: [7] WRITE: enqueued 7 bytes for 0xb. Total 7 bytes.

gnutls.c: [7] WRITE FLUSH: 7 bytes in buffer.

gnutls.c: [7] WRITE: wrote 7 bytes, 0 bytes left.

gnutls.c: [4] REC[0x11c53de00]: Sent Packet[2] Alert(21) with length: 7

gnutls.el: (err=[-9] A TLS packet with unexpected length was received.)
boot: (:priority NORMAL :hostname jabber.se :loglevel 10 :min-prime-bits
nil :trustfiles nil :crlfiles nil :keylist nil :verify-flags nil
:verify-error t :verify-hostname-error t :callbacks nil)
gnutls.c: [2] (Emacs) Deallocating x509 credentials
gnutls.c: [6] BUF[HSK]: Cleared Data from buffer

gnutls.c: [4] REC[0x11c53de00]: Epoch #0 freed

gnutls.c: [4] REC[0x11c53de00]: Epoch #1 freed

----------------------------------------------------------------------

Comment By: Elias Pipping (pipping)
Date: 2012-05-19 07:44

Message:
After

commit 1dca591d17cf084e6d870f55898e9343926f8bb8
Author: Magnus Henoch <mag...@gm...>
Date:   Sat May 19 15:01:05 2012 +0100

    Fix reporting of STARTTLS negotiation errors [..]

My message buffer looks like this:

Sat May 19 16:40:07 2012: Starting jabber-connection
Sat May 19 16:40:07 2012: jabber-connection enters :connecting
Sat May 19 16:40:07 2012: Found enter function for :connecting: #[(fsm
state-data) "\306\307\"\310	!\306\311\"\306\312\"\306\313\"

$\210-\314D\207" [state-data connection-type connect-function server
network-server port plist-get :connection-type jabber-get-connect-function
:server :network-server :port nil fsm] 5]
Sat May 19 16:40:07 2012: Using data from enter function
Sat May 19 16:40:07 2012: Sent :connected to jabber-connection in state
:connecting
Sat May 19 16:40:07 2012: jabber-connection enters :connected
Sat May 19 16:40:07 2012: Found enter function for :connected: #[(fsm
state-data) "\303!\210\304
\305D\207" [fsm *jabber-connected* state-data jabber-send-stream-header t
nil] 2]
Sat May 19 16:40:07 2012: Using data from enter function
Sat May 19 16:40:07 2012: Sent :filter to jabber-connection in state
:connected
Sat May 19 16:40:07 2012: Sent :stream-start to jabber-connection in state
:connected
Sat May 19 16:40:08 2012: Sent :filter to jabber-connection in state
:connected
Sat May 19 16:40:08 2012: Sent :stanza to jabber-connection in state
:connected
Sat May 19 16:40:08 2012: jabber-connection enters :starttls
Sat May 19 16:40:08 2012: Found enter function for :starttls: #[(fsm
state-data) "\302!\210	\303D\207" [fsm state-data jabber-starttls-initiate
nil] 2]
Sat May 19 16:40:08 2012: Using data from enter function
Sat May 19 16:40:08 2012: Sent :filter to jabber-connection in state
:starttls
Sat May 19 16:40:08 2012: Sent :stanza to jabber-connection in state
:starttls
Sat May 19 16:40:08 2012: jabber-connection enters nil
Sat May 19 16:40:08 2012: Found enter function for nil: #[(fsm state-data)
"\306\307\"\310	!\203\"

----------------------------------------------------------------------

You can respond by visiting: 
https://sourceforge.net/tracker/?func=detail&atid=586350&aid=3527994&group_id=88346