[mosquitto-dev] MQTT QoS 2 protocol problem

[Jos Vos <jos@xxxxxx>]

Hi,

I have a (probably timing-related) problem with a (non-Paho/Mosquitto)
MQTT client implementation sending 2 messages quickly after each
other to a Mosquitto broker.  I just want to verify whether this indeed
is a protocol error of the client or not.

This MQTT client is sending messages with QoS 2, my mosquitto_sub client
(irrelevant, but used to see that the broker does not further process
the second message) is subscribed to that topic with QoS 0.

Mosquitto broker trace (the XXXXXXXX-XXXX client is the suspicious client):

SEQUENCE WORKING OK (message id 48 and 49):

1537369517: Received PUBLISH from 2382a99f-fe9c (d0, q2, r0, m48, 'test/topic/a', ... (504 bytes))
1537369517: Sending PUBREC to 2382a99f-fe9c (Mid: 48)
1537369517: Received PUBLISH from 2382a99f-fe9c (d0, q2, r0, m49, 'test/topic/a', ... (360 bytes))
1537369517: Received PUBREL from 2382a99f-fe9c (Mid: 48)
1537369517: Sending PUBCOMP to 2382a99f-fe9c (Mid: 48)
1537369517: Sending PUBLISH to mosqsub/12643-xos069.xo (d0, q0, r0, m0, 'test/topic/a', ... (504 bytes))
1537369517: Sending PUBREC to 2382a99f-fe9c (Mid: 49)
1537369517: Received PUBREL from 2382a99f-fe9c (Mid: 49)
1537369517: Sending PUBCOMP to 2382a99f-fe9c (Mid: 49)
1537369517: Sending PUBLISH to mosqsub/12643-xos069.xo (d0, q0, r0, m0, 'test/topic/a', ... (360 bytes))

SEQUENCE NOT OK (message id 4 and 5):

1537369818: Received PUBLISH from 22c2105a-6926 (d0, q2, r0, m4, 'test/topic/a', ... (1175 bytes))
1537369818: Sending PUBREC to 22c2105a-6926 (Mid: 4)
1537369818: Received PUBLISH from 22c2105a-6926 (d0, q2, r0, m5, 'test/topic/a', ... (360 bytes))
1537369818: Sending PUBREC to 22c2105a-6926 (Mid: 5)
1537369818: Received PUBREL from 22c2105a-6926 (Mid: 4)
1537369818: Sending PUBCOMP to 22c2105a-6926 (Mid: 4)
1537369818: Sending PUBLISH to mosqsub/12643-xos069.xo (d0, q0, r0, m0, 'test/topic/a', ... (1175 bytes))

Doing this many times, it seems to be more or less random whether it
works ok or not.  In the failing sequence, the broker has sent the
PUBREC for the second message before the PUBCOMP of the first one.
The trace shows that the client then does not respond anymore to
this PUBREC for the second message and nothing happens anymore.

Additional note:
An older Mosquitto broker seems to send this PUBREC again after 20
seconds, the 1.5.1 broker does never seem to send the PUBREC again.

Thanks for any help,

-- 
--    Jos Vos <jos@xxxxxx>
--    X/OS Experts in Open Systems BV   |   Office: +31 20 6938364
--    Amsterdam, The Netherlands        |   Mobile: +31 6 26216181