Bot doesn't show in contact list after session established

[bossyang]

The bot doesn't show in contact list after session established. I can see its session on admin console. But its presence state is offline.

XMPP Server: Openfire 4.0.3

11:58:59.930 [info]  Established connection to im.jourdeness.com.tw

11:58:59.938 [debug] [hubot@im.jourdeness.com.tw][OUTGOING] "<stream:stream to='im.jourdeness.com.tw' version='1.0' xml:lang='en' xmlns='jabber:client' xmlns:stream='http://etherx.jabber.org/streams'>"

11:58:59.941 [debug] [hubot@im.jourdeness.com.tw][INCOMING] "<?xml version='1.0' encoding='UTF-8'?><stream:stream xmlns:stream=\"http://etherx.jabber.org/streams\" xmlns=\"jabber:client\" from=\"im.jourdeness.com.tw\" id=\"10f7uphfoo\" xml:lang=\"en\" version=\"1.0\">"

11:59:00.146 [debug] [hubot@im.jourdeness.com.tw][INCOMING] "<stream:features><starttls xmlns=\"urn:ietf:params:xml:ns:xmpp-tls\"></starttls><mechanisms xmlns=\"urn:ietf:params:xml:ns:xmpp-sasl\"><mechanism>PLAIN</mechanism><mechanism>JIVE-SHAREDSECRET</mechanism></mechanisms><compression xmlns=\"http://jabber.org/features/compress\"><method>zlib</method></compression><auth xmlns=\"http://jabber.org/features/iq-auth\"/><register xmlns=\"http://jabber.org/features/iq-register\"/></stream:features>"

11:59:00.147 [debug] [hubot@im.jourdeness.com.tw][OUTGOING] "<starttls xmlns='urn:ietf:params:xml:ns:xmpp-tls'/>"

11:59:00.152 [debug] [hubot@im.jourdeness.com.tw][INCOMING] "<proceed xmlns=\"urn:ietf:params:xml:ns:xmpp-tls\"/>"

11:59:00.152 [info]  Negotiating secure connection

11:59:00.546 [info]  Connection successfully secured

11:59:00.546 [debug] [hubot@im.jourdeness.com.tw][OUTGOING] "<stream:stream to='im.jourdeness.com.tw' version='1.0' xml:lang='en' xmlns='jabber:client' xmlns:stream='http://etherx.jabber.org/streams'>"

11:59:00.547 [debug] [hubot@im.jourdeness.com.tw][INCOMING] "<?xml version='1.0' encoding='UTF-8'?><stream:stream xmlns:stream=\"http://etherx.jabber.org/streams\" xmlns=\"jabber:client\" from=\"im.jourdeness.com.tw\" id=\"10f7uphfoo\" xml:lang=\"en\" version=\"1.0\"><stream:features><mechanisms xmlns=\"urn:ietf:params:xml:ns:xmpp-sasl\"><mechanism>PLAIN</mechanism><mechanism>JIVE-SHAREDSECRET</mechanism></mechanisms><compression xmlns=\"http://jabber.org/features/compress\"><method>zlib</method></compression><auth xmlns=\"http://jabber.org/features/iq-auth\"/><register xmlns=\"http://jabber.org/features/iq-register\"/></stream:features>"

11:59:00.549 [info]  Authenticating with PLAIN

11:59:00.560 [debug] [hubot@im.jourdeness.com.tw][OUTGOING] "<auth xmlns='urn:ietf:params:xml:ns:xmpp-sasl' mechanism='PLAIN'>AGh1Ym90AHFhdTdmYzR6</auth>"

11:59:00.573 [debug] [hubot@im.jourdeness.com.tw][INCOMING] "<success xmlns=\"urn:ietf:params:xml:ns:xmpp-sasl\"/>"

11:59:00.573 [info]  Authenticated successfully

11:59:00.573 [debug] [hubot@im.jourdeness.com.tw][OUTGOING] "<stream:stream to='im.jourdeness.com.tw' version='1.0' xml:lang='en' xmlns='jabber:client' xmlns:stream='http://etherx.jabber.org/streams'>"

11:59:00.574 [debug] [hubot@im.jourdeness.com.tw][INCOMING] "<?xml version='1.0' encoding='UTF-8'?><stream:stream xmlns:stream=\"http://etherx.jabber.org/streams\" xmlns=\"jabber:client\" from=\"im.jourdeness.com.tw\" id=\"10f7uphfoo\" xml:lang=\"en\" version=\"1.0\"><stream:features><compression xmlns=\"http://jabber.org/features/compress\"><method>zlib</method></compression><bind xmlns=\"urn:ietf:params:xml:ns:xmpp-bind\"/><session xmlns=\"urn:ietf:params:xml:ns:xmpp-session\"><optional/></session><sm xmlns='urn:xmpp:sm:2'/><sm xmlns='urn:xmpp:sm:3'/></stream:features>"

11:59:00.574 [debug] [hubot@im.jourdeness.com.tw][OUTGOING] "<iq type='set' id='d4a9'><bind xmlns='urn:ietf:params:xml:ns:xmpp-bind'><resource></resource></bind></iq>"

11:59:00.578 [debug] [hubot@im.jourdeness.com.tw][INCOMING] "<iq type=\"result\" id=\"d4a9\" to=\"im.jourdeness.com.tw/10f7uphfoo\"><bind xmlns=\"urn:ietf:params:xml:ns:xmpp-bind\"><jid>hubot@im.jourdeness.com.tw/10f7uphfoo</jid></bind></iq>"

11:59:00.578 [info]  Bound to resource: 10f7uphfoo

11:59:00.578 [debug] [hubot@im.example.com.tw][OUTGOING] "<iq type='set' id='328c'><session xmlns='urn:ietf:params:xml:ns:xmpp-session'/></iq>"

11:59:00.581 [debug] [hubot@im.jourdeness.com.tw][INCOMING] "<iq type=\"result\" id=\"328c\" to=\"hubot@im.jourdeness.com.tw/10f7uphfoo\"/>"

11:59:00.581 [info]  Session established

11:59:00.581 [debug] [hubot@im.jourdeness.com.tw][OUTGOING] "<iq type='get' id='3e2d'><query xmlns='jabber:iq:roster'/></iq>"

[scrogson]

Is that the end of the logs for the bot? Looks like it may be deadlocked waiting for the roster to come back. If that's the case, there is a bug I will need to fix. I don't see the debug message for the bot sending <presence/> to the server. So that would be why you do not see it online.

[bossyang]

@scrogson Yes. All logs here from iex console.

[scrogson]

Hello @bossyang,

Can you please try this again by adding the following to your deps:

{:romeo, github: "scrogson/romeo", override: true}

I have fixed a few things in Romeo that should fix this issue.

Thank you

[bossyang]

@scrogson It works! What a Happy Monday morning. Thank you.