Hello,
For some time, I’ve occasionally received two identical responses when
using XMPP with my openhab installation. Today, I received 5, so I
decided to dig a bit.
When I run sudo -u ejabberd ejabberdctl connected_users on my jabber
server, I see that the openhab account is indeed connected on 5 separate
sessions.
I have had debug logging enabled for the XMPP service, so I went to my
run.log and did a quick grep for xmpp:
2016-05-10 01:24:48.846 [DEBUG] [.a.xmpp.internal.XMPPActivator] - XMPP action has been started.
2016-05-10 01:24:51.849 [INFO ] [tion.xmpp.internal.XMPPConnect] - Connection to XMPP as ‘openhab@timesinks.net/11651746611462868691693730’ has been established. Is secure/encrypted: true
2016-05-10 01:24:58.200 [DEBUG] [riptExtensionClassNameProvider] - Script actions have changed: HTTPActionService, PingActionService, ExecActionService, TransformationActionService, AudioActionService, XMPPActionService,
2016-05-10 01:28:32.121 [DEBUG] [riptExtensionClassNameProvider] - Script actions have changed: HTTPActionService, PingActionService, ExecActionService, TransformationActionService, AudioActionService, XMPPActionService,
2016-05-11 04:40:22.193 [WARN ] [esoftware.smack.XMPPConnection] - Connection closed with error
2016-05-11 04:40:42.257 [WARN ] [tion.xmpp.internal.XMPPConnect] - XMPP connection has been closed on error: {}
2016-05-11 04:40:45.074 [ERROR] [tion.xmpp.internal.XMPPConnect] - Could not establish connection to XMPP server ‘timesinks.net:5222’: null
2016-05-11 04:40:45.075 [ERROR] [tion.xmpp.internal.XMPPConnect] - XMPP re-connection failed, giving up: null
2016-05-11 11:10:23.458 [INFO ] [tion.xmpp.internal.XMPPConnect] - Connection to XMPP as ‘openhab@timesinks.net/30346330001462990223377439’ has been established. Is secure/encrypted: true
2016-05-11 11:10:23.545 [DEBUG] [nhab.action.xmpp.internal.XMPP] - Sent message ‘Lights out!’ to ‘ccowart@timesinks.net’.
2016-05-12 10:25:07.476 [DEBUG] [nhab.action.xmpp.internal.XMPP] - Sent message ‘Lights out!’ to ‘ccowart@timesinks.net’.
2016-05-12 11:27:07.426 [WARN ] [esoftware.smack.XMPPConnection] - Connection closed with error
2016-05-12 11:27:07.427 [WARN ] [esoftware.smack.XMPPConnection] - Connection closed with error
2016-05-12 11:27:07.440 [WARN ] [tion.xmpp.internal.XMPPConnect] - XMPP connection has been closed on error: {}
2016-05-12 11:27:07.446 [WARN ] [tion.xmpp.internal.XMPPConnect] - XMPP connection has been closed on error: {}
2016-05-12 11:27:07.610 [ERROR] [tion.xmpp.internal.XMPPConnect] - Could not establish connection to XMPP server ‘timesinks.net:5222’: null
2016-05-12 11:27:07.611 [ERROR] [tion.xmpp.internal.XMPPConnect] - XMPP re-connection failed, giving up: null
2016-05-12 11:27:07.611 [ERROR] [tion.xmpp.internal.XMPPConnect] - Could not establish connection to XMPP server ‘timesinks.net:5222’: null
2016-05-12 11:27:07.611 [ERROR] [tion.xmpp.internal.XMPPConnect] - XMPP re-connection failed, giving up: null
2016-05-13 12:04:07.207 [INFO ] [tion.xmpp.internal.XMPPConnect] - Connection to XMPP as ‘openhab@timesinks.net/4116926643146316624774681’ has been established. Is secure/encrypted: true
It would appear that when there are transient connectivity problems,
openhab creates a new connection – but the pre-existing and temporarily
failing ones aren’t cleaned up. So when the connectivity issue resolves,
you wind up with multiple sessions to the server.
This repeats for a couple more episodes until we wind up with 5 open
sessions and 5 actions taken for every message received:
2016-05-31 21:22:29.050 [DEBUG] [tion.xmpp.internal.XMPPConsole] - Received XMPP message: send livingArea 0 of type chat
2016-05-31 21:22:29.051 [DEBUG] [tion.xmpp.internal.XMPPConsole] - Received XMPP message: send livingArea 0 of type chat
2016-05-31 21:22:29.051 [DEBUG] [tion.xmpp.internal.XMPPConsole] - Received XMPP message: send livingArea 0 of type chat
2016-05-31 21:22:29.051 [DEBUG] [tion.xmpp.internal.XMPPConsole] - Received XMPP message: send livingArea 0 of type chat
2016-05-31 21:22:29.050 [DEBUG] [tion.xmpp.internal.XMPPConsole] - Received XMPP message: send livingArea 0 of type chat
I’m currently running 1.8.2. Is this a known issue?
On a side note, as I was digging, I noticed that the xmpp client appears
not to connect using ipv6. That made me a little sad.
Thanks for all the hard work you put into this project.