no 'activeConnection' even though status is authenticated

[Daniel Gultsch]

I’m using blabber 0.8.2 and I got my XMPP clients into a weird state after an automatic reconnect that occurred after a network switch.

‌

I think this is the most telling stack trace:

java.lang.IllegalStateException: Session is not connected to server (status: AUTHENTICATED)
    at rocks.xmpp.core.session.XmppSession.sendInternal(XmppSession.java:910)
    at rocks.xmpp.core.session.XmppSession.trackAndSend(XmppSession.java:1000)
    at rocks.xmpp.core.session.XmppSession.sendIQ(XmppSession.java:973)
    at rocks.xmpp.core.session.XmppSession.sendAndAwait(XmppSession.java:822)
    at rocks.xmpp.core.session.XmppSession.query(XmppSession.java:748)
    at rocks.xmpp.core.session.XmppSession.query(XmppSession.java:733)
    at rocks.xmpp.extensions.pubsub.PubSubNode.getItems(PubSubNode.java:331)

‌

When ever I try to send an IQ (or any stanza for that matter) the IQ would instantly fail because the XmppClient didn’t think it was connected. However status was AUTHENTICATED and has previously went through all prior status CONNECTING, CONNECTED, AUTHENTICATING etc after the automatic reconnect. (It was fine before the reconnect as well)

In that state the XMPP client was able to receive stanzas. Any inbound message listeners etc would fire. So my assumption is that the xmpp client was indeed connected but activeConnection (which is would is being checked when this IllegalStateException is thrown was null for some reason.

‌

Probably some kind of race condition. I‘m unable to reproduce this now under artificial conditions. One probably noteworthy thing is that I had ~30ish XMPP clients connected in the same JVM and ~10 of them showed this behaviour when the network switch occurred. (Not sure to what degree different XmppClients would share the same threads or synchronize around the same static variables or something.

[Daniel Gultsch]

As a somewhat interesting side note: Because the xmpp client connection was still happily receiving messages (and other stanza) the PingManager never fired or else it would have probably caught this problem and restarted the connection.

[Christian Schudt]

That’s a tough one. I browsed throught the code, but have no clue yet, what could be the cause.

Would you try also Version 0.9.0-SNAPSHOT?

[Daniel Gultsch]

I have not tried 0.9.0. Have there been any significant changes around (re)connect and/or the synchronization around it? Like I said I can’t exactly reproduce it. It just seems to happen from time to time.

In fact I have another data point:

java.lang.NullPointerException: null
at rocks.xmpp.core.session.XmppClient.connect(XmppClient.java:239)
at rocks.xmpp.core.session.XmppSession.connect(XmppSession.java:315)
at rocks.xmpp.core.session.ReconnectionManager.lambda$scheduleReconnection$1(ReconnectionManager.java:164)
at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
at rocks.xmpp.util.concurrent.QueuedScheduledExecutorService$ScheduledFutureTask.doRun(QueuedScheduledExecutorService.java:266)
at rocks.xmpp.util.concurrent.QueuedExecutorService.doExecute(QueuedExecutorService.java:154)
at rocks.xmpp.util.concurrent.QueuedExecutorService.lambda$poll$0(QueuedExecutorService.java:126)
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
at java.base/java.lang.Thread.run(Thread.java:829)

This appeared in the logs. I don’t think this happens before the other error I outlined above but instead. But I think the underlying causes might be similar as this also happened during a connection loss and looking at the respective code it also looks like activeConnection is null in a place where we don’t assume it would be null.

‌