eclipse / paho.mqtt.java

Eclipse Paho Java MQTT client library. Paho is an Eclipse IoT project.
https://eclipse.org/paho
Other
2.12k stars 883 forks source link

QoS on wire is always set to 1 #581

Closed swpalmer closed 6 years ago

swpalmer commented 6 years ago

Please fill out the form below before submitting, thank you!

When a message has QoS set to 0 or 2, Wireshark still shows that the QoS going out is set to 1.

jpwsutton commented 6 years ago

Hi @swpalmer,

I've just written a quick test that publishes a message at QoS 2 and can see it being received correctly at the broker as QoS 2:

Test Log:

20180910 110150.461 *************************************************************
20180910 110150.461 * BasicTest.testQoS2Pub
20180910 110150.461 *************************************************************
20180910 110150.488 Assigning callback...
20180910 110150.489 Connecting...(serverURI:tcp://localhost:1883, ClientId:testQoS2Pub
20180910 110150.509 Publishing to...BasicTest-457b3333-e070-41da-8a2f-2273cb434108-topic_02
20180910 110150.517 Disconnecting...
20180910 110150.518 delivery complete
20180910 110150.528 Close...

Broker Log:

DEBUG 20180910 110150 in: (10) Connects(DUP=False, QoS=0, Retain=False, ProtocolName=MQTT, ProtocolVersion=4, CleanSession=True, WillFlag=False, KeepAliveTimer=60, ClientId=testQoS2Pub, usernameFlag=False, passwordFlag=False)
DEBUG 20180910 110150 out: (10) Connacks(DUP=False, QoS=0, Retain=False, Session present=False, ReturnCode=0)
DEBUG 20180910 110150 resending unfinished publications []
DEBUG 20180910 110150 Waiting for request
DEBUG 20180910 110150 in: (10) Publishes(DUP=False, QoS=2, Retain=False, MsgId=1, TopicName='BasicTest-457b3333-e070-41da-8a2f-2273cb434108-topic_02', Payload=b'foo')
DEBUG 20180910 110150 out: (10) Pubrecs(DUP=False, QoS=0, Retain=False, MsgId=1)
DEBUG 20180910 110150 Waiting for request
DEBUG 20180910 110150 in: (10) Pubrels(DUP=False, QoS=1, Retain=False, MsgId=1)
DEBUG 20180910 110150 out: (10) Pubcomps(DUP=False, QoS=0, Retain=False, MsgId=1)
DEBUG 20180910 110150 Waiting for request
DEBUG 20180910 110150 in: (10) Disconnects(DUP=False, QoS=0, Retain=False)

Looking at the output from Wireshark, I can see it identifying the header byte as 0x34 (0011 0100) Breaking it down manually:

Which looks like it agrees with the version of WireShark that I'm running:

Header Flags: 0x34 (Publish Message)
0011 .... = Message Type: Publish Message (3)
.... 0... = DUP Flag: Not set
.... .10. = QoS Level: Exactly once delivery (Assured Delivery) (2)
.... ...0 = Retain: Not set

I've also verified that it works with QoS 0 and QoS 1. If you're still seeing this issue with your code, perhaps you could attach a sample to this issue so that we can help you debug it.

swpalmer commented 6 years ago

Thanks for looking into it.

This is very weird. I have code like this:

System.err.println("*** publishing QoS="+message.getQos()+", msg="+message);
client.publish(topic, message);

message is org.eclipse.paho.client.mqttv3.MqttMessage client is org.eclipse.paho.client.mqttv3.MqttClient

The debug print shows the correct QoS (0 in my case, though I tried 2 as well), but Wireshark always shows this:

Header Flags: 0x3a, Message Type: Publish Message, DUP Flag, QoS Level: At least once delivery 
(Acknowledged deliver)
    0011 .... = Message Type: Publish Message (3)
    .... 1... = DUP Flag: Set
    .... .01. = QoS Level: At least once delivery (Acknowledged deliver) (1)
    .... ...0 = Retain: Not set

When I confirmed with that print that my QoS wasn’t getting through, I filed the bug.

I then tried to reproduce this in an isolated test program and so far it worked there for me as well !! I will try to hunt down what is different in my main program.
(Using dependency: group: 'org.eclipse.paho', name: 'org.eclipse.paho.client.mqttv3', version: ‘1.2.0')

Are you aware of any issues regarding multi-threading?

jpwsutton commented 6 years ago

There shouldn't be any multi-threading issues with the Paho client, we commonly spin up multiple threads when testing it.

Are you by any chance subscribing to the same topic on the same machine? Any incoming messages would also show as publish messages in Wireshark, and the Client will subscribe with QoS 1 by default...

swpalmer commented 6 years ago

I filtered Wireshark messages by destination IP so I don't think that is the case. I checked all MQTT Publish messages and they all have the same QoS when I run my main app. I'm using the same Wireshark capture when I run the test program that works and my main app (with the print) that doesn't.

The main app is publishing every second or more and always hitting the connection lost due to EOF bug (already logged here as issue 474) .. I'm trying to set the QoS to work around it.

swpalmer commented 6 years ago

After getting extremely confusing results from my code, I decided to change the client ID (in the same running instance of the application), and it magically it started doing the right thing. Prior to that I got very strange results - including publishing to the wrong (old) topic. This is after many code changes and re-launches of the process. I printed the topic and message details immediately prior to calling publish on the client object and wireshark always showed old data, except for the msg payload. After I changed the client ID wireshark magically matched the prints.

swpalmer commented 6 years ago

This was caused by a misunderstanding of the persistence mechanism. Sorry for the noise.