Combing sleekxmpp.ClientXMPP and XEP-0009 results in SSL errors

[cajus]

I've a bot that implements sleekxmpp.ClientXMPP and makes use XEP-0009 with the same client instance (using _Remote.new_session_withclient). Running an RPC client against the bot results in an SSL error like show below, while the stand alone RPC bot works just fine.

---

Parts of the bar-bot log:

DEBUG    Registering ACL [(True, '*', '*')] for endpoint thermostat.
DEBUG    Starting HANDLER THREAD
DEBUG    New caps verification string: fFVwzz5J6UhZb+xyN668mNMJjkU=
DEBUG    Received disco info query from <> to <bot@example.net/aafda821-17db-437e-a77b-98940cdc23f5>.
DEBUG    SEND: <presence xml:lang="en"><c xmlns="http://jabber.org/protocol/caps" node="http://sleekxmpp.com/ver/1.1.11" ver="KusiAWiS8JbPdTPtk5Y2llpdgHo="  hash="sha-1" /></presence>
DEBUG    Loading event runner
DEBUG    SEND (IMMED): <stream:stream to='example.net' xmlns:stream='http://etherx.jabber.org/streams' xmlns='jabber:client' xml:lang='en' version='1.0'>
ERROR    Socket Error #1: _ssl.c:1359: error:140D2081:SSL routines:TLS1_ENC:block cipher pad is wrong
ERROR    Socket Error #1: _ssl.c:1359: error:1408F10B:SSL routines:SSL3_GET_RECORD:wrong version number
DEBUG    reconnecting...
DEBUG    reconnecting...
DEBUG    SEND (IMMED): </stream:stream>
INFO     Waiting for </stream:stream> from server
DEBUG     ==== TRANSITION connected -> disconnected

Parts of the rpc_client_side.py log:

DEBUG    SEND: <iq to="bot@example.net/rpc" type="set" id="3" from="client@example.net/ac4234f9-56bf-4b7c-bed8-2ecfacf9b759"><query xmlns="jabber:iq:rpc"><methodCall><methodName>thermostat.get_temperature</methodName><params /></methodCall></query></iq>
DEBUG    RECV: <presence from="client@example.net/ac4234f9-56bf-4b7c-bed8-2ecfacf9b759" />
DEBUG    RECV: <presence to="client@example.net/ac4234f9-56bf-4b7c-bed8-2ecfacf9b759" from="bot@example.net/aafda821-17db-437e-a77b-98940cdc23f5" xml:lang="en"><c xmlns="http://jabber.org/protocol/caps" node="http://sleekxmpp.com/ver/1.1.11" hash="sha-1" ver="bK8E/DRaxY11BsJQkjpEX6nRYDg=" /></presence>
DEBUG    RECV: <presence to="client@example.net" type="unavailable" from="bot@example.net/aafda821-17db-437e-a77b-98940cdc23f5"><status>Disconnected: decryption failed or bad record mac</status></presence>
DEBUG    STATUS: client@example.net/ac4234f9-56bf-4b7c-bed8-2ecfacf9b759[available]: 
DEBUG    RECV: <iq to="client@example.net/ac4234f9-56bf-4b7c-bed8-2ecfacf9b759" type="error" id="3" from="bot@example.net/rpc"><error type="cancel"><service-unavailable xmlns="urn:ietf:params:xml:ns:xmpp-stanzas" /></error></iq>
DEBUG    STATUS: bot@example.net/aafda821-17db-437e-a77b-98940cdc23f5[available]: 
DEBUG    bot@example.net aafda821-17db-437e-a77b-98940cdc23f5 got offline
DEBUG    STATUS: bot@example.net/aafda821-17db-437e-a77b-98940cdc23f5[unavailable]: Disconnected: decryption failed or bad record mac
['XEP-0009']._handle_error -> ERROR! Iq is '<iq to="client@example.net/ac4234f9-56bf-4b7c-bed8-2ecfacf9b759" type="error" id="3" from="bot@example.net/rpc"><error type="cancel"><service-unavailable xmlns="urn:ietf:params:xml:ns:xmpp-stanzas" /></error></iq>'
#######################
### NOT IMPLEMENTED ###
#######################

The server log (prosedy 0.8.2) says:

Jan 16 03:26:28 socket  debug   server.lua: client 192.168.56.1:47550 read error: block cipher pad is wrong
Jan 16 03:26:28 c2s99e7db8      info    Client disconnected: block cipher pad is wrong
Jan 16 03:26:28 c2s99e7db8      info    Destroying session for   bot@example.net/ee62e283-b4eb-4adb-9615-3b12c7edbe7d (bot@example.net)
Jan 16 03:26:28 sessionmanager  debug   All resources of bot are now offline

---

Any ideas what causes this?

[cajus]

Stripped down example code is at http://ferdi.naasa.net/foobar.tar.gz .

[legastero]

This is because Remote.new_session_with_client is assuming that it is what is responsible for starting up the client. So the client is trying to doubly process the stream.

I would just manually do the initing of the RemoteSession and the event handlers that is done in Remote instead.

[cajus]

There must be something magic I don't get right now: I've replaced the RPC integration parts with

class BarBot(sleekxmpp.ClientXMPP):

    def __init__(self, jid, password):

        [...]

        # Integrate RPC
        def _session_close_callback():
            pass

        self.rpc_session = RemoteSession(self, _session_close_callback)
        self.plugin['xep_0009'].xmpp.add_event_handler('jabber_rpc_method_call', self.rpc_session._on_jabber_rpc_method_call, threaded=True)
        self.plugin['xep_0009'].xmpp.add_event_handler('jabber_rpc_method_response', self.rpc_session._on_jabber_rpc_method_response, threaded=True)
        self.plugin['xep_0009'].xmpp.add_event_handler('jabber_rpc_method_fault', self.rpc_session._on_jabber_rpc_method_fault, threaded=True)
        self.plugin['xep_0009'].xmpp.add_event_handler('jabber_rpc_error', self.rpc_session._on_jabber_rpc_error, threaded=True)

and added the Thermostat registration in _start

    def _start(self, event):
        self.send_presence()
        self.get_roster()
        self['xep_0115'].update_caps()

        thermostat = self.rpc_session.new_handler(ANY_ALL, Thermostat, 18)

The result is that the bot never receives the RPC calls and the client says NOT IMPLEMENTED. The SSL error actually is gone.

Hmm. What is the bit I'm missing?

[cajus]

Looks like it can be used "the other way around". If I let the Remote() class manage the client.process() it works. Although this might be not what one wants to do it works, I'm closing the issue.