eclipse-mosquitto / mosquitto

Eclipse Mosquitto - An open source MQTT broker
https://mosquitto.org
Other
9.01k stars 2.39k forks source link

Mosquitto 2.0.12 don't send LWT #2314

Closed MarcHamel closed 3 years ago

MarcHamel commented 3 years ago

With Mosquitto 2.0.12 (with Windows 10 64 bit), whe don't receive the Last Will & Testament (LWT) message when a client disconnect. With the same code for my clients, it works with version 2.0.11.

In verbose mode, with version 2.0.11 & 2.0.12, I see the client has set the LWT message (QoS=2) and when the client disconnects, both versions log the client connection closed but only version 2.0.11 log it sent the LWT.

roger1233 commented 3 years ago

I can confirm on arm64, when I use the 2.0.12 docker image, one of my devices disconnects, and I never see the LWT published. When I revert back to eclipse-mosquitto:2.0.11 it works with no other changes that the version of the docker image

Here is my use-case and my tests: I have a device which I want only to know if it's online or not (track if it has power)

So when the client connects, it sets a LWT to a status topic saying "offline" and then publishes "online" to the same topic. So as long as the device is online, the status shows "online" and when the broker loses connection to it, the LWT will get published.

When that client loses power, the LWT is executed approx 30 seconds later, and "offline" is published on the status topic. This works fine with 2.0.11

When I change 2.0.11 to 2.0.12, then when the client loses power, the LWT is never published, and the status topic still says "online". It's only when the device reconnects (regains power) and tries to reconnect with the same clientID, that the broker disconnects the old client (therefore publishing LWT and putting a "offline" message on the status topic) and right after that, (same second) the devices logs in, and publishes a "online" message.

Daedaluz commented 3 years ago

I cannot replicate this issue. I receive LWT on both 2.0.11 and 2.0.12.

Can you share the logs? maybe the config too?

MarcHamel commented 3 years ago

First I should say the problem may only exists on Windows 10 because a coworker tried it on Linux and is seems to work.

Here is the config file and a part of logs for both versions:

///////////////////////// .conf ///////////////////////// per_listener_settings true listener 1885 allow_anonymous false password_file C:\mosquitto_1885.auth

///////////////////////// 2.0.11 ///////////////////////// 1631889509: mosquitto version 2.0.11 starting ... 1631889509: Opening ipv6 listen socket on port 1885. 1631889509: Opening ipv4 listen socket on port 1885. 1631889509: mosquitto version 2.0.11 running 1631889509: New connection from 127.0.0.1:53134 on port 1885. 1631889509: New client connected from 127.0.0.1:53134 as Client_1885 (p5, c1, k5, u'client1'). ... 1631889518: New connection from 127.0.0.1:53136 on port 1885. 1631889518: New client connected from 127.0.0.1:53136 as E0F641FA-F4C2-48B4-A38D-585A6D409B9D (p5, c1, k5, u'client1'). 1631889518: Will message specified (51 bytes) (r1, q2). 1631889518: t/E0F641FA-F4C2-48B4-A38D-585A6D409B9D/status/gateway ... 1631889521: Client E0F641FA-F4C2-48B4-A38D-585A6D409B9D closed its connection. 1631889521: Sending PUBLISH to Client_1885 (d0, q2, r0, m2, 't/E0F641FA-F4C2-48B4-A38D-585A6D409B9D/status/gateway', ... (51 bytes)) 1631889521: Received PUBREC from Client_1885 (Mid: 2) 1631889521: Sending PUBREL to Client_1885 (m2) 1631889521: Received PUBCOMP from Client_1885 (Mid: 2, RC:0) 1631889526: Received PINGREQ from Client_1885 1631889526: Sending PINGRESP to Client_1885

///////////////////////// 2.0.12 ///////////////////////// 1631889311: mosquitto version 2.0.12 starting ... 1631889311: Opening ipv6 listen socket on port 1885. 1631889311: Opening ipv4 listen socket on port 1885. 1631889311: mosquitto version 2.0.12 running 1631889311: New connection from 127.0.0.1:53134 on port 1885. 1631889311: New client connected from 127.0.0.1:53134 as Client_1885 (p5, c1, k5, u'client1'). ... 1631889327: New connection from 127.0.0.1:57640 on port 1885. 1631889327: New client connected from 127.0.0.1:57640 as E0F641FA-F4C2-48B4-A38D-585A6D409B9D (p5, c1, k5, u'client1'). 1631889327: Will message specified (51 bytes) (r1, q2). 1631889327: t/E0F641FA-F4C2-48B4-A38D-585A6D409B9D/status/gateway ... 1631889331: Client E0F641FA-F4C2-48B4-A38D-585A6D409B9D closed its connection. 1631889333: Received PINGREQ from Client_1885 1631889333: Sending PINGRESP to Client_1885 1631889339: Received PINGREQ from Client_1885 1631889339: Sending PINGRESP to Client_1885 1631889344: Received PINGREQ from Client_1885 1631889344: Sending PINGRESP to Client_1885

Elix-g commented 3 years ago

Dears,

I have to confirm this issue unfortunately. I'm running a Mosquitto broker under Debian Bullseye on a RasPi, binaries from Mosquitto Debian repository (for Buster). Most clients running Tasmota but also other clients that utilize mosquitto_pub are affected. Upon a new client connection to the broker, the LWT is recognized as such but when a client disconnects gracefully or unexpected, the LWT is not being replayed and the retained online message remains. Going back to 2.0.11 resolves this issue.

BR, Elix

ralight commented 3 years ago

Thanks very much for the details, it was helpful. It turns out it is the per_listener_settings true part causing the problem. I have fixed the problem in the fixes branch and added a test to cover that situation. It will be part of the next release.

Elix-g commented 3 years ago

@ralight: Thanks a lot for your time and work and your help with this issue, very appreciated!

roger1233 commented 3 years ago

Sorry for not having responded earlier, so much work to do. But many thanks for your reports and fix! Looking forward returning on the normal upgrade path with this fix! Have a good day.

MarcHamel commented 3 years ago

Thanks everyone