Hi, I’m using Openfire 4.5.2. I use stanza.io and bosh on the client side. Client receives a terminate package within 5-10 minutes after connecting, even though the internet connection is good:
<body xmlns="http://jabber.org/protocol/httpbind" type="terminate" condition="item-not-found"/>
I opened log.httpbind.enabled on Openfire side, and saw the following log records.
2020.08.25 10:26:54 INFO [Jetty-QTP-BOSH-23202]: org.jivesoftware.openfire.http.HttpBindServlet - HTTP RECV(5eq8dbree2): <body xmlns:xmpp="urn:xmpp:xbosh" rid="6027381331" sid="5eq8dbree2"></body>
2020.08.25 10:26:54 INFO [Jetty-QTP-BOSH-23202]: org.jivesoftware.openfire.http.HttpSession - Creating connection for rid: 6027381331 in session 5eq8dbree2
2020.08.25 10:26:54 INFO [Jetty-QTP-BOSH-23202]: org.jivesoftware.openfire.http.HttpSession - Adding connection to stream 5eq8dbree2 with rid 6027381331
2020.08.25 10:27:02 WARN [Jetty-QTP-BOSH-23875]: org.eclipse.jetty.server.HttpChannelState - java.lang.NullPointerException while invoking onTimeout listener org.eclipse.jetty.server.AsyncContextState$WrappedAsyncListener@51f34c6b
2020.08.25 10:27:02 INFO [Jetty-QTP-BOSH-23875]: org.jivesoftware.openfire.http.HttpBindServlet - HTTP SENT(i2qd5qcwi): <body xmlns='http://jabber.org/protocol/httpbind' ack='3005658049'></body>
2020.08.25 10:27:02 INFO [Jetty-QTP-BOSH-22652]: org.jivesoftware.openfire.http.HttpBindServlet - HTTP RECV(i2qd5qcwi): <body xmlns:xmpp="urn:xmpp:xbosh" rid="3005658050" sid="i2qd5qcwi"></body>
2020.08.25 10:27:02 INFO [Jetty-QTP-BOSH-22652]: org.jivesoftware.openfire.http.HttpSession - Creating connection for rid: 3005658050 in session i2qd5qcwi
2020.08.25 10:27:02 INFO [Jetty-QTP-BOSH-22652]: org.jivesoftware.openfire.http.HttpSession - Adding connection to stream i2qd5qcwi with rid 3005658050
2020.08.25 10:27:24 WARN [Jetty-QTP-BOSH-23875]: org.eclipse.jetty.server.HttpChannelState - java.lang.NullPointerException while invoking onTimeout listener org.eclipse.jetty.server.AsyncContextState$WrappedAsyncListener@6a0b6032
2020.08.25 10:27:24 INFO [Jetty-QTP-BOSH-23875]: org.jivesoftware.openfire.http.HttpBindServlet - HTTP SENT(5eq8dbree2): <body xmlns='http://jabber.org/protocol/httpbind' ack='6027381331'></body>
2020.08.25 10:27:24 WARN [Jetty-QTP-BOSH-23875]: org.eclipse.jetty.server.HttpChannelState - java.io.IOException: java.util.concurrent.TimeoutException: Idle timeout expired: 30001/30000 ms while invoking onTimeout listener org.jivesoftware.openfire.http.HttpSession$3@64861fd2
2020.08.25 10:27:24 WARN [Jetty-QTP-BOSH-23875]: org.eclipse.jetty.util.thread.QueuedThreadPool -
java.lang.IllegalStateException: ABORTED
at org.eclipse.jetty.server.HttpChannelState.sendError(HttpChannelState.java:893) ~[jetty-server-9.4.28.v20200408.jar:9.4.28.v20200408]
at org.eclipse.jetty.server.HttpChannelState.nextAction(HttpChannelState.java:501) ~[jetty-server-9.4.28.v20200408.jar:9.4.28.v20200408]
at org.eclipse.jetty.server.HttpChannelState.unhandle(HttpChannelState.java:420) ~[jetty-server-9.4.28.v20200408.jar:9.4.28.v20200408]
at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:529) ~[jetty-server-9.4.28.v20200408.jar:9.4.28.v20200408]
at org.eclipse.jetty.server.HttpChannel.run(HttpChannel.java:335) ~[jetty-server-9.4.28.v20200408.jar:9.4.28.v20200408]
at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:806) ~[jetty-util-9.4.28.v20200408.jar:9.4.28.v20200408]
at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:938) [jetty-util-9.4.28.v20200408.jar:9.4.28.v20200408]
at java.lang.Thread.run(Thread.java:748) [?:1.8.0_151]
2020.08.25 10:27:24 INFO [Jetty-QTP-BOSH-23387]: org.jivesoftware.openfire.http.HttpBindServlet - HTTP RECV(5eq8dbree2): <body xmlns:xmpp="urn:xmpp:xbosh" rid="6027381332" sid="5eq8dbree2"></body>
2020.08.25 10:27:24 INFO [Jetty-QTP-BOSH-23387]: org.jivesoftware.openfire.http.HttpSession - Creating connection for rid: 6027381332 in session 5eq8dbree2
2020.08.25 10:27:24 INFO [Jetty-QTP-BOSH-23387]: org.jivesoftware.openfire.http.HttpSession - Adding connection to stream 5eq8dbree2 with rid 6027381332
2020.08.25 10:27:32 WARN [Jetty-QTP-BOSH-23875]: org.eclipse.jetty.server.HttpChannelState - java.lang.NullPointerException while invoking onTimeout listener org.eclipse.jetty.server.AsyncContextState$WrappedAsyncListener@22e716c8
2020.08.25 10:27:32 INFO [Jetty-QTP-BOSH-23875]: org.jivesoftware.openfire.http.HttpBindServlet - HTTP SENT(i2qd5qcwi): <body xmlns='http://jabber.org/protocol/httpbind' ack='3005658050'></body>
2020.08.25 10:27:32 INFO [Jetty-QTP-BOSH-22652]: org.jivesoftware.openfire.http.HttpBindServlet - HTTP RECV(i2qd5qcwi): <body xmlns:xmpp="urn:xmpp:xbosh" rid="3005658051" sid="i2qd5qcwi"></body>
2020.08.25 10:27:32 INFO [Jetty-QTP-BOSH-22652]: org.jivesoftware.openfire.http.HttpSession - Creating connection for rid: 3005658051 in session i2qd5qcwi
2020.08.25 10:27:32 INFO [Jetty-QTP-BOSH-22652]: org.jivesoftware.openfire.http.HttpSession - Adding connection to stream i2qd5qcwi with rid 3005658051
2020.08.25 10:27:54 WARN [Jetty-QTP-BOSH-23889]: org.eclipse.jetty.server.HttpChannelState - java.lang.NullPointerException while invoking onTimeout listener org.eclipse.jetty.server.AsyncContextState$WrappedAsyncListener@76c2b64b
2020.08.25 10:27:54 INFO [Jetty-QTP-BOSH-23889]: org.jivesoftware.openfire.http.HttpBindServlet - HTTP SENT(5eq8dbree2): <body xmlns='http://jabber.org/protocol/httpbind' ack='6027381332'></body>
2020.08.25 10:27:54 INFO [Jetty-QTP-BOSH-23889]: org.jivesoftware.openfire.http.HttpSession - Unexpected RID error 6027381332 for session 5eq8dbree2
2020.08.25 10:27:54 WARN [Jetty-QTP-BOSH-23889]: org.eclipse.jetty.server.HttpChannelState - java.io.IOException: Unexpected RID error. while invoking onTimeout listener org.jivesoftware.openfire.http.HttpSession$3@1fba2ac3
2020.08.25 10:27:54 INFO [Jetty-QTP-BOSH-23387]: org.jivesoftware.openfire.http.HttpBindServlet - HTTP RECV(5eq8dbree2): <body xmlns:xmpp="urn:xmpp:xbosh" rid="6027381333" sid="5eq8dbree2"></body>
2020.08.25 10:27:54 INFO [Jetty-QTP-BOSH-23387]: org.jivesoftware.openfire.http.HttpSession - Creating connection for rid: 6027381333 in session 5eq8dbree2
2020.08.25 10:27:54 WARN [Jetty-QTP-BOSH-23387]: org.jivesoftware.openfire.http.HttpSession - Request 6027381333 > 6027381332, ending session 5eq8dbree2
2020.08.25 10:27:54 INFO [Jetty-QTP-BOSH-23387]: org.jivesoftware.openfire.http.HttpBindServlet - HTTP ERR(5eq8dbree2): terminate, item-not-found.
2020.08.25 10:27:54 INFO [Jetty-QTP-BOSH-23387]: org.jivesoftware.openfire.http.HttpBindServlet - HTTP SENT(5eq8dbree2): <body xmlns="http://jabber.org/protocol/httpbind" type="terminate" condition="item-not-found"/>
2020.08.25 10:27:54 INFO [Jetty-QTP-BOSH-23387]: org.jivesoftware.openfire.http.HttpSession - Session 5eq8dbree2 being closed
The 5eq8dbree2 session visible on the log side is important.
And when I constantly tested it, I definitely saw the log below before throwing the terminate package:
2020.08.25 10:17:24 WARN [Jetty-QTP-BOSH-23739]: org.eclipse.jetty.server.HttpChannelState - java.io.IOException: java.util.concurrent.TimeoutException: Idle timeout expired: 30001/30000 ms while invoking onTimeout listener org.jivesoftware.openfire.http.HttpSession$3@3961327f
2020.08.25 10:17:24 WARN [Jetty-QTP-BOSH-23739]: org.eclipse.jetty.util.thread.QueuedThreadPool -
java.lang.IllegalStateException: ABORTED
at org.eclipse.jetty.server.HttpChannelState.sendError(HttpChannelState.java:893) ~[jetty-server-9.4.28.v20200408.jar:9.4.28.v20200408]
at org.eclipse.jetty.server.HttpChannelState.nextAction(HttpChannelState.java:501) ~[jetty-server-9.4.28.v20200408.jar:9.4.28.v20200408]
at org.eclipse.jetty.server.HttpChannelState.unhandle(HttpChannelState.java:420) ~[jetty-server-9.4.28.v20200408.jar:9.4.28.v20200408]
at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:529) ~[jetty-server-9.4.28.v20200408.jar:9.4.28.v20200408]
at org.eclipse.jetty.server.HttpChannel.run(HttpChannel.java:335) ~[jetty-server-9.4.28.v20200408.jar:9.4.28.v20200408]
at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:806) ~[jetty-util-9.4.28.v20200408.jar:9.4.28.v20200408]
at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:938) [jetty-util-9.4.28.v20200408.jar:9.4.28.v20200408]
at java.lang.Thread.run(Thread.java:748) [?:1.8.0_151]
I thought the problem was with the nginx configuration and when I tried it without nginx the result did not change.
In the picture below, there is a terminate package at 106ms.
