| Re: [mosquitto-dev] in order guarantees when max_inflight_messages = 1 |
Surely this is "as expected" with your retry interval set so short? I presume that your subscriber is taking more than a second on some processing, and so the broker is retrying as directed. Just turn retry down/off/something reasonable and you should be seeing behaviour more in line with your expectations. Sincerely, Karl P Martin Eden <martineden131@xxxxxxxxx> wrote: > Hi all, > > I have the following setup: > > 1 Mosquitto server 1.4.12 using this docker image > https://hub.docker.com/_/eclipse-mosquitto/. It has > max_inflight_messages = 1 and retry_interval = 1. > > 2 x Paho 1.1.1 Java clients (*client_pub* and *client_sub*). > > *client_pub* is publishing 1 msg a second to one topic using > QOS 2 (in flight window 1). > > *client_sub* is subscribing to the same topic using QOS 2 and > persistent session enabled (clean session flag set to false). > It receives the message and forwards it to a processor but only > sends the last QOS 2 ack (PUBCOMP) once the processor finished > processing the result, which happens on a separate thread. > > With this setup I see multiple messages in flight coming from > the broker which also leads to re-ordering of messages. > > This happens in an integration test where I am simply stopping > the consumer app (containing client_sub) and bringing it back > again. > > Basically that pattern of messages that I am observing (9 out > of 10 times) is *client_pub* sends messages 1,2,3,4 and > *client_sub* emits 1,2,3,2,3,4 from it's messageArrived Paho > callback method. This pattern is possible with QOS 1 as it is > stated here > http://docs.oasis-open.org/mqtt/mqtt/v3.1.1/os/mqtt-v3.1.1-os.html#_Toc398718105 > but should not be possible with QOS 2. I am definitely using > QOS 2 for all clients. > > Note that messages 1, 2 and 3 for which we get the unexpected > behaviour are published to the topic during the app downtime > (*client_sub *downtime). > > I am not able to explain why this is happening, as my > understanding is that with QOS 2 and max in flight set to 1 > MQTT guarantees a topic is an ordered topic. See the detailed > Paho client logs and Mosquitto server logs below showing the > not expected messages sent by the server. > > Martin > > *client_sub* log (as printed by the paho messageArrived > callback; timestamp format is HHMMssSSSS): 17-08-10 1946300446 > DEBUG MQTTSource.messageArrived: MqttClient with id > <client_sub> received and passed on this message from the MQTT > broker: id <1>, qos <2>, body <...>, isDuplicate <false>. > 17-08-10 1946320399 DEBUG MQTTSource.messageArrived: MqttClient > with id <client_sub> received and passed on this message from > the MQTT broker: id <2>, qos <2>, body <...>, isDuplicate > <false>. 17-08-10 1946320400 DEBUG MQTTSource.messageArrived: > MqttClient with id <client_sub> received and passed on this > message from the MQTT broker: id <3>, qos <2>, body <...>, > isDuplicate <false>. *NOT EXPECTED vvvv* 17-08-10 1946330545 > DEBUG MQTTSource.messageArrived: MqttClient with id > <client_sub> received and passed on this message from the MQTT > broker: id <2>, qos <2>, body <...>, isDuplicate <false>. > 17-08-10 1946330545 DEBUG MQTTSource.messageArrived: MqttClient > with id <client_sub> received and passed on this message from > the MQTT broker: id <3>, qos <2>, body <...>, isDuplicate > <false>. *NOT EXPECTED ^^^^* 17-08-10 1946340439 DEBUG > MQTTSource.messageArrived: MqttClient with id <client_sub> > received and passed on this message from the MQTT broker: id > <4>, qos <2>, body <...>, isDuplicate <false>. 17-08-10 > 1946360396 DEBUG MQTTSource.messageArrived: MqttClient with id > <client_sub> received and passed on this message from the MQTT > broker: id <5>, qos <2>, body <...>, isDuplicate <false>. > 17-08-10 1946370583 DEBUG MQTTSource.messageArrived: MqttClient > with id <client_sub> received and passed on this message from > the MQTT broker: id <5>, qos <2>, body <...>, isDuplicate > <false>. 17-08-10 1946380394 DEBUG MQTTSource.messageArrived: > MqttClient with id <client_sub> received and passed on this > message from the MQTT broker: id <6>, qos <2>, body <...>, > isDuplicate <false>. 17-08-10 1946390591 DEBUG > MQTTSource.messageArrived: MqttClient with id <client_sub> > received and passed on this message from the MQTT broker: id > <6>, qos <2>, body <...>, isDuplicate <false>. > > *mosquitto* server log: > 1502390751: Sending PUBLISH to client_sub (d0, q2, r0, m1, > 'topic_1', ... (666 bytes)) 1502390751: client_sub 2 topic_1 > 1502390752: Received PUBREC from client_sub (Mid: 1) > 1502390752: Sending PUBREL to client_sub (Mid: 1) 1502390753: > Received PUBCOMP from client_sub (Mid: 1) > > *NOT EXPECTED vvvv* (sent 2 msgs at the same time - so 2 are in > flight at the same time) 1502390753: Sending PUBLISH to > client_sub (d0, q2, r0, m2, 'topic_1', ... (665 bytes)) > 1502390753: Sending PUBLISH to client_sub (d0, q2, r0, m3, > 'topic_1', ... (668 bytes)) 1502390753: Received PUBREC from > client_sub (Mid: 2) 1502390753: Sending PUBREL to client_sub > (Mid: 2) 1502390753: Received PUBREC from client_sub (Mid: 3) > 1502390753: Sending PUBREL to client_sub (Mid: 3) *NOT EXPECTED > ^^^^* > > *NOT EXPECTED vvvv* (PUBRELS are expected but because two msgs > are sent at the same time before we have a PUBREL for msg 2 > after the PUBLISH from msg 3 which is not expected) 1502390755: > Sending PUBREL to client_sub (Mid: 2) 1502390755: Sending > PUBREL to client_sub (Mid: 3) 1502390755: Received PUBCOMP from > client_sub (Mid: 2) 1502390755: Received PUBCOMP from > client_sub (Mid: 3) *NOT EXPECTED ^^^^* > > 1502390755: Sending PUBLISH to client_sub (d0, q2, r0, m4, > 'topic_1', ... (666 bytes)) 1502390755: Received PUBREC from > client_sub (Mid: 4) 1502390755: Sending PUBREL to client_sub > (Mid: 4) 1502390757: Received PUBCOMP from client_sub (Mid: 4) > 1502390757: Sending PUBLISH to client_sub (d0, q2, r0, m5, > 'topic_1', ... (667 bytes)) 1502390757: Received PUBREC from > client_sub (Mid: 5) 1502390757: Sending PUBREL to client_sub > (Mid: 5) 1502390759: Sending PUBREL to client_sub (Mid: 5) > 1502390759: Received PUBCOMP from client_sub (Mid: 5) > 1502390759: Sending PUBLISH to client_sub (d0, q2, r0, m6, > 'topic_1', ... (667 bytes)) 1502390759: Received PUBREC from > client_sub (Mid: 6) 1502390759: Sending PUBREL to client_sub > (Mid: 6) 1502390761: Sending PUBREL to client_sub (Mid: 6) > 1502390761: Received PUBCOMP from client_sub (Mid: 6) > _______________________________________________ mosquitto-dev > mailing list mosquitto-dev@xxxxxxxxxxx To change your delivery > options, retrieve your password, or unsubscribe from this list, > visit https://dev.eclipse.org/mailman/listinfo/mosquitto-dev
Attachment:
signature.html
Description: OpenPGP Digital Signature