Hi Flow;
I checked the recent commits and did not see anything mentioning stream management so I did not think new version might solve my issue. I will update, try and report back.
Best regards.
Unfortunately I still encounter it with 4.2.3.
Just a question btw., are the SENT - RECV log lines serial/in order? I mean can we just look at an outgoing ack, lets say it’s h = 20, count 5 incoming stanzas in the logs from that point on, and can reliably say the next one will/has to be 25?
Best regards.
The log may be out of order.
Afaik Recent Openfire has issues with StreamManagement, so it might in fact be an Openfire issue. Did you test your implementation against other servers too?
Yes, there is also an ejabberd server. Actually i already tested with it after upgrading smack to latest version. I did not encounter the same issue, it is also configured to use stream management and i can see acks in the logs.
It may either mean this is an openfire issue or still a smack issue but handled gracefully by the other server, i am not sure. However now that you mention it, we recently updated openfire to a new version and i dont remember it happening before. Do you know the exact version that has stream management issues? Thanks btw.
Anyway; whether caused by smack or openfire or my implementation, i have to pinpoint it. The app i am working on is almost unusable in its current state because of these disconnects. I will also check openfire support forums.
Best regards.
2 posts were merged into an existing topic: Terminating the connection on inconsistent Stream Management data
It should be in-order, otherwise the logs would be pretty useless.
To be frank, it looks more like an client issue. But on the other hand, I haven’t received a bug report regarding Smack’s Stream Management functionality in a while. But the log we see is
SENT (0): <a xmlns='urn:xmpp:sm:3' h='22'/>
RECV (0): <message></message>
RECV (0): <message></message>
RECV (0): <message></message>
RECV (0): <message></message>
…
RECV (0): <message></message>
…
SENT (0): <a xmlns='urn:xmpp:sm:3' h='29'/>
RECV (0): <stream:error xmlns:stream="http://etherx.jabber.org/streams"><undefined-condition xmlns="urn:ietf:params:xml:ns:xmpp-streams"/><text xmlns="urn:ietf:params:xml:ns:xmpp-streams">You acknowledged stanzas that we didn't send. Your Ack h: 29, our last stanza: 27</text></stream:error></stream:stream>
XMPPConnection closed due to an exception (XMPPTCPConnection[myuser2@mydomain.com/android] (0))
which clearly shows the server is right, indicating a client issue.
Today I will capture a wireshark trace and count the incoming packets after
stream establishment. I can replicate the issue but sometimes it takes too
long a sequence, if i can get a short enough one it should be countable.
And that should make the issue clear. I will share my findings.
Best regards
As an update to the issue; someone seems to have just posted this about the same problem:
If their analysis is correct, it looks like a bug on Openfire side. I am still going to capture a trace though.
Best regards.
Maybe it would be helpful to have the logs before the h=‘22’, i.e. the whole log.
So that we can count all reveived stanzas, just in case something went out of order in the log.
Hi once again;
I was able to clearly reproduce the problem while capturing a trace. I am not including the whole trace but I have a better result image. Here is what I did: I filtered the follow tcp output by incoming packets, copied the whole xml into Eclipse to format it and then marked all the stanzas in the xml document and this is the result:
The error I got was: “You acknowledged stanzas that we didn’t send. Your Ack h: 72, our last stanza: 70” but as you can see there actually are 72 incoming stanzas from the first till the stream termination. I will escalate this issue to our server team and to Openfire side of the forums. I can also send the original trace if someone is interested or wants to verify my findings.
Some ambiguity remains though, why were my first logs sort of indicating an error on the client side? Maybe there was some inconsistency in logging but the evidence I gathered is enough to shift my focus to server side for now.
Thanks to everybody for their comments and help.
3 Likes
This is very useful information, thanks. I’d love to see that trace. Clicking on the link that you provide gives me a “Request forbidden by administrative rules” error though. Can you make it available again please?
Seeing same issue with Android/Smack 4.2.0 and Openfire 4.2.3. Did not see issue when we previously used Openfire 4.1.6
I have tried updating to Smack 4.2.3, still having same issue
We will have to roll back to earlier version of Openfire due to existing Smack clients in use, which have stream mgmt enabled.
Does anyone know which version of Openfire introduced this behavior?
I also have a 3rd party XMPP client (Mac/Adium) that seems to behave quite a bit better (maybe it does not use stream mgmt?), but has also had minimal disconnect issues including error message “XMPP stream header missing”
I have tried to disable use of stream mgmt in Smack 4.2.3, and it seems to behave much better. But I may still have disconnect issues (much less frequently) which I need to review further
OpenFire/Server log
2018.03.28 11:41:02 WARN [socket_c2s-thread-3]: class org.jivesoftware.openfire.streammanagement.StreamManager[174.110.53.240] - Closing client session. Client acknowledges stanzas that we didn’t send! Client Ack h: 726, our last stanza: 721, affected session: org.jivesoftware.openfire.session.LocalClientSession@45e4880a status: 3 address: byoung@mytest.net/ANDROID-355301074232615 id: 8fz7b4mbfn presence:
Have also seen this variant in Openfire log
2018.03.28 13:14:49 ERROR [socket_c2s-thread-2]: org.jivesoftware.openfire.nio.ConnectionHandler - Closing connection due to error while processing message:
Smack/client error log
Often I see no error client side. The client continues to think it is still connected to Openfire, though it is not. But once I did capture this stack in the Android logcat
03-26 11:08:08.164 21274-26352/com.atakmap.app I/System.out: 11:08:08 RECV (2): <stream:error xmlns:stream=“http://etherx.jabber.org/streams”>You acknowledged stanzas that we didn’t send. Your Ack h: 143, our last stanza: 140</stream:error>
03-26 11:08:08.164 21274-26352/com.atakmap.app W/AbstractXMPPConnection: Connection XMPPTCPConnection[byoung@mytest.net/ANDROID-355301074232615] (2) closed with error
java.lang.IllegalStateException: Could not transform string ‘undefined_condition’ to XMPPErrorCondition
at org.jivesoftware.smack.packet.StreamError$Condition.fromString(StreamError.java:194)
at org.jivesoftware.smack.util.PacketParserUtils.parseStreamError(PacketParserUtils.java:820)
at org.jivesoftware.smack.tcp.XMPPTCPConnection$PacketReader.parsePackets(XMPPTCPConnection.java:1040)
at org.jivesoftware.smack.tcp.XMPPTCPConnection$PacketReader.access$300(XMPPTCPConnection.java:980)
at org.jivesoftware.smack.tcp.XMPPTCPConnection$PacketReader$1.run(XMPPTCPConnection.java:996)
at java.lang.Thread.run(Thread.java:818)
Caused by: java.lang.IllegalArgumentException: undefined_condition is not a constant in org.jivesoftware.smack.packet.StreamError$Condition
at java.lang.Enum.valueOf(Enum.java:200)
at org.jivesoftware.smack.packet.StreamError$Condition.valueOf(StreamError.java:156)
at org.jivesoftware.smack.packet.StreamError$Condition.fromString(StreamError.java:192)
at org.jivesoftware.smack.util.PacketParserUtils.parseStreamError(PacketParserUtils.java:820)
at org.jivesoftware.smack.tcp.XMPPTCPConnection$PacketReader.parsePackets(XMPPTCPConnection.java:1040)
at org.jivesoftware.smack.tcp.XMPPTCPConnection$PacketReader.access$300(XMPPTCPConnection.java:980)
at org.jivesoftware.smack.tcp.XMPPTCPConnection$PacketReader$1.run(XMPPTCPConnection.java:996)
at java.lang.Thread.run(Thread.java:818)
You could also simply disable stream management on server side, avoiding downgrading Openfire…
Was having the same issue so I edited the below value:
stream.management.active false
Everything is working okay now:)
Anyone can resolve this issue, I got the same problem.
If we set stream.management.active false, then stream resumption will not work, is it right 
?
Yes, but stream resumption doesn’t work very well when it’s set to true, either.
https://issues.igniterealtime.org/browse/OF-1497
Greg
1 Like
Thanks Greg,
When I set to false, I send a subscription request to a offline JID, when receiver online, he does not receive the subscription request.
Another case: When I set to false, I send a subscription request to a online JID, he receives the subscription request, but not accept or reject, he logout and login again, he does not receive subscription request again.
Do you know why?
I don’t, no. Sorry!
1 Like