MQTT Subscriber gets disconnected frequently when there are large number of MQTT clients connected

Previous Topic Next Topic
 
classic Classic list List threaded Threaded
4 messages Options
Reply | Threaded
Open this post in threaded view
|

MQTT Subscriber gets disconnected frequently when there are large number of MQTT clients connected

Shobhana
This post was updated on .
Background : We use AMQ to exchange MQTT non-persistent messages between our
server components and clients (Android/iOS devices). About 100-200
messages/second get exchanged during peak hours.

This is our MQTT transport connector configuration :
<transportConnector name="mqtt+nio"
uri="mqtt+nio://0.0.0.0:1883?maximumConnections=200000&amp;wireFormat.maxInactivityDuration=180000&amp;wireFormat.maxFrameSize=104857600&amp;jms.useAsyncSend=true&amp;jms.alwaysSessionAsync=false"/>

When there are more than 10000 MQTT connections (and roughly about 30000
topics), the MQTT subscribers get disconnected. Even publish operations time
out (timeout is set to 60 seconds on the publisher and subscriber end).
After a few attempts, connection gets re-established. Once broker enters
this state, disconnects become more frequent and after sometime, the
reconnect also fails forever until the broker is restarted!

Any suggestions on how to investigate why this happens? Since this is a
production environment, I can't debug/profile the broker. I have checked
memory usage and CPU usage .. both are well under control. Thread dumps show
that there are no blocked threads. Log level is set to WARN only. Sometimes
I see following error in log files when this happens :

2017-10-27 13:03:15,599 | WARN  | Failed to send frame MQTTFrame { type: PINGRESP, qos: AT_MOST_ONCE, dup:false } | org.apache.activemq.transport.mqtt.MQTTProtocolConverter | ActiveMQ NIO Worker 9
java.io.IOException: Connection reset by peer
        at sun.nio.ch.FileDispatcherImpl.write0(Native Method)[:1.7.0_151]
        at sun.nio.ch.SocketDispatcher.write(SocketDispatcher.java:47)[:1.7.0_151]
        at sun.nio.ch.IOUtil.writeFromNativeBuffer(IOUtil.java:93)[:1.7.0_151]
        at sun.nio.ch.IOUtil.write(IOUtil.java:65)[:1.7.0_151]
        at sun.nio.ch.SocketChannelImpl.write(SocketChannelImpl.java:492)[:1.7.0_151]
        at org.apache.activemq.transport.nio.NIOOutputStream.write(NIOOutputStream.java:206)[activemq-client-5.14.5.jar:5.14.5]
        at org.apache.activemq.transport.nio.NIOOutputStream.flush(NIOOutputStream.java:132)[activemq-client-5.14.5.jar:5.14.5]
        at java.io.DataOutputStream.flush(DataOutputStream.java:123)[:1.7.0_151]
        at org.apache.activemq.transport.tcp.TcpTransport.oneway(TcpTransport.java:194)[activemq-client-5.14.5.jar:5.14.5]
        at org.apache.activemq.transport.mqtt.MQTTTransportFilter.sendToMQTT(MQTTTransportFilter.java:120)[activemq-mqtt-5.14.5.jar:5.14.5]
        at org.apache.activemq.transport.mqtt.MQTTProtocolConverter.sendToMQTT(MQTTProtocolConverter.java:186)[activemq-mqtt-5.14.5.jar:5.14.5]
        at org.apache.activemq.transport.mqtt.MQTTProtocolConverter.onMQTTCommand(MQTTProtocolConverter.java:200)[activemq-mqtt-5.14.5.jar:5.14.5]
        at org.apache.activemq.transport.mqtt.MQTTTransportFilter.onCommand(MQTTTransportFilter.java:94)[activemq-mqtt-5.14.5.jar:5.14.5]
        at org.apache.activemq.transport.TransportSupport.doConsume(TransportSupport.java:83)[activemq-client-5.14.5.jar:5.14.5]
        at org.apache.activemq.transport.mqtt.MQTTCodec$1.onFrame(MQTTCodec.java:65)[activemq-mqtt-5.14.5.jar:5.14.5]
        at org.apache.activemq.transport.mqtt.MQTTCodec.processCommand(MQTTCodec.java:90)[activemq-mqtt-5.14.5.jar:5.14.5]
        at org.apache.activemq.transport.mqtt.MQTTCodec.access$400(MQTTCodec.java:26)[activemq-mqtt-5.14.5.jar:5.14.5]
        at org.apache.activemq.transport.mqtt.MQTTCodec$3.parse(MQTTCodec.java:166)[activemq-mqtt-5.14.5.jar:5.14.5]
        at org.apache.activemq.transport.mqtt.MQTTCodec$2.parse(MQTTCodec.java:138)[activemq-mqtt-5.14.5.jar:5.14.5]
        at org.apache.activemq.transport.mqtt.MQTTCodec.parse(MQTTCodec.java:76)[activemq-mqtt-5.14.5.jar:5.14.5]
        at org.apache.activemq.transport.mqtt.MQTTNIOTransport.processBuffer(MQTTNIOTransport.java:132)[activemq-mqtt-5.14.5.jar:5.14.5]
        at org.apache.activemq.transport.mqtt.MQTTNIOTransport.serviceRead(MQTTNIOTransport.java:120)[activemq-mqtt-5.14.5.jar:5.14.5]
        at org.apache.activemq.transport.mqtt.MQTTNIOTransport.access$000(MQTTNIOTransport.java:43)[activemq-mqtt-5.14.5.jar:5.14.5]
        at org.apache.activemq.transport.mqtt.MQTTNIOTransport$1.onSelect(MQTTNIOTransport.java:72)[activemq-mqtt-5.14.5.jar:5.14.5]
        at org.apache.activemq.transport.nio.SelectorSelection.onSelect(SelectorSelection.java:98)[activemq-client-5.14.5.jar:5.14.5]
        at org.apache.activemq.transport.nio.SelectorWorker$1.run(SelectorWorker.java:118)[activemq-client-5.14.5.jar:5.14.5]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1152)[:1.7.0_151]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:622)[:1.7.0_151]
        at java.lang.Thread.run(Thread.java:748)[:1.7.0_151]

Any clue about what is happening or how to investigate further?

TIA,
Regards,
Shobhana



--
Sent from: http://activemq.2283324.n4.nabble.com/ActiveMQ-User-f2341805.html
Reply | Threaded
Open this post in threaded view
|

Re: MQTT Subscriber gets disconnected frequently when there are large number of MQTT clients connected

Tim Bain
Is there anything in the broker's logs when this happens? I believe the log
content you quoted was from the client, not the broker, and I wasn't sure
if what you wrote meant that there was nothing in the broker's logs, so I
want to make sure.

Can you reproduce the problem in a non-production environment where the use
of a debugger or a profiler or increasing the logging level of the broker
would be an option? Those techniques are the ones that jump to mind for how
to investigate further, starting with increasing the logging level.

Tim

On Oct 27, 2017 2:19 AM, "Shobhana" <[hidden email]> wrote:

> Background : We use AMQ to exchange MQTT non-persistent messages between
> our
> server components and clients (Android/iOS devices). About 100-200
> messages/second get exchanged during peak hours.
>
> This is our MQTT transport connector configuration :
> <transportConnector name="mqtt+nio"
> uri="mqtt+nio://0.0.0.0:1883?maximumConnections=200000&amp;wireFormat.
> maxInactivityDuration=180000&amp;wireFormat.maxFrameSize=
> 104857600&amp;jms.useAsyncSend=true&amp;jms.alwaysSessionAsync=false"/>
>
> When there are more than 10000 MQTT connections (and roughly about 30000
> topics), the MQTT subscribers get disconnected. Even publish operations
> time
> out (timeout is set to 60 seconds on the publisher and subscriber end).
> After a few attempts, connection gets re-established. Once broker enters
> this state, disconnects become more frequent and after sometime, the
> reconnect also fails forever until the broker is restarted!
>
> Any suggestions on how to investigate why this happens? Since this is a
> production environment, I can't debug/profile the broker. I have checked
> memory usage and CPU usage .. both are well under control. Thread dumps
> show
> that there are no blocked threads. Log level is set to WARN only. Sometimes
> I see following error in log files when this happens :
>
>
>
> Any clue about what is happening or how to investigate further?
>
> TIA,
> Regards,
> Shobhana
>
>
>
> --
> Sent from: http://activemq.2283324.n4.nabble.com/ActiveMQ-User-
> f2341805.html
>
Reply | Threaded
Open this post in threaded view
|

Re: MQTT Subscriber gets disconnected frequently when there are large number of MQTT clients connected

Shobhana
Hi Tim,

The log content quoted in my post was from broker log.

I'll try to reproduce this in a test environment. Meanwhile if you could
think of any common (generic) reasons why broker may becomes unresponsive,
please share.

Thanks,
Shobhana



--
Sent from: http://activemq.2283324.n4.nabble.com/ActiveMQ-User-f2341805.html
Reply | Threaded
Open this post in threaded view
|

Re: MQTT Subscriber gets disconnected frequently when there are large number of MQTT clients connected

Tim Bain
OK. Those log lines indicate that the far side of the connection (the
client) closed the connection when the near end (the broker) wasn't
expecting it. The root cause may be something on the broker's side (for
example, the broker got so busy that it stopped responding to the client,
who reacted by closing the connection), but for now we need to follow the
trail over to the client side and see what its logs say. Can you please
post whatever content is in the client logs shortly before you see the
content you posted from the broker's logs?

Generic reasons why the broker could become unresponsive include not having
enough heap (so the JVM spends most of its time GCing), having so many
connections that it can't service them all quickly enough, disk I/O that's
too slow, or of course maybe there's a bug. Some of those (e.g. spending
too much time GCing) manifest as high CPU usage, and you said CPU usage is
low/normal, but you may still want to double check GC and CPU usage from
JConsole or something similar.

You could also take a thread dump (via jstack or another method, there are
several ways to do this) of your production broker and see if maybe there
are lots of threads blocked waiting for a lock while trying to do real work
(i.e. not the threads in a thread pool that are blocked trying to get a
task from their queue, those are expected and don't indicate a problem).

Tim

On Oct 29, 2017 11:21 PM, "Shobhana" <[hidden email]> wrote:

> Hi Tim,
>
> The log content quoted in my post was from broker log.
>
> I'll try to reproduce this in a test environment. Meanwhile if you could
> think of any common (generic) reasons why broker may becomes unresponsive,
> please share.
>
> Thanks,
> Shobhana
>
>
>
> --
> Sent from: http://activemq.2283324.n4.nabble.com/ActiveMQ-User-
> f2341805.html
>