Server terminates client connection due to the client acknowledging a stanza that was not sent by the server

[alex.rudnev]

Hello,

We are on Openfire 4.2.2 with OFMeet / OFFocus plugins 0.9.3 (or custom builds based on 0.9.4-SNAPSHOT with smack libraries bumped up to 4.2.3) running in Ubuntu 16.04 based docker containers.

From time to time client connection of focus user from OFFocus plugin gets terminated by the server.
When it happens server logs message similar to this one:

2018.03.06 19:53:53 WARN  [socket_c2s-thread-3]: class org.jivesoftware.openfire.streammanagement.StreamManager[127.0.0.1] - Closing client session. Client acknowledges stanzas that we didn't send! Client Ack h: 27, our last stanza: 26

When server closes the connection it does that with the following error:

new StreamError( StreamError.Condition.undefined_condition, "You acknowledged stanzas that we didn't send. Your Ack h: " + h + ", our last stanza: " + unacknowledgedServerStanzas.getLast().x );

Unfortunately, OFFocus 0.9.3 ships with smack 4.2.1, which had misspelled value for undefined_condition enum, but if we upgrade to 4.2.3 version of the smack libraries we see the following error on the client side of the connection:

2018.03.06 19:53:53 WARN  [Smack Packet Reader (0)]: org.jivesoftware.smack.AbstractXMPPConnection - Connection XMPPTCPConnection[focus@some-xmpp-domain/focus1301297637290360] (0) closed with error
org.jivesoftware.smack.XMPPException$StreamErrorException: undefined-condition You can read more about the meaning of this stream error at http://xmpp.org/rfcs/rfc6120.html#streams-error-conditions
<stream:error><undefined-condition xmlns='urn:ietf:params:xml:ns:xmpp-streams'/><text>You acknowledged stanzas that we didn&apos;t send. Your Ack h: 27, our last stanza: 26</text></stream:error>
	at org.jivesoftware.smack.tcp.XMPPTCPConnection$PacketReader.parsePackets(XMPPTCPConnection.java:1058)
	at org.jivesoftware.smack.tcp.XMPPTCPConnection$PacketReader.access$300(XMPPTCPConnection.java:994)
	at org.jivesoftware.smack.tcp.XMPPTCPConnection$PacketReader$1.run(XMPPTCPConnection.java:1010)
	at java.lang.Thread.run(Thread.java:748)
2018.03.06 19:53:53 ERROR [Smack Packet Reader (0)]: org.jitsi.impl.protocol.xmpp.XmppProtocolProvider - XMPP connection closed on error: undefined-condition You can read more about the meaning of this stream error at http://xmpp.org/rfcs/rfc6120.html#streams-error-conditions
<stream:error><undefined-condition xmlns='urn:ietf:params:xml:ns:xmpp-streams'/><text>You acknowledged stanzas that we didn&apos;t send. Your Ack h: 27, our last stanza: 26</text></stream:error> 

It seems that server sends multiple stanzas to the client and client sometimes acknowledges them before they are added to the list of unacknowledged stanzas in the org.jivesoftware.openfire.streammanagement.StreamManager.

Here is an example sequence that demonstrates that (we were running it with stream.management.requestFrequency=20 in this case, but it’s the same with default value of 5):

2018.03.06 22:55:15 TRACE [socket_c2s-thread-2]: class org.jivesoftware.openfire.streammanagement.StreamManager[127.0.0.1] - Added stanza of type 'iq' to collection of unacknowledged stanzas (x=62). Collection size is now 20.
2018.03.06 22:55:15 DEBUG [socket_c2s-thread-2]: class org.jivesoftware.openfire.streammanagement.StreamManager[127.0.0.1] - Requesting acknowledgement from peer, as we have 20 or more unacknowledged stanzas.
2018.03.06 22:55:15 DEBUG [socket_c2s-thread-3]: class org.jivesoftware.openfire.streammanagement.StreamManager[127.0.0.1] - Received acknowledgement from client: h=64
2018.03.06 22:55:15 WARN  [socket_c2s-thread-3]: class org.jivesoftware.openfire.streammanagement.StreamManager[127.0.0.1] - Closing client session. Client acknowledges stanzas that we didn't send! Client Ack h: 64, our last stanza: 62
2018.03.06 22:55:16 TRACE [pool-6-thread-13]: class org.jivesoftware.openfire.streammanagement.StreamManager[127.0.0.1] - Added stanza of type 'iq' to collection of unacknowledged stanzas (x=63). Collection size is now 21.
2018.03.06 22:55:16 TRACE [Jetty-QTP-BOSH-75]: class org.jivesoftware.openfire.streammanagement.StreamManager[127.0.0.1] - Added stanza of type 'iq' to collection of unacknowledged stanzas (x=64). Collection size is now 22.
2018.03.06 22:55:21 TRACE [Jetty-QTP-BOSH-71]: class org.jivesoftware.openfire.streammanagement.StreamManager[127.0.0.1] - Added stanza of type 'presence' to collection of unacknowledged stanzas (x=65). Collection size is now 23.
2018.03.06 22:55:25 TRACE [socket_c2s-thread-3]: class org.jivesoftware.openfire.streammanagement.StreamManager[127.0.0.1] - Added stanza of type 'iq' to collection of unacknowledged stanzas (x=1). Collection size is now 1.

[sydnal]

I also encountered the same problem as a client developer and initially thought it was a smack issue:

Smack ack 'h' (handled) count terminates the stream with OpenFire Server

Hi; I am using Smack 4.2.0 in Android, connecting to an OpenFire server. When I enable stream management I occasionally get an error like this and the stream is terminated: <stream:error xmlns:stream=“http://etherx.jabber.org/streams”>You acknowledged stanzas that we didn’t send. Your Ack h: 13, our last stanza: 10</stream:error></stream:stream> When I check the logs and count the incoming stanzas, server seems to be right about this message. Here is a sample log which starts with a correct ac…

I already linked this issue there. Anyway after some debugging and trace captures we concluded that this is an Openfire issue. Maybe stream termination decision could be reconsidered until a fix for stream management is ready.

Best regards.

[Brian38]

This issue plagues me as well, I posted few comments over on the referenced Smack support bug since it had more recent activity