Connection with latest ejabberd raises unknown/unhandled exception

[DenSA-Inc]

EDIT: I found out the problem is not my certificate. I will edit my posts once I have the time, until that the real problem is in the 3rd comment.

I use sleekxmpp for python3 with the latest ejabberd. After the update of ejabberd I was unable to connect to it anymore. The reason is a failing certificate check, CERT: Invalid certificate trust chain. Yes, the certificate is self-signed, but sleekxmpp never bothered with that before (and yes, sleekxmpp is the newest version).

I tried discarding the ssl_*-events, checked that ClientXMPP.ca_certs is None and even tried to put my certificate next to my program and set ca_certs to the filename. In short, I did everything proposed in this issue.

To make it even weirder, somehow the TLS-connection can be established if I don't use sleekxmpp, but a raw tcp-socket and the ssl-module. I opened a python-shell, opened a tcp-socket, sent everything that sleekxmpp would send to up to the beginning of a TLS-connection and tried ssl.wrap and SSLSocket.do_handshake (with no parameters). It worked, and I'm speechless and don't know where the error might be.

My python-version is 3.4.2 btw.

[DenSA-Inc]

This is the debug-log from my connection-attempt:

DEBUG    Loaded Plugin: RFC 6120: Stream Feature: STARTTLS
DEBUG    Loaded Plugin: RFC 6120: Stream Feature: Resource Binding
DEBUG    Loaded Plugin: RFC 3920: Stream Feature: Start Session
DEBUG    Loaded Plugin: RFC 6121: Stream Feature: Roster Versioning
DEBUG    Loaded Plugin: RFC 6121: Stream Feature: Subscription Pre-Approval
DEBUG    Loaded Plugin: RFC 6120: Stream Feature: SASL
INFO     Certs: None
DEBUG    Loaded Plugin: XEP-0030: Service Discovery
DEBUG    Loaded Plugin: XEP-0184: Message Delivery Receipts
DEBUG    Waiting 1.7415307570433871 seconds before connecting.
WARNING  DNS: dnspython not found. Can not use SRV lookup.
DEBUG    DNS: Querying my.domain for AAAA records.
DEBUG    DNS: Error retreiving AAAA address info for my.domain.
DEBUG    DNS: Querying my.domain for A records.
DEBUG    Connecting to XXX.XXX.XXX.XXX:5222
DEBUG    Event triggered: connected
DEBUG     ==== TRANSITION disconnected -> connected
DEBUG    Starting HANDLER THREAD
DEBUG    Loading event runner
DEBUG    SEND (IMMED): <stream:stream to='my.domain' xmlns:stream='http://etherx.jabber.org/streams' xmlns='jabber:client' xml:lang='en' version='1.0'>
DEBUG    RECV: <stream:stream from="my.domain" id="3431598390" version="1.0" xml:lang="en">
DEBUG    RECV: <stream:features xmlns="http://etherx.jabber.org/streams"><starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls" /><mechanisms xmlns="urn:ietf:params:xml:ns:xmpp-sasl"><mechanism>SCRAM-SHA-1</mechanism><mechanism>DIGEST-MD5</mechanism><mechanism>PLAIN</mechanism></mechanisms><c xmlns="http://jabber.org/protocol/caps" hash="sha-1" ver="TQ2JFyRoSa70h2G1bpgjzuXb2sU=" node="http://www.process-one.net/en/ejabberd/" /><register xmlns="http://jabber.org/features/iq-register" /></stream:features>
DEBUG    SEND (IMMED): <starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls" />
DEBUG    RECV: <proceed xmlns="urn:ietf:params:xml:ns:xmpp-tls" />
DEBUG    Starting TLS
INFO     Negotiating TLS
INFO     Using SSL version: TLS 1.0
ERROR    CERT: Invalid certificate trust chain.
DEBUG    Event triggered: session_end
DEBUG    Event triggered: disconnected
DEBUG     ==== TRANSITION connected -> disconnected
ERROR    Can not read from closed socket.
DEBUG    reconnecting...
DEBUG    connecting...
DEBUG    Waiting 2.196748637732717 seconds before connecting.
DEBUG    No remaining DNS records to try.
DEBUG    Waiting 4.805024601126729 seconds before connecting.
WARNING  DNS: dnspython not found. Can not use SRV lookup.
DEBUG    DNS: Querying my.domain for AAAA records.
DEBUG    DNS: Error retreiving AAAA address info for my.domain.
DEBUG    DNS: Querying my.domain for A records.
DEBUG    Connecting to XXX.XXX.XXX.XXX:5222
DEBUG    Event triggered: connected
DEBUG     ==== TRANSITION disconnected -> connected

I changed my domain-name in the logs to my.domain and my ip-address to XXX.XXX.XXX.XXX. Also, I'm enabling XEP-0184 but that's a minor information.

[DenSA-Inc]

And here is my attempt to connect "manually" from the python-shell. Again, domain-name and ip-addresses are replaced.

Python 3.4.2 (default, Oct 19 2014, 13:31:11)
[GCC 4.9.1] on linux
Type "help", "copyright", "credits" or "license" for more information.
>>> from socket import *
>>> import ssl
>>> 
>>> s = socket(AF_INET, SOCK_STREAM)
>>> s.connect(("my.domain", 5222))
>>> s.send("<stream:stream to='my.domain' xmlns:stream='http://etherx.jabber.org/streams' xmlns='jabber:client' xml:lang='en' version='1.0'>\n".encode("utf-8"))
144
>>> s.recv(1000)
b"<?xml version='1.0'?><stream:stream xmlns='jabber:client' xmlns:stream='http://etherx.jabber.org/streams' id='1332369713' from='my.domain' version='1.0' xml:lang='en'><stream:features><starttls xmlns='urn:ietf:params:xml:ns:xmpp-tls'/><mechanisms xmlns='urn:ietf:params:xml:ns:xmpp-sasl'><mechanism>SCRAM-SHA-1</mechanism><mechanism>DIGEST-MD5</mechanism><mechanism>PLAIN</mechanism></mechanisms><c xmlns='http://jabber.org/protocol/caps' hash='sha-1' node='http://www.process-one.net/en/ejabberd/' ver='TQ2JFyRoSa70h2G1bpgjzuXb2sU='/><register xmlns='http://jabber.org/features/iq-register'/></stream:features>"
>>> s.send("""<starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls" />\n""".encode("utf-8"))
53
>>> s.recv(1000)
b"<proceed xmlns='urn:ietf:params:xml:ns:xmpp-tls'/>"
>>> x = ssl.wrap_socket(s)
>>> x.do_handshake()
>>> x.send("</stream>\n".encode("utf-8"))
10
>>> x.recv(1000)
b"<?xml version='1.0'?><stream:stream xmlns='jabber:client' xmlns:stream='http://etherx.jabber.org/streams' id='2432932244' from='my.domain' version='1.0'>"
>>> x.close()
>>> 

[DenSA-Inc]

After a bit of checking (I really need a good python-debugger after that) I redid what I tried in the comment above with the paramters sleekxmpp uses for the function ssl.wrap_socket. These parameters are:

certfile: None
ssl_version: 3 (ssl.PROTOCOL_TLSv1)
cert_regs: 0 (ssl.CERT_NONE)
ciphers: None
keyfile: None
ca_certs: None
do_handshake_on_connect: false

Using these parameters (and the socket of course) as arguments to ssl.socket_wrap causes the later ssl.SSLSocket.do_handshake to throw a ssl.SSLEOFError: EOF occurred in violation of protocol (_ssl.c:600). The line it refers to is here.

[DenSA-Inc]

After hours of debugging I found the error: In the latest ejabberd-update the supported TLS-versions changed to 1.2 only. Therefore initiating a connection with ssl_version = 3 (TLS-1.0) while actually connection via TLS-1.2 will probably lead to this error. And this might explain why omitting the ssl_version-parameter results in a correct handshake. The only thing left to do is pushing the latest version in the pip(3)-repositories. I tried setting the ssl_version to 1.2, but that gave me an error because on line 843 in xmlstream.py the ssl-descriptions are hardcoded (here). I had to manually add the TLS-v1.X-entries for it to work. And I am sure that this abstrocity of an action will not let me sleep at night.

So that problem solved itself, with only a tiny thing to do left (I have this 1.3.1-line in my code even though sleekxmpp.__version__ returns "1.3.2", that's to solve too). I will keep this issue for anyone that stumbles upon the same problem. I don't wish anyone to experience what I have experienced.

[thoastbrot]

To be honest, I didn't debug this through sleekxmpp, but I'm sure having the same issue. After debugging my own bot for quite some time, I found out that my working deployed bot (vs my indev bot) is using 1.3.1, so I tried using that version, and see: it works fine... same environment otherwise. After looking through the diff 1.3.1..1.3.2, I guess this is just development of a long time (planned for 1.4.0), applied the patch and released 1.3.2 "to get it into stretch". That's not exactly my understanding of a patch release...

[apollo13]

@DenSA-Inc My workaround is currently to just set ssl_version = ssl.PROTOCOL_TLS. While this allows for SSL to be negotiated, it at least allows for a functioning SleekXMPP for now.

On a related note. The actual fix would be to require Python 2.7.9+ and use ssl.PROTOCOL_SSLv23 as ssl_version and set ssl.OP_NO_SSLv2 as well as ssl.OP_NO_SSLv3. This would effectively disable SSL and allow for all TLS variants.

[viniarck]

+1

[MaxwellBo]

Try applying this patch

diff --git a/xmlstream/cert.py b/xmlstream/cert.py
index d357b32..c53150d 100644
--- a/xmlstream/cert.py
+++ b/xmlstream/cert.py
@@ -50,18 +50,17 @@ def extract_names(raw_cert):
     extensions = tbs.getComponentByName('extensions') or []

     # Extract the CommonName(s) from the cert.
-    for rdnss in subject:
-        for rdns in rdnss:
-            for name in rdns:
-                oid = name.getComponentByName('type')
-                value = name.getComponentByName('value')
+    for rdnss in subject.getComponent():
+        for name in rdnss:
+            oid = name.getComponentByName('type')
+            value = name.getComponentByName('value')

-                if oid != COMMON_NAME:
-                    continue
+            if oid != COMMON_NAME:
+                continue

-                value = decoder.decode(value, asn1Spec=DirectoryString())[0]
-                value = decode_str(value.getComponent())
-                results['CN'].add(value)
+            value = decoder.decode(value, asn1Spec=DirectoryString())[0]
+            value = decode_str(value.getComponent())
+            results['CN'].add(value)

     # Extract the Subject Alternate Names (DNS, SRV, URI, XMPPAddr)
     for extension in extensions:
     for extension in extensions:

[Neustradamus]

It works with TLS 1.2 without problem now?

[Neustradamus]

@DenSA-Inc @thoastbrot @apollo13 @viniarck @MaxwellBo Any news?

Have you tested with "master"?

• https://github.com/fritzy/SleekXMPP/commits/develop

It works?