mqtt connection issue after upgrade from 5.5.1 to 5.6.2

[imranoftherings]

Describe the Bug

Connection to mosquitto broker getting rejected with Not Authorized message

Steps to Reproduce

Install/Upgrade ring-mqtt to 5.6.2 and connect to mosquitto 2.0.17 with "allow_anonymous false"

Expected Behavior

Connection should be successful

Log Output

2023-09-08T02:50:00.682041146Z s6-rc: info: service s6rc-oneshot-runner: starting
2023-09-08T02:50:00.684162294Z s6-rc: info: service s6rc-oneshot-runner successfully started
2023-09-08T02:50:00.684268576Z s6-rc: info: service fix-attrs: starting
2023-09-08T02:50:00.688049761Z s6-rc: info: service fix-attrs successfully started
2023-09-08T02:50:00.688135729Z s6-rc: info: service legacy-cont-init: starting
2023-09-08T02:50:00.691358898Z cont-init: info: running /etc/cont-init.d/ring-mqtt.sh
2023-09-08T02:50:01.214742571Z -------------------------------------------------------
2023-09-08T02:50:01.214781198Z | Ring-MQTT with Video Streaming                      |
2023-09-08T02:50:01.214788468Z | Docker Edition                                      |
2023-09-08T02:50:01.214806204Z |                                                     |
2023-09-08T02:50:01.214812426Z | For support questions please visit:                 |
2023-09-08T02:50:01.214818045Z | https://github.com/tsightler/ring-mqtt/discussions  |
2023-09-08T02:50:01.214823683Z -------------------------------------------------------
2023-09-08T02:50:01.215424843Z cont-init: info: /etc/cont-init.d/ring-mqtt.sh exited 0
2023-09-08T02:50:01.215750870Z s6-rc: info: service legacy-cont-init successfully started
2023-09-08T02:50:01.215966448Z s6-rc: info: service legacy-services: starting
2023-09-08T02:50:01.220925066Z services-up: info: copying legacy longrun ring-mqtt (no readiness notification)
2023-09-08T02:50:01.277607931Z s6-rc: info: service legacy-services successfully started
2023-09-08T02:50:02.244265532Z -------------------------------------------------------
2023-09-08T02:50:02.247387974Z ring-mqtt.js version: 5.6.2
2023-09-08T02:50:02.286587344Z Node version v18.17.1
2023-09-08T02:50:02.883874314Z NPM version 9.1.2
2023-09-08T02:50:02.888579636Z git version 2.38.5
2023-09-08T02:50:02.888604998Z -------------------------------------------------------
2023-09-08T02:50:02.888612110Z Running ring-mqtt...
2023-09-08T02:50:03.124383836Z 2023-09-08T02:50:03.123Z ring-mqtt Detected runmode: docker
2023-09-08T02:50:03.125009008Z 2023-09-08T02:50:03.124Z ring-mqtt Configuration file: /data/config.json
2023-09-08T02:50:04.547463001Z 2023-09-08T02:50:04.536Z ring-mqtt Reading latest data from state file: /data/ring-state.json
2023-09-08T02:50:04.547498462Z 2023-09-08T02:50:04.540Z ring-mqtt MQTT URL: mqtt://mosquitto.ix-mosquitto.svc.cluster.local:1883
2023-09-08T02:50:04.593178937Z 2023-09-08T02:50:04.584Z ring-mqtt Attempting connection to Ring API using saved refresh token...
2023-09-08T02:50:06.855518676Z 2023-09-08T02:50:06.855Z ring-mqtt Successfully established connection to Ring API using saved token
2023-09-08T02:50:06.856352024Z 2023-09-08T02:50:06.856Z ring-mqtt Received updated refresh token
2023-09-08T02:50:06.856502193Z 2023-09-08T02:50:06.856Z ring-mqtt Saving updated refresh token to state file
2023-09-08T02:50:07.871567932Z 2023-09-08T02:50:07.869Z ring-mqtt Successfully saved updated state file: /data/ring-state.json
2023-09-08T02:50:08.857176161Z 2023-09-08T02:50:08.856Z ring-mqtt Attempting connection to MQTT broker...
2023-09-08T02:50:08.938617150Z 2023-09-08T02:50:08.938Z ring-mqtt Unable to connect to MQTT broker Connection refused: Not authorized
2023-09-08T02:50:09.948513522Z 2023-09-08T02:50:09.948Z ring-mqtt Attempting to reconnect to MQTT broker...
2023-09-08T02:50:09.950672159Z 2023-09-08T02:50:09.950Z ring-mqtt Unable to connect to MQTT broker Connection refused: Not authorized
2023-09-08T02:50:10.969823808Z 2023-09-08T02:50:10.952Z ring-mqtt Attempting to reconnect to MQTT broker...

Screenshots

No response

Config File

{
    "mqtt_url": "mqtt://<user>:<pass>@192.168.1.3:1883",
    "mqtt_options": "",
    "ring_topic": "ring",
    "hass_topic": "homeassistant/status",
    "ring_token": "<TOKEN>",
    "enable_cameras": true,
    "enable_modes": false,
    "enable_panic": true,
    "enable_volume": false,
    "location_ids": [
        ""
    ],
    "disarm_code": ""
}

Install Type

Docker

Version

5.6.2

Operating System

TrueNAS Scale 22.12.3.2

Architecture

x86_64

Machine Details

Physical x86_64

[imranoftherings]

I would also like to add that rolling back to 5.5.1 allows ring-mqtt to connect to mosquitto just fine, without any changes to the config.json

[tsightler]

As there were no changes in ring-mqtt code around MQTT connectivity, and really there haven't been for years (quite literally the mqtt.js code hasn't even been touched in 8 months), it's hard to see what this could be, but, as a theory, there was a major new version of MQTTjs from v4.x to v5.x, which was released back in July. I did bump dependencies to this new major version in the 5.6.x releases, so maybe there's a bug there, but hard to see what it could be as 1000's of users have upgraded already and there are no other reports of this issue.

One thing that is super confusing, the log you sent doesn't match the config, for example in the log it says:

MQTT URL: mqtt://mosquitto.ix-mosquitto.svc.cluster.local:1883

While in the config you have:

"mqtt_url": "mqtt://<user>:<pass>@192.168.1.3:1883"

This seems...strange. The URL in the log should match the URL in the config other than the password would be obscured in the log.

[imranoftherings]

As there were no changes in ring-mqtt code around MQTT connectivity, and really there haven't been for years (quite literally the mqtt.js code hasn't even been touched in 8 months), it's hard to see what this could be, but, as a theory, there was a major new version of MQTTjs from v4.x to v5.x, which was released back in July. I did bump dependencies to this new major version in the 5.6.x releases, so maybe there's a bug there, but hard to see what it could be as 1000's of users have upgraded already and there are no other reports of this issue.

One thing that is super confusing, the log you sent doesn't match the config, for example in the log it says:

MQTT URL: mqtt://mosquitto.ix-mosquitto.svc.cluster.local:1883

While in the config you have:

"mqtt_url": "mqtt://:@192.168.1.3:1883"

This seems...strange. The URL in the log should match the URL in the config other than the password would be obscured in the log.

Yes. I did notice that mqtt.js file wasn't touched in 8months. so that's why this seemed very weird. I thought maybe something else in my environment changed and hence I did a rollback of the container to the older image to check and the older image still works.

Good catch about the URL. See attached logs after rollback. The URL after rollback is as defined in config.json

I do see connection attempts in Mosquitto logs with the 5.6.2 version. So I am not sure whether this is an indication of an issue or a red herring.

s6-rc: info: service s6rc-oneshot-runner: starting
s6-rc: info: service s6rc-oneshot-runner successfully started
s6-rc: info: service fix-attrs: starting
s6-rc: info: service fix-attrs successfully started
s6-rc: info: service legacy-cont-init: starting
cont-init: info: running /etc/cont-init.d/ring-mqtt.sh
-------------------------------------------------------
| Ring-MQTT with Video Streaming                      |
| Docker Edition                                      |
|                                                     |
| For support questions please visit:                 |
| https://github.com/tsightler/ring-mqtt/discussions  |
-------------------------------------------------------
cont-init: info: /etc/cont-init.d/ring-mqtt.sh exited 0
s6-rc: info: service legacy-cont-init successfully started
s6-rc: info: service legacy-services: starting
services-up: info: copying legacy longrun ring-mqtt (no readiness notification)
s6-rc: info: service legacy-services successfully started
-------------------------------------------------------
ring-mqtt.js version: 5.5.1
Node version v18.17.0
NPM version 9.1.2
git version 2.38.5
-------------------------------------------------------
Running ring-mqtt...
2023-09-08T03:07:42.159Z ring-mqtt Detected runmode: docker
2023-09-08T03:07:42.160Z ring-mqtt Configuration file: /data/config.json
2023-09-08T03:07:47.262Z ring-mqtt Reading latest data from state file: /data/ring-state.json
2023-09-08T03:07:47.295Z ring-mqtt MQTT URL: mqtt://<user>:********@192.168.1.3:1883
2023-09-08T03:07:47.305Z ring-mqtt Attempting connection to Ring API using saved refresh token...
2023-09-08T03:07:49.597Z ring-mqtt Successfully established connection to Ring API using saved token
2023-09-08T03:07:49.598Z ring-mqtt Received updated refresh token
2023-09-08T03:07:49.598Z ring-mqtt Saving updated refresh token to state file
2023-09-08T03:07:50.618Z ring-mqtt Successfully saved updated state file: /data/ring-state.json
2023-09-08T03:07:51.597Z ring-mqtt Attempting connection to MQTT broker...
2023-09-08T03:07:51.699Z ring-mqtt MQTT connection established, processing Ring locations...

[imranoftherings]

This may be a problem with TrueCharts, which is what I am using for ring-mqtt installation. I just checked their commits and saw this

truecharts/charts@8ee41c2

Let me dig around a bit more

[imranoftherings]

Yes, TrueCharts changed how the configuration was being passed to the container. I fixed my setup to adapt to the new format and it worked.

Thanks for your help!

[pilot1981]

Hi,
I tried to install this custome component on HA Home Assistant 2023.8.4 using HACS, but I obtained this error:

<Integration tsightler/ring-mqtt> Repository structure for v5.6.2 is not compliant

I see you marked it as bug, but I don't understand why this issue was closed...problem isn't solved...?!

[tsightler]

@pilot1981 The issue was resolved, which is why it was closed, and it was not directly related to any bug in this project anyway (the problem was with a 3rd party which repackages this project). This project has nothing to do with HACS and the instructions for installing this project in Home Assistant do not mention HACS. https://hacs.xyz/docs/faq/addons/.

[pilot1981]

Yes, TrueCharts changed how the configuration was being passed to the container. I fixed my setup to adapt to the new format and it worked.

Thanks for your help!

Please, can you share workaround for it?

regards