[Request] Improve logging and handling of MQTT disconnect

[jeremysherriff]

Describe the solution you'd like

I have had 3 situations when the remote MQTT broker has been offline for a period and unfortunately I have not realised that the LnxLink instances have not reconnected when the broker is back up. To recover from this I have to log into each LnxLink endpoint and restart the service, because I have lost remote control and can't use LnxLink to fix things for me :)

I assume that the MQTT broker connection is reattempted, and that eventually LnxLink gives up. But I see no log entries to help understand what is happening.

I turned on debug logging and shut down my MQTT broker, here's the log output:

Nov 16 19:39:55 stuff systemd[1]: Started LNXlink.
Nov 16 19:39:56 stuff lnxlink[717354]: INFO:lnxlink:LNXlink 2024.11.0, Python 3.10.12
Nov 16 19:39:56 stuff lnxlink[717354]: DEBUG:lnxlink:Path=/usr/local/lib/python3.10/dist-packages
Nov 16 19:39:56 stuff lnxlink[717354]: DEBUG:lnxlink:Found addons: bash, cpu, memory, mounts, restart, required_restart, statistics, sys_updates, update
Nov 16 19:39:56 stuff lnxlink[717354]: INFO:lnxlink:Loaded addons: bash, cpu, memory, mounts, required_restart, restart, statistics, sys_updates, update
Nov 16 19:39:56 stuff lnxlink[717354]: INFO:lnxlink:MQTT connection: Connection Accepted.
Nov 16 19:39:56 stuff lnxlink[717354]: DEBUG:urllib3.connectionpool:Starting new HTTPS connection (1): api.github.com:443
Nov 16 19:39:57 stuff lnxlink[717354]: DEBUG:urllib3.connectionpool:https://api.github.com:443 "GET /repos/bkbilly/lnxlink/releases/latest HTTP/1.1" 200 822
Nov 16 19:54:58 stuff lnxlink[717354]: INFO:lnxlink:Sending statistics data: {"uuid": "c55c416261984ee982cd6a6ac871b920", "version": "2024.11.0"}
Nov 16 19:54:58 stuff lnxlink[717354]: DEBUG:urllib3.connectionpool:Starting new HTTPS connection (1): analyzer.bkbilly.workers.dev:443
Nov 16 19:55:00 stuff lnxlink[717354]: DEBUG:urllib3.connectionpool:https://analyzer.bkbilly.workers.dev:443 "POST /api/lnxlink HTTP/1.1" 200 0
Nov 16 20:12:06 stuff lnxlink[717354]: INFO:lnxlink:MQTT connection: Connection Accepted.

I shut down the MQTT broker at 19:52 and started it back up again at 20:10 (just over 17 minutes with no MQTT broker available). A few things of note:

• no log entry to indicate MQTT broker connection has been lost
• no log entry to indicate reconnection attempts
• when the MQTT broker was started back up, LnxLink reconnected automatically as expected (after around 2 minutes)

How long/how many times is the MQTT connection attempted before giving up?
Can we get some log entries to indicate broker connection attempts, and broker connection loss?

Additional context

As a side note, I would like the log level setting to be in the config file rather than having to edit the service definition.

[bkbilly]

Thank you for taking the time to investigate the issue!

I've also made some tests, but I couldn't get the MQTT to timeout.
I disabled the MQTT Broker for about 2 hours, but my LNXlink devices connected without any issue.

The 2 minutes connection time is the default after some time, so it is normal to connect with a bit of a delay.
The MQTT client used by LNXlink should never give up connecting after a connection drop.

I could add a log message when it loses connection which will make it more clear when this happens, but I don't know what else I could check for the issue you are having.

[jeremysherriff]

Adding a log entry when connection is lost would be helpful as there is already a "Connection Accepted" log message, so a disconnect message would be appropriate.

The MQTT client used by LNXlink should never give up connecting after a connection drop.

Interesting.. that means the behaviour I have experienced is probably related to my environment.
If you are able to add a DEBUG log entry for MQTT connection attempts then I can attempt to diagnose my issue further, and confirm whether the MQTT client is indeed giving up or if something else is happening.

[github-actions]

No activity on this issue recently. Make sure you update to the latest version of LNXlink to check if the issue has been resolved.
If no further activity occurs, the issue will be closed.

[jeremysherriff]

No change since previous comment;

If you are able to add a DEBUG log entry for MQTT connection attempts then I can attempt to diagnose my issue further, and confirm whether the MQTT client is indeed giving up or if something else is happening.

But also, no further occurrences of the issue that led me to log this request.