NanoMQ: Socket Multiplexing?

[sumeetkler]

Describe the bug

I recently upgraded to version 0.10.8 of NanoMQ from 0.5.0. I am using the Paho MQTT client embedded client inside my application to connect to the broker. In the connection configuration I am disabling clean sessions and sending all MQTT payloads with QOS level 1.

In this configuration if the client disconnects from the broker and reconnects, the broker will stop forwarding the MQTT payloads for the subscribed topics to the client.

NOTE: from the clients perspective the connection request as well as the subscription requests were all valid upon reconnection.

Expected behavior

With clean session disabled and all payloads published using QOS 1; if a client disconnects and reconnects to the MQTT broker, the broker will forward all payloads for topics subscribed to by the client to the client. This includes any payloads that were sent while the client was disconnected as well as new payloads that were sent after the client reconnected.

Actual Behavior

The client does not receive any payloads from the broker after reconnecting.

To Reproduce

1. Run the NanoMQ broker nanomq start --url nmq-tcp://127.0.0.1:1243
2. Connect a client to the broker with clean sessions disabled
3. Continuously publish messages to a topic that the client is subscribed to
4. If the client disconnects and reconnects the client will no longer receive any data

One note, the exact same configuration on the client side is used between using versions 0.5.0 and 0.10.8. If I revert back to 0.5.0 I do not see this behaviour and after a disconnect+reconnect the client still receives all data from the broker.

** Environment Details **

• NanoMQ versionL 0.10.8
• Operating system and version: 20.04.1-Ubuntu
• Compiler and language used: Clang-10

Client SDK
Paho MQTT Embedded-C Client

Additional context

Terminating NanoMQ and relaunching it resolves the issue and my application is able to receive the payloads.

[JaylinYu]

Hi, Thanks for submitting this detailed issue according to the template.

As I just confirmed on code ver of 0.10.8 and 0.5.0. There is not much difference in terms of msg resending. And I also made a quick test on your scenario, the QoS 1/2 msg is successfully being resent when the client connects with a persistent session.

So I guess you might be considering to set the "qos_duration" in "nanomq.conf" to a minimum value for a faster resending.

qos_duration
The nano qos duration
Value: 1-infinity
qos_duration=2

This value controls the resend/checker timer of each client/pipe, if you set this value to 360s, then you have to wait another 360s to get the resending function started.

If this doesn't resolve your issue, please share your PAHO code/ or test it with an MQTT client tool, so that we can be guaranteed to work on the same page.

[justStokes]

Thanks for this, we are looking into it. Are there any other settings that could possibly cause this issue? For reference, we are launching NanoMQ through another program and don't specify a nanomq.conf file. We will try the following: nanomq start --url nmq-tcp://127.0.0.1:1234 --qos_duration=2

[justStokes]

We are still seeing this issue when setting the qos_duration to 2 . Since we are not launching using a nanomq.conf file, could any of the other defaulted settings be causing the behavior we see?

[JaylinYu]

@justStokes hi, if the nanomq.conf file is not specified, then it will use 10 as a default value; I expect you will also see the QoS msg is being retransmitted after 10 sec. No other config params affects the resend timer

But I suspect this is sth else, I was missing this condition:
Terminating NanoMQ and relaunching it resolves the issue and my application is able to receive the payloads.

perhaps I misunderstand your issue. I was talking about the condition as follows:

client A publish msg to client B (MQTT 3.1.1 with clean session disabled)
Client B disconnect, and Client A kept publishing Qos 1/2 msg to a topic Client B subscribed to.
Client B reconnect with same client ID, not receiving the msgs that Client A published during the period Client B is disconnected

[JaylinYu]

does it means, nanomq failed to forward any msg to any client? or only the reconnected client?

[nickschiffer]

Hello, I've also been able to reproduce this on the latest master (latest commit being: 116439b1aa794774ea5edbfc6a1e2d6d837120ba)

Summary:

While using nanomq, if a client is kicked for exceeding its keepalive time with clean-sessions off, the client will not be aware that it has been kicked by the broker. The client will be able to continue to send messages to the broker but no messages will ever be routed back to it. This behavior is not the case with clean-sessions enabled. The same test can be performed with the mosquitto broker and the client will indeed be able to recover and receive messages.

Steps to reproduce:

Terminal 1: Run broker with default configuration and settings:

> nanomq broker start --url nmq-tcp://127.0.0.1:1234

Terminal 2: Listen on test topic w/ mosquitto_sub

keepalive: 10s, clean-session: off, QOS: 1

> mosquitto_sub -p 1234 -t test/topic -k 10 -v -c -i test_client -q 1

Terminal 3: Publish message

> mosquitto_pub -p 1234 -t test/topic -m "test_message" -q 1

Terminal 2: Message should arrive

> mosquitto_sub -p 1234 -t test/topic -k 10 -v -c -i test_client -q 1
test/topic test_message

Terminal 2: Sleep process until kicked by the broker (ctrl-z)

mosquitto_sub -p 1234 -t test/topic -k 10 -v -c -i test_client -q 1
test/topic test_message
test/topic test_message
^Z
[1]  + 428099 suspended  mosquitto_sub -p 1234 -t test/topic -k 10 -v -c -i test_client -q 1

Terminal 1: Wait for broker to kick Terminal 2 (wait for this message to appear)

Warning: close pipe & kick client due to KeepAlive timeout!

Terminal 2: Wake up Terminal 2 (fg)

> fg
[1]  + 428099 continued  mosquitto_sub -p 1234 -t test/topic -k 10 -v -c -i test_client -q 1

Terminal 3: Transmit another test message

> mosquitto_pub -p 1234 -t test/topic -m "test_message_2" -q 1

Terminal 2: Notice that this message (or any subsequent messages) do not arrive and the client is unaware that it has been kicked.

This is basically irrecoverable at this point.

Terminal 4: Perform the same steps above with the mosquitto broker and observe that after the subscriber is awoken, it is able to receive messages.

> mosquitto -p 1234 -v

[JaylinYu]

Hi bro @nickschiffer, thanks for your detailed report. If the issue experienced by @sumeetkler & @justStokes is the same issue as yours, Then I probably know what is behind this.
For session keeping, NanoMQ doesn't close the TCP socket explicitly, leaving this work to the client, this is the original design for reusing sockets. So in this case, NanoMQ take this client as a cached client still, all msg routed to this client will be stored.
Perhaps this is not what I expect in the beginning. Will fix this soon

BTW, do you guys think preserving sockets is valuable? or just close it like mosquitto does?

[JaylinYu]

Before you guys reply me with your thoughts, I have submitted a PR to make it work as the same way of mosquito.

[sumeetkler]

@JaylinYu

For session keeping, NanoMQ doesn't close the TCP socket explicitly, leaving this work to the client, this is the original design for reusing sockets. So in this case, NanoMQ take this client as a cached client still, all msg routed to this client will be stored.

For this thought, how is the client expected to know to close the socket? When the client is kicked does nanoMQ send some indication to the client itself?

[nickschiffer]

@JaylinYu Thank you for the quick reply and fix. I did some testing and your commit to nng seems to fix the bug we encountered.

❯ mosquitto_sub -p 1234 -t test/topic -k 10 -v -c -i test_client -q 1
test/topic test_message
^Z
[1]  + 18061 suspended  mosquitto_sub -p 1234 -t test/topic -k 10 -v -c -i test_client -q 1
❯ fg
[1]  + 18061 continued  mosquitto_sub -p 1234 -t test/topic -k 10 -v -c -i test_client -q 1
test/topic test_message     <-- sent while subscriber was asleep but before kick
test/topic test_message     <-- rx'd again
test/topic test_message     <-- rx'd again
test/topic test_message_2   <-- sent while subscriber was asleep but after kick
test/topic test_message_3   <-- sent after subscriber was woken up and reconnected

I first tested that once kicked, the client is informed of the disconnect via the closed socket and therefore is able to reconnect and receive new messages.

I also tested the scenario where messages are published while the subscriber is asleep and those are delivered once the subscriber reconnects. I sent messages while the subscriber was asleep before and after the kick. The messages sent before the kick are received a few times, but that is allowed with QOS1.

FWIW I do see some internal warning logs from the broker that may or may not be interesting to you. Otherwise, it seems to behave properly after some quick testing.

Warning: close pipe & kick client due to KeepAlive timeout!
2023-03-17 10:21:51 [17979] WARN  /home/nschiffer/nanomq/nng/src/sp/transport/mqtt/broker_tcp.c:609 tcptran_pipe_recv_cb: nni aio recv error!! Object closed

2023-03-17 10:21:51 [17979] WARN  /home/nschiffer/nanomq/nng/src/sp/transport/mqtt/broker_tcp.c:609 tcptran_pipe_recv_cb: nni aio recv error!! Object closed

2023-03-17 10:21:51 [17979] WARN  /home/nschiffer/nanomq/nng/src/sp/transport/mqtt/broker_tcp.c:857 tcptran_pipe_recv_cb: tcptran_pipe_recv_cb: recv error rv: 139

2023-03-17 10:21:51 [17979] WARN  /home/nschiffer/nanomq/nng/src/sp/transport/mqtt/broker_tcp.c:857 tcptran_pipe_recv_cb: tcptran_pipe_recv_cb: recv error rv: 139

[JaylinYu]

I first tested that once kicked, the client is informed of the disconnect via the closed socket and therefore is able to reconnect and receive new messages.

I also tested the scenario where messages are published while the subscriber is asleep and those are delivered once the subscriber reconnects. I sent messages while the subscriber was asleep before and after the kick. The messages sent before the kick are received a few times, but that is allowed with QOS1.

FWIW I do see some internal warning logs from the broker that may or may not be interesting to you. Otherwise, it seems to behave properly after some quick testing.

Warning: close pipe & kick client due to KeepAlive timeout!
2023-03-17 10:21:51 [17979] WARN  /home/nschiffer/nanomq/nng/src/sp/transport/mqtt/broker_tcp.c:609 tcptran_pipe_recv_cb: nni aio recv error!! Object closed

2023-03-17 10:21:51 [17979] WARN  /home/nschiffer/nanomq/nng/src/sp/transport/mqtt/broker_tcp.c:609 tcptran_pipe_recv_cb: nni aio recv error!! Object closed

2023-03-17 10:21:51 [17979] WARN  /home/nschiffer/nanomq/nng/src/sp/transport/mqtt/broker_tcp.c:857 tcptran_pipe_recv_cb: tcptran_pipe_recv_cb: recv error rv: 139

2023-03-17 10:21:51 [17979] WARN  /home/nschiffer/nanomq/nng/src/sp/transport/mqtt/broker_tcp.c:857 tcptran_pipe_recv_cb: tcptran_pipe_recv_cb: recv error rv: 139

Glad my PR works. Yes, only QoS 1 msg will be cached when session is kept.
Dont mind those logs, it just means client is being disconnected.

[JaylinYu]

For this thought, how is the client expected to know to close the socket? When the client is kicked does nanoMQ send some indication to the client itself?

My original idea was like: never let client knows if it is still using the same socket of pre-existed connection. This is usually happens in real case in poor network situation. Networking is off for a while, both side of TCP is silence and will not send FIN to close the socket. And I think it is better to get over with it once the network back to normal (the disconnect is fired on MQTT layer).
However, you are right, currently NanoMQ expect client to send CONNECT when resumming the session, I would like to make it be like auto-recovering (session gonna be restored when any packet like PINGREQ is received?)

[JaylinYu]

I gonna close this issue and convert it to discussion