Strange performance with option MQTT_SUB_OPT_NO_LOCAL.

[maxvalor]

Hello, Does the option "MQTT_SUB_OPT_NO_LOCAL" mean the subscriber would not receive the message from the same object of "struct mosquitto"? Or it means the subscriber would received the message from the same object of "struct mosquitto" directly but not though the broker? I modified the example to make the publisher subscribe its own topic with option "MQTT_SUB_OPT_NO_LOCAL". I tried two ways:

(The "sub start time" is same as the "pub start time".)

1. To subscribe the topic with different object of "struct mosquitto":

[log]
start pub.
finished pub.
pub start time: 1610077360 s 393472 us
pub end   time: 1610077360 s 394470 us
pub delay     : 0.998000 ms
Message with mid 38 has been published.
received.
sub start time: 1610077360 s 393472 us
sub end   time: 1610077360 s 395938 us
sub delay     : 2.466000 ms
start pub.
finished pub.
pub start time: 1610077361 s 394684 us
pub end   time: 1610077361 s 395681 us
pub delay     : 0.997000 ms
Message with mid 39 has been published.
received.
sub start time: 1610077361 s 394684 us
sub end   time: 1610077361 s 397913 us
sub delay     : 3.229000 ms
start pub.
finished pub.
pub start time: 1610077362 s 395895 us
pub end   time: 1610077362 s 396895 us
pub delay     : 1.000000 ms
Message with mid 40 has been published.
received.
sub start time: 1610077362 s 395895 us
sub end   time: 1610077362 s 398335 us
sub delay     : 2.440000 ms

2. To subscribe the topic with the same object of "struct mosquitto":

[log]
start pub.
finished pub.
pub start time: 1610077507 s 705200 us
pub end   time: 1610077507 s 706207 us
pub delay     : 1.007000 ms
Message with mid 26 has been published.
received.
sub start time: 1610077507 s 705200 us
sub end   time: 1610077507 s 707757 us
sub delay     : 2.557000 ms
start pub.
finished pub.
pub start time: 1610077508 s 706419 us
pub end   time: 1610077508 s 707441 us
pub delay     : 1.022000 ms
Message with mid 27 has been published.
received.
sub start time: 1610077508 s 706419 us
sub end   time: 1610077508 s 709761 us
sub delay     : 3.342000 ms
start pub.
finished pub.
pub start time: 1610077509 s 707678 us
pub end   time: 1610077509 s 708695 us
pub delay     : 1.017000 ms
Message with mid 28 has been published.
received.
sub start time: 1610077509 s 707678 us
sub end   time: 1610077509 s 751624 us
sub delay     : 43.946000 ms
start pub.
finished pub.
pub start time: 1610077510 s 708904 us
pub end   time: 1610077510 s 709914 us
pub delay     : 1.010000 ms
Message with mid 29 has been published.
received.
sub start time: 1610077510 s 708904 us
sub end   time: 1610077510 s 755713 us
sub delay     : 46.809000 ms

All the two ways the publisher can receive the message it publishes. But with the second way, the performance seems a little strange to me, it is not stable and is slower than the first way.

The size of data: 1920 1080 4 / 20.

[ralight]

Hi Max, it's not quite clear to me what the different parts of the log mean in terms of what you are doing. My guess is: "pub start" refers to the time when you call mosquitto_publish(), and pub end is when your on_publish callback is triggered? For subscribe when you call mosquitto_subscribe() and when your on_subscribe callback is triggered? It would be helpful if you could provide a small working example source file that demonstrates what you are doing.

Having said that, perhaps the following will help.

The MQTT_SUB_OPT_NO_LOCAL option applies to a specific subscription for a single struct mosquitto only. It only works with MQTT v5 clients. You would use it as follows:

mosquitto_subscribe(mosq, NULL, "my/topic", MQTT_SUB_OPT_NO_LOCAL | qos);

If you use that option, then any messages that mosq sends to the my/topic topic will not be sent back to it.

The ~40ms delay that you are seeing looks to me like Nagle buffering at both ends. To disable this buffering you need to set the TCP no delay option. On the client (before you connect):

mosquitto_int_option(mosq, MOSQ_OPT_TCP_NODELAY, 1);

On the broker the config file option is:

set_tcp_nodelay true

[maxvalor]

Thanks for replying,

"pub start" refers to the time before calling mosquitto_publish() and "pub end" refers to the time after calling mosquitto_publish(). "sub start" is the same as "pub start", it is passed by message though the test topic, while "sub end" refers to the time when on_subscribe is triggered.

In fact, my questions are of two:

1. Why can I still receive message while subscribing the test topic with MQTT_SUB_OPT_NO_LOCAL?

   mosquitto_subscribe_v5(mosq, NULL, "example/temperature", 2, MQTT_SUB_OPT_NO_LOCAL, NULL);
   mosquitto_publish(mosq, NULL, "example/temperature", IMAGE_SIZE / COMPRESSED, payload, 2, true);

2. If the MQTT_SUB_OPT_NO_LOCAL doesn't mean the mosq will not receive its own message, why the 2) is slower than 1)?

   1) code for log 1
   mosq = mosquitto_new("test", true, NULL);
   mosq2 = mosquitto_new(NULL, true, NULL);
   mosquitto_subscribe_v5(mosq, NULL, "example/temperature", 2, MQTT_SUB_OPT_NO_LOCAL, NULL);
   mosquitto_publish(mosq2, NULL, "example/temperature", IMAGE_SIZE / COMPRESSED, payload, 2, true);
   
   2) code for log 2, which performance is slower the 1)
   mosq = mosquitto_new("test", true, NULL);
   mosquitto_subscribe_v5(mosq, NULL, "example/temperature", 2, MQTT_SUB_OPT_NO_LOCAL, NULL);
   mosquitto_publish(mosq, NULL, "example/temperature", IMAGE_SIZE / COMPRESSED, payload, 2, true);

After calling mosquitto_int_option(mosq, MOSQ_OPT_TCP_NODELAY, 1);, the log is same.

[ralight]

Sorry, but without a complete example that I could just compile it's impossible to say what is happening. There are lots of ways you could be doing things, if any of them are different to what I assume then I'll get different behaviour.

One thing to note - using mosquitto_subscribe_v5() doesn't convert your connection to using MQTT v5, it just gives you the ability to set MQTT v5 properties for a subscribe call. You should set your client to use MQTT v5 immediately after creating it with:

mosquitto_int_option(mosq, MOSQ_OPT_PROTOCOL_VERSION, MQTT_PROTOCOL_V5);

[maxvalor]

It works! Thanks a lot!

[maxvalor]

Anyway, I found another problem, I'm not sure if it is a bug or not. If I publish messge with:

mosquitto_publish(mosq, NULL, "example/temperature", IMAGE_SIZE / COMPRESSED, payload, 2, true);

The sample would receive one message with the operations below: =>start the mosquitto service : OK. =>start the sample : log is correct, no messages received. [log-1] =>stop the sample by ctrl-c: OK. =>start the sample : log is incorrect, one message received. [log-2] =>stop the sample by ctrl-c: OK. =>start the sample : log is incorrect, one message received. [log-3] =>stop the sample by ctrl-c: OK. =>restart the mosquitto service: OK. =>start the sample : log is correct, no messages received. [log-4] =>stop the sample by ctrl-c: OK. =>start the sample : log is incorrect, one message received. [log-5]

BUT, if I publish the message with retain = false, the result is always correct:

mosquitto_publish(mosq, NULL, "example/temperature", IMAGE_SIZE / COMPRESSED, payload, 2, false);

---

[log-1]

on_subscribe: 0:granted qos = 2
start pub.
finished pub.
pub start time: 1610437694 s 442814 us
pub end   time: 1610437694 s 443956 us
pub delay     : 1.142000 ms
Message with mid 2 has been published.
start pub.
finished pub.
pub start time: 1610437695 s 444673 us
pub end   time: 1610437695 s 445770 us
pub delay     : 1.097000 ms
Message with mid 3 has been published.
start pub.
finished pub.
pub start time: 1610437696 s 445973 us
pub end   time: 1610437696 s 446644 us
pub delay     : 0.671000 ms
Message with mid 4 has been published.

[log-2]

on_subscribe: 0:granted qos = 2
start pub.
finished pub.
pub start time: 1610437700 s 458161 us
pub end   time: 1610437700 s 459451 us
pub delay     : 1.290000 ms
received.
sub start time: 1610437696 s 445973 us
sub end   time: 1610437700 s 459760 us
sub delay     : 4013.787000 ms
Message with mid 2 has been published.
start pub.
finished pub.
pub start time: 1610437701 s 460199 us
pub end   time: 1610437701 s 461295 us
pub delay     : 1.096000 ms
Message with mid 3 has been published.
start pub.
finished pub.
pub start time: 1610437702 s 461498 us
pub end   time: 1610437702 s 462177 us
pub delay     : 0.679000 ms
Message with mid 4 has been published.

[log-3]

on_connect: Connection Accepted.
on_subscribe: 0:granted qos = 2
start pub.
finished pub.
pub start time: 1610438099 s 63511 us
pub end   time: 1610438099 s 64578 us
pub delay     : 1.067000 ms
received.
sub start time: 1610437702 s 461498 us
sub end   time: 1610438099 s 64628 us
sub delay     : 396603.130000 ms
Message with mid 2 has been published.
start pub.
finished pub.
pub start time: 1610438100 s 65241 us
pub end   time: 1610438100 s 66352 us
pub delay     : 1.111000 ms
Message with mid 3 has been published.
start pub.
finished pub.
pub start time: 1610438101 s 66546 us
pub end   time: 1610438101 s 67261 us
pub delay     : 0.715000 ms
Message with mid 4 has been published.

[log-4]

on_connect: Connection Accepted.
on_subscribe: 0:granted qos = 2
start pub.
finished pub.
pub start time: 1610438517 s 916640 us
pub end   time: 1610438517 s 917791 us
pub delay     : 1.151000 ms
Message with mid 2 has been published.
start pub.
finished pub.
pub start time: 1610438518 s 918519 us
pub end   time: 1610438518 s 919656 us
pub delay     : 1.137000 ms
Message with mid 3 has been published.
start pub.
finished pub.
pub start time: 1610438519 s 919851 us
pub end   time: 1610438519 s 920535 us
pub delay     : 0.684000 ms
Message with mid 4 has been published.

[log-5]

on_connect: Connection Accepted.
on_subscribe: 0:granted qos = 2
start pub.
finished pub.
pub start time: 1610438596 s 287260 us
pub end   time: 1610438596 s 288525 us
pub delay     : 1.265000 ms
received.
sub start time: 1610438519 s 919851 us
sub end   time: 1610438596 s 288617 us
sub delay     : 76368.766000 ms
Message with mid 2 has been published.
start pub.
finished pub.
pub start time: 1610438597 s 289293 us
pub end   time: 1610438597 s 290389 us
pub delay     : 1.096000 ms
Message with mid 3 has been published.
start pub.
finished pub.
pub start time: 1610438598 s 290591 us
pub end   time: 1610438598 s 291294 us
pub delay     : 0.703000 ms
Message with mid 4 has been published.

[ralight]

If you set a message to be retained, whenever a client subscribes it will receive a copy of that retained message, that's the whole point of retained messages. If you don't want that to happen, you can set MQTT_SUB_OPT_SEND_RETAIN_NEVER on your subscription by ORing it with the no-local flag. The other choice is MQTT_SUB_OPT_SEND_RETAIN_NEW which only sends retained messages on the first subscription in a session for a given topic filter.

[maxvalor]

OK, Thanks again.