going offline after some time

[Jaglag]

Hi,

the bot just going offline after some time of idle and i dont know how to fix that:

[Sat Feb 22 2014 13:41:31 GMT+0100 (CET)] DEBUG [received iq]  iq type="get" id="111-111111" from="robertsspaceindustries.com" to="[email protected]/7fbb6dc0" xmlns:stream="http://etherx.jabber.org/streams"><ping xmlns="urn:xmpp:ping"/ /iq


 [Sat Feb 22 2014 13:41:31 GMT+0100 (CET)] DEBUG [sending pong] iq to="robertsspaceindustries.com" from="[email protected]/7fbb6dc0" type="result" id="111-111111"/


 [Sat Feb 22 2014 13:46:34 GMT+0100 (CET)] DEBUG Received offline event
 [Sat Feb 22 2014 13:46:34 GMT+0100 (CET)] DEBUG Received offline event

sometimes it takes 30min sometime over 2 hours then he´s going offline

[markstory]

It sounds like your server is sending the offline message. What jabber server are you using?

[Jaglag]

i dont know exactly which server version this is i think its a modded version for this game:
https://robertsspaceindustries.com/faq/xmpp-setup
but i can connect via pidgin or any other xmpp client without special settings or something else and idle for hours!
only the bot disconnects
Im in a channel via bitlbee over a znc with mirc too without any problems.

[Jaglag]

thats some parts of my pidgin connection log:

 jabber: Sending (ssl) ([email protected]/ee4db276): iq type='result' id='127:sendIQ' to='[email protected]/Semtecs' query xmlns='http://jabber.org/protocol/disco#info' node='http://pidgin.im/#I22W7CegORwdbnu0ZiQwGpxr0Go=' identity category='client' type='pc' name='Pidgin'/><feature var='jabber:iq:last'/ feature var='jabber:iq:oob'/ feature var='urn:xmpp:time'/ feature var='jabber:iq:version'/ feature var='jabber:x:conference'/ feature var='http://jabber.org/protocol/bytestreams'/ feature var='http://jabber.org/protocol/caps'/ feature var='http://jabber.org/protocol/chatstates'/ feature var='http://jabber.org/protocol/disco#info'/ feature var='http://jabber.org/protocol/disco#items'/ feature var='http://jabber.org/protocol/muc'/ feature var='http://jabber.org/protocol/muc#user'/ feature var='http://jabber.org/protocol/si'/ feature var='http://jabber.org/protocol/si/profile/file-transfer'/ feature var='http://jabber.org/protocol/xhtml-im'/ feature var='urn:xmpp:ping'/ feature var='urn:xmpp:attention:0'/ feature var='urn:xmpp:bob'/ feature var='urn:xmpp:jingle:1'/ feature var='urn:xmpp:avatar:metadata'/ feature var='urn:xmpp:avatar:data'/><feature var='urn:xmpp:avatar:metadata+notify'/ feature var='http://jabber.org/protocol/mood'/ feature var='http://jabber.org/protocol/mood+notify'/ feature var='http://jabber.org/protocol/tune'/ feature var='http://jabber.org/protocol/tune+notify'/ feature var='http://jabber.org/protocol/nick'/ feature var='http://jabber.org/protocol/nick+notify'/ feature var='http://jabber.org/protocol/ibb'/ /query /iq

here connecting a user to the channel:

(13:05:46) jabber: Recv (ssl)(371): presence to="[email protected]/ee4db276" from="[email protected]/user" type="unavailable" c xmlns="http://jabber.org/protocol/caps" hash="sha-1" node="https://candy-chat.github.io/candy/" ver="kR9jljQwQFoklIvoOmy/GAli0gA=" x xmlns="http://jabber.org/protocol/muc#user" item affiliation="member" role="none"/ /x /presence

And this is the bot:

(13:05:55) jabber: Recv (ssl)(1): 
(13:05:55) jabber: Recv (ssl)(238): presence to="[email protected]/ee4db276" from="[email protected]/user" type="unavailable" x xmlns="http://jabber.org/protocol/muc#user" item affiliation="member" role="none"/ /x /presence

here a ping via pidgin:

(13:40:14) jabber: Sending (ssl) ([email protected]/ee4db276):  iq type='get' id='purplebca203ac' ping xmlns='urn:xmpp:ping iq
(13:40:14) jabber: Recv (ssl)(1):
(13:40:14) jabber: Recv (ssl)(86): iq type="result" id="purplebca203ac" to="[email protected]/ee4db276"/

and 1 warning via pidgin:

(13:09:40) jabber: <show/> present on presence, but type is not default ('available')

and here the leave log from basebot:

(13:48:44) jabber: Recv (ssl)(238): presence to="[email protected]/ee4db276" from="[email protected]/username" type="unavailable" x xmlns="http://jabber.org/protocol/muc#user" item affiliation="member" role="none x /presence

the weird thing wen i set ssl to 1 and port to 5223 it wont let me connect with the bot.
here in pidgin everywhere is an ssl tag..

[Jaglag]

what variables i have for the disable tls option 0,1,2 etc?
like
0 means SSL 3.0, 1 means TLS 1.0, 2 means TLS 1.1, etc?

[bnied]

This sounds similar to my issue, where Hubot won't automatically reconnect once it receives the offline event from the server.

[Jaglag]

markstory can you write a workaround like:
when hubot getting offline message restart hubot?

[markstory]

@bnied This does sound like #58. As soon as I figure out how to make ejabberd send and offline message I should be able to figure this out.

[Jaglag]

@markstory is the disconnect thing now fixxed in 1.10? so i can use it?

[markstory]

I was never able to reproduce the issues on the ejabberd servers I have access to.

[bnied]

@markstory if you restart your ejabberd server while hubot is still connected, does it reconnect as expected?

[markstory]

I have not tried that. Based on reading the code the bot will not reconnect, as the offline event handler does not attempt to reconnect.

[bnied]

I thought #37 was supposed to add that functionality.

[markstory]

True, I totally forgot about that, if a reconnect is not happening it might poi t to a problem in node-xmpp, as the main change in #37 was to set the reconnect option.

I can see how hubot handles ejabberd restarting.

[bnied]

If it does work, can you let me know which version of node-xmpp you're running?

[pixelrebel]

I'm having this issue too. But I don't see the server (slack) sending an offline event. Instead, what I see in the log is that hubot sends a ping every 30 seconds and receives a bad-request "Missing 'id'" error:

[Wed Aug 26 2015 13:10:54 GMT-0700 (PDT)] DEBUG [sending ping] <iq type="get"><ping xmlns="urn:xmpp:ping"/></iq>
[Wed Aug 26 2015 13:10:54 GMT-0700 (PDT)] ERROR [xmpp error]<iq type="error" xmlns:stream="http://etherx.jabber.org/streams"><error type="modify"><bad-request xmlns="urn:ietf:params:xml:ns:xmpp-stanzas"/><text xmlns="urn:ietf:params:xml:ns:xmpp-stanzas" xml:lang="en">Missing 'id'</text></error></iq>

At the moment hubot disconnects, nothing else shows in the logs, but the ping with its error still continues every 30 seconds.

[pixelrebel]

Still stuck on the above issue. Can anyone confirm this "Missing id" error is causing hubot to disconnect? My workaround is a cron restart every 30 minutes. Any advice? Thanks.

[anupdhml]

@pixelrebel are you using this with slack? There's a slack adapter for hubot, which should be a better choice: https://github.com/slackhq/hubot-slack

If you have to use this, your problem seems to be beacuse hubot-xmpp currently does not include 'id' field in the ping messages: https://github.com/markstory/hubot-xmpp/blob/master/src/xmpp.coffee#L112

[pixelrebel]

@anupdhml: I am using the hubot-xmpp adapter with slack because my bot needs to upload files and send attachments which (correct me if I'm wrong) isn't currently supported by hubot-slack.

Perhaps I can fork this project and add a line for the id. Do you know what id this error is referring to? Can this just be a random number?

[pixelrebel]

Well, adding the id to iq ping stanza didn't solve my disconnection problem, but it does make the "bad-request" error go away.

I submitted a PR for this fix:
#93

[anupdhml]

@pixelrebel I found this for slack: slackapi/node-slack-sdk#56, but merging it could be tricky. hubot-xmpp does not currently support sending attachments though: you would have to write in the functionality. So maybe give hubot-slack with that PR a try?

From the xmpp specification:

There SHOULD NOT be an 'id' attribute on the XML stream header sent from the initiating entity to the receiving entity; however, if an 'id' attribute is included, it SHOULD be silently ignored by the receiving entity.

But looks like slack has different expectations. Adding id to ping stanzas probably won't have any side effects, so your PR should be all right. I used ids in #90 (comment) and haven't noticed anything off.

[pixelrebel]

@anupdhml That's interesting about the xmpp spec. I actually found this example which includes the id in the iq tag, but I guess it's not based off the official spec?

Now I'm thinking it's best abide by the spec. I can just keep my own fork if I continue to use this adapter with slack. In fact, #93 does not fix my connection problem, so it just a petty fix to avoid an error from slack.

[anupdhml]

@pixelrebel yes #93 does not solve your connection issues. Have you tried debugging from here: https://github.com/markstory/hubot-xmpp/blob/master/src/xmpp.coffee#L194

Add something like console.log stanza.toString() to see all the incoming stanzas from the server. Maybe it will give you a clue as to what's going wrong. If only you could access slack logs, this would be much easier.

[pixelrebel]

Thanks for the tip @anupdhml . I gave that a try, but I didn't see anything that stood out. I have a support ticket open asking them to check their server logs around the last time I was booted. I'll let you know if they come back with anything interesting.

I'm thinking about going back to the hubot-slack adapter. This recent commit slackapi/hubot-slack@d8d6660 is sort of a revelation to me. It seems slack now allows real users to use the adapter. Which is all I really need at this point. Attachments are also supported, and I'm using curl to upload files anyway.

[pixelrebel]

@anupdhml Here's what slack support came back with:

It looks like the client is disconnecting — there was a pretty noticeable pattern of disconnection messages coming in every thirty minutes. It also looks like a lot of these disconnections are initiated around the same time the client is marked as away. I'm not sure that's related, but thought I'd pass it on anyway.

This makes sense to me because it doesn't seem to disconnect when the bot is actively posting. So, is there a way to keep the bot from going idle?

[anupdhml]

@pixelrebel If that's the case, you should be able to keep hubot online by broadcasting presence messages at fixed intervals.

http://xmpp.org/rfcs/rfc3921.html#rfc.section.5.1.2

If slack's XMPP implementation follows the spec here, it should work. You can model the code on the initial presence stanza that hubot currently sends.

There should be a better way of doing it though: the underlying node-xmpp client should have detected the disconnect from slack, and hubot-xmpp should be able to catch that and reconnect. There's already some code for reconnecting, but looks like slack behaves differently. See if the disconnect event used here helps.

Let me know if you need help as you go about this, good luck!