tellstick-plugin-mqtt-hass icon indicating copy to clipboard operation
tellstick-plugin-mqtt-hass copied to clipboard

Connection to MQTT @ Homeassistant - multiple issues

Open Yngve0 opened this issue 2 years ago • 18 comments

I have a setup with HASS and Mosquitto broker on dedicated VM. I have 2x Tellstick; one located in same subnet as the broker and HASS and on remote which is available over site2site-VPN. Tellstick version: 1.3.2 Tellstick HASS MQTT-plugin: 0.90.4 Home Assistant 2022.8.5

The remote Tellstick to work fine,even if there WAN is not the best with some packetdrop and reconnect.

The local Tellstick is not able to connect to the broker in the same LAN. The logs from the mosquitto-broker reports:

1660885240: New client connected from %%LAN-IP%% as 880D7D93-B5DB-2FDF-743E-95466CB80E8A (p2, c1, k10).
1660885256: Client 880D7D93-B5DB-2FDF-743E-95466CB80E8A has exceeded timeout, disconnecting.
1660885262: New connection from %%LAN-IP%% on port 1883.

I have also tested with a Mosquitto broker on a VPS on internett with the same issue.

When I try to set up the embedded Mosquitto AddOn in HASS with use of username and password it seems like the tellstick-plugin is not sending the credentials?

The logs from the HASS Mosquittto-addon reports for both Tellsticks: error: received null username or password for unpwd check

I am able to connect to the embedded broker when I use the same credential from MQTT Explorer

Anyone?

Yngve0 avatar Aug 18 '22 18:08 Yngve0

I get almost the same, "... client exceeded timeout." Had the "...null username or password..." at first, tried creating a dedicated user for the telldus-integration, errors gone now. Broker works on other publishers

2022-10-28 17:30:06: New connection from 192.168.0.167:48056 on port 1883. 2022-10-28 17:30:06: New client connected from 192.168.0.167:48056 as auto-ECBF060C-50E5-2C7A-CEA8-96B98EB2266E (p2, c1, k10, u'mqtt'). 2022-10-28 17:30:24: New connection from 172.30.32.2:45276 on port 1883. 2022-10-28 17:30:24: Client <unknown> closed its connection. 2022-10-28 17:30:35: Client auto-ECBF060C-50E5-2C7A-CEA8-96B98EB2266E disconnected. 2022-10-28 17:30:35: New connection from 192.168.0.167:40834 on port 1883. 2022-10-28 17:30:35: New client connected from 192.168.0.167:40834 as auto-76500D57-517A-2C64-8E92-727B115322B6 (p2, c1, k10, u'mqtt').

172.30.32.2 is localhost connecting to publish

Telldus plugin is not publishing anything to the broker

hauard avatar Oct 28 '22 16:10 hauard

Same problem here since a while.

Leatherface75 avatar Jan 15 '23 02:01 Leatherface75

Still can't get this working again. Have tried everything restarting everything, remove and readd again etc. I am getting this in Home Assistant. @quazzie Can you take a look on this?

2023-04-21 13:55:52: New client connected from 192.168.0.82:40300 as auto-792C734C-B9F3-2672-C986-41CD1DB1FAAC (p2, c1, k10, u'mqtt'). 2023-04-21 13:56:07: Client auto-792C734C-B9F3-2672-C986-41CD1DB1FAAC has exceeded timeout, disconnecting. error: received null username, clientid or topic, or access is equal or less than 0 for acl check error: received null username, clientid or topic, or access is equal or less than 0 for acl check 2023-04-21 13:56:21: New connection from 192.168.0.82:39389 on port 1883. 2023-04-21 13:56:21: New client connected from 192.168.0.82:39389 as auto-8078300E-5ED1-6D88-DCDD-D67354F00CFF (p2, c1, k10, u'mqtt'). 2023-04-21 13:56:37: Client auto-8078300E-5ED1-6D88-DCDD-D67354F00CFF has exceeded timeout, disconnecting. error: received null username, clientid or topic, or access is equal or less than 0 for acl check error: received null username, clientid or topic, or access is equal or less than 0 for acl check 2023-04-21 13:56:54: New connection from 192.168.0.82:48385 on port 1883. 2023-04-21 13:56:54: New client connected from 192.168.0.82:48385 as auto-BCCFB0A9-5B6E-4616-0100-538994E116C5 (p2, c1, k10, u'mqtt'). 2023-04-21 13:57:13: Client auto-BCCFB0A9-5B6E-4616-0100-538994E116C5 has exceeded timeout, disconnecting. error: received null username, clientid or topic, or access is equal or less than 0 for acl check error: received null username, clientid or topic, or access is equal or less than 0 for acl check 2023-04-21 13:57:23: New connection from 192.168.0.82:47899 on port 1883. 2023-04-21 13:57:24: New client connected from 192.168.0.82:47899 as auto-348D6146-3C68-C548-A163-01C8BD7FD9A2 (p2, c1, k10, u'mqtt'). 2023-04-21 13:57:43: Client auto-348D6146-3C68-C548-A163-01C8BD7FD9A2 has exceeded timeout, disconnecting. error: received null username, clientid or topic, or access is equal or less than 0 for acl check error: received null username, clientid or topic, or access is equal or less than 0 for acl check 2023-04-21 13:57:51: New connection from 192.168.0.82:57104 on port 1883. 2023-04-21 13:57:51: New client connected from 192.168.0.82:57104 as auto-D13C01E3-E861-D758-C5E5-A90E22B07888 (p2, c1, k10, u'mqtt'). 2023-04-21 13:58:07: Client auto-D13C01E3-E861-D758-C5E5-A90E22B07888 has exceeded timeout, disconnecting. error: received null username, clientid or topic, or access is equal or less than 0 for acl check error: received null username, clientid or topic, or access is equal or less than 0 for acl check 2023-04-21 13:58:21: New connection from 192.168.0.82:39677 on port 1883. 2023-04-21 13:58:21: New client connected from 192.168.0.82:39677 as auto-177B60BE-C34E-34FF-3A66-D8C3F9F70D76 (p2, c1, k10, u'mqtt'). 2023-04-21 13:58:37: Client auto-177B60BE-C34E-34FF-3A66-D8C3F9F70D76 has exceeded timeout, disconnecting. error: received null username, clientid or topic, or access is equal or less than 0 for acl check error: received null username, clientid or topic, or access is equal or less than 0 for acl check 2023-04-21 13:58:50: New connection from 192.168.0.82:38122 on port 1883. 2023-04-21 13:58:50: New client connected from 192.168.0.82:38122 as auto-ECC0292A-A244-C0A3-C209-670DD1E823D2 (p2, c1, k10, u'mqtt'). 2023-04-21 13:59:07: Client auto-ECC0292A-A244-C0A3-C209-670DD1E823D2 has exceeded timeout, disconnecting. error: received null username, clientid or topic, or access is equal or less than 0 for acl check error: received null username, clientid or topic, or access is equal or less than 0 for acl check 2023-04-21 13:59:20: New connection from 192.168.0.82:55411 on port 1883. 2023-04-21 13:59:20: New client connected from 192.168.0.82:55411 as auto-A096322F-8D18-50E8-437A-66E3B5C46278 (p2, c1, k10, u'mqtt'). 2023-04-21 13:59:37: Client auto-A096322F-8D18-50E8-437A-66E3B5C46278 has exceeded timeout, disconnecting. error: received null username, clientid or topic, or access is equal or less than 0 for acl check error: received null username, clientid or topic, or access is equal or less than 0 for acl check 2023-04-21 13:59:53: New connection from 192.168.0.82:54856 on port 1883. 2023-04-21 13:59:53: New client connected from 192.168.0.82:54856 as auto-2902F824-1714-D70B-19DC-5AAB40E572F4 (p2, c1, k10, u'mqtt'). 2023-04-21 14:00:13: Client auto-2902F824-1714-D70B-19DC-5AAB40E572F4 has exceeded timeout, disconnecting. error: received null username, clientid or topic, or access is equal or less than 0 for acl check error: received null username, clientid or topic, or access is equal or less than 0 for acl check 2023-04-21 14:00:31: New connection from 192.168.0.82:43341 on port 1883. 2023-04-21 14:00:31: New client connected from 192.168.0.82:43341 as auto-DEA1E8C3-E5DF-B32B-2E90-CF3708634E40 (p2, c1, k10, u'mqtt'). 2023-04-21 14:00:49: Client auto-DEA1E8C3-E5DF-B32B-2E90-CF3708634E40 has exceeded timeout, disconnecting. error: received null username, clientid or topic, or access is equal or less than 0 for acl check error: received null username, clientid or topic, or access is equal or less than 0 for acl check 2023-04-21 14:01:06: New connection from 192.168.0.82:48636 on port 1883. 2023-04-21 14:01:06: New client connected from 192.168.0.82:48636 as auto-17994610-C949-134B-B69D-01705AECA43E (p2, c1, k10, u'mqtt'). 2023-04-21 14:01:25: Client auto-17994610-C949-134B-B69D-01705AECA43E has exceeded timeout, disconnecting. error: received null username, clientid or topic, or access is equal or less than 0 for acl check error: received null username, clientid or topic, or access is equal or less than 0 for acl check 2023-04-21 14:01:26: Saving in-memory database to /data//mosquitto.db. 2023-04-21 14:01:40: New connection from 192.168.0.82:50161 on port 1883. 2023-04-21 14:01:40: New client connected from 192.168.0.82:50161 as auto-9EDAC30B-1717-5B71-3002-CB29071285EA (p2, c1, k10, u'mqtt'). 2023-04-21 14:01:55: Client auto-9EDAC30B-1717-5B71-3002-CB29071285EA has exceeded timeout, disconnecting. error: received null username, clientid or topic, or access is equal or less than 0 for acl check error: received null username, clientid or topic, or access is equal or less than 0 for acl check 2023-04-21 14:02:14: New connection from 192.168.0.82:37506 on port 1883. 2023-04-21 14:02:14: New client connected from 192.168.0.82:37506 as auto-B15F172A-D452-CEB3-04C2-875356285CE5 (p2, c1, k10, u'mqtt'). 2023-04-21 14:02:17: New connection from 172.30.32.1:36732 on port 1883. 2023-04-21 14:02:17: New client connected from 172.30.32.1:36732 as 5NZneF8jbKwsHumBwPpZ0o (p2, c1, k60, u'mqtt'). error: received null username, clientid or topic, or access is equal or less than 0 for acl check error: received null username, clientid or topic, or access is equal or less than 0 for acl check 2023-04-21 14:02:31: Client auto-B15F172A-D452-CEB3-04C2-875356285CE5 has exceeded timeout, disconnecting. error: received null username, clientid or topic, or access is equal or less than 0 for acl check error: received null username, clientid or topic, or access is equal or less than 0 for acl check 2023-04-21 14:02:49: New connection from 192.168.0.82:47191 on port 1883. 2023-04-21 14:02:49: New client connected from 192.168.0.82:47191 as auto-4DCF6048-AC92-ADF9-4FB0-3D893385A0F7 (p2, c1, k10, u'mqtt'). 2023-04-21 14:02:55: New connection from 172.30.32.1:49724 on port 1883. 2023-04-21 14:02:55: New client connected from 172.30.32.1:49724 as 3pas8xHFxLhji2o0IyAoWY (p2, c1, k60, u'mqtt'). 2023-04-21 14:02:55: Client 3pas8xHFxLhji2o0IyAoWY disconnected. 2023-04-21 14:03:07: Client auto-4DCF6048-AC92-ADF9-4FB0-3D893385A0F7 has exceeded timeout, disconnecting. error: received null username, clientid or topic, or access is equal or less than 0 for acl check error: received null username, clientid or topic, or access is equal or less than 0 for acl check 2023-04-21 14:03:21: New connection from 192.168.0.82:60160 on port 1883. 2023-04-21 14:03:21: New client connected from 192.168.0.82:60160 as auto-E5B48A61-43F7-B8B4-0D89-E9CF7FF8BF71 (p2, c1, k10, u'mqtt'). 2023-04-21 14:03:22: Client 51jlP7dzacqc4WgHYWXa3Q closed its connection. error: received null username, clientid or topic, or access is equal or less than 0 for acl check error: received null username, clientid or topic, or access is equal or less than 0 for acl check 2023-04-21 14:03:37: Client auto-E5B48A61-43F7-B8B4-0D89-E9CF7FF8BF71 has exceeded timeout, disconnecting. error: received null username, clientid or topic, or access is equal or less than 0 for acl check error: received null username, clientid or topic, or access is equal or less than 0 for acl check 2023-04-21 14:03:50: New connection from 192.168.0.82:36115 on port 1883. 2023-04-21 14:03:50: New client connected from 192.168.0.82:36115 as auto-ECA8D323-2B1A-5DEB-3B00-BE575D2F6E49 (p2, c1, k10, u'mqtt'). 2023-04-21 14:04:07: Client auto-ECA8D323-2B1A-5DEB-3B00-BE575D2F6E49 has exceeded timeout, disconnecting. error: received null username, clientid or topic, or access is equal or less than 0 for acl check error: received null username, clientid or topic, or access is equal or less than 0 for acl check 2023-04-21 14:04:22: New connection from 192.168.0.82:52805 on port 1883. 2023-04-21 14:04:22: New client connected from 192.168.0.82:52805 as auto-25410B97-A192-D0DB-5D82-3BC2D5BD24ED (p2, c1, k10, u'mqtt'). 2023-04-21 14:04:43: Client auto-25410B97-A192-D0DB-5D82-3BC2D5BD24ED has exceeded timeout, disconnecting. error: received null username, clientid or topic, or access is equal or less than 0 for acl check error: received null username, clientid or topic, or access is equal or less than 0 for acl check 2023-04-21 14:04:53: New connection from 192.168.0.82:55101 on port 1883. 2023-04-21 14:04:53: New client connected from 192.168.0.82:55101 as auto-9D25A369-740A-B7C4-7A9B-BC09568A722A (p2, c1, k10, u'mqtt'). 2023-04-21 14:05:13: Client auto-9D25A369-740A-B7C4-7A9B-BC09568A722A has exceeded timeout, disconnecting. error: received null username, clientid or topic, or access is equal or less than 0 for acl check error: received null username, clientid or topic, or access is equal or less than 0 for acl check

Leatherface75 avatar Apr 06 '23 08:04 Leatherface75

@quazzie maybe this helps. If the MQTT is restarted I get the following exception from paho. After that the plugin never reconnects.

Apr 21 10:39:07 [INF] HaClient: publish state for (10_2_0) homeassistant/sensor/test/10_2_0/state : {"lastUpdated": 1682073546, "value": "67"}
Apr 21 10:39:17 [INF] HaClient: Mqtt disconnected
Apr 21 10:39:23 [ERR] Exception in thread Thread-54:
Traceback (most recent call last):
  File "/usr/lib/python2.7/threading.py", line 801, in __bootstrap_inner
    self.run()
  File "/usr/lib/python2.7/threading.py", line 754, in run
    self.__target(*self.__args, **self.__kwargs)
  File "build/bdist.linux-x86_64/egg/paho/mqtt/client.py", line 3591, in _thread_main
  File "build/bdist.linux-x86_64/egg/paho/mqtt/client.py", line 1779, in loop_forever
  File "build/bdist.linux-x86_64/eg
Apr 21 10:39:25 [INF] HaClient: Sensor value changed (23) type: 256 scale: 2 value: 35.51
Apr 21 10:39:25 [INF] HaClient: publish state for (23_256_2) homeassistant/sensor/test/23_256_2/state : {"lastUpdated": 1682073565, "value": "35.51"}
Apr 21 10:39:35 [INF] HaClient: publish state for (live) homeassistant/binary_sensor/test/live/state : online
Apr 21 10:39:35 [INF] HaClient: publish state for (ipaddr) homeassistant/sensor/test/ipaddr/state : 192.168.22.113
Apr 21 10:39:36 [INF] HaClient: publish state for (cpu) homeassistant/sensor/test/cpu/state : 3.0
Apr 21 10:39:36 [INF] HaClient: publish state for (ram_free) homeassistant/sensor/test/ram_free/state : 29
Apr 21 10:39:36 [INF] HaClient: publish state for (net_recv) homeassistant/sensor/test/net_recv/state : 3
Apr 21 10:39:36 [INF] HaClient: publish state for (net_sent) homeassistant/sensor/test/net_sent/state : 8

tiehfood avatar Apr 21 '23 10:04 tiehfood

For me it's not sending any values at all it it can't connect. When readding everything again i can get values sometimes but old values that never changes.

Leatherface75 avatar Apr 21 '23 12:04 Leatherface75

The initial connection to MQTT should work fine. There is no error message and I also get all the values. The problem starts, if the MQTT server is down or restarts. Then the thread in the plugin which handles the connection crashes with the message above. After that the new connection is never established if the MQTT server comes back

tiehfood avatar Apr 21 '23 13:04 tiehfood

As also stated here #38 the plugin still works with the latests version of HA and a Tellstick ZNet Lite v2 for me. Only the reconnection is broken.

tiehfood avatar Apr 21 '23 13:04 tiehfood

I think this might be the problem:

The method self.client.loop_start() which is needed after a reconnect (the old thread terminates as seen in the logs) is only called in the connect method. This method on the other hand is only called during (via discoverAndConnect) a configuration change not in the on_connect callback of paho (on_connect = self.onMqttConnect)

tiehfood avatar Apr 21 '23 13:04 tiehfood

@quazzie might it an option to put self.client.loop_stop() and self.client.loop_start() in the onMqttDisconnect and onMqttConnect methods instead of the disconnect and connect methods? Or what is the reason in putting them there? I don't have a personal GPG key for the tellstick nor a local dev setup to test this. So maybe you could help us here?

I might have wrote this to the #30 ticket 🙈

tiehfood avatar Apr 21 '23 13:04 tiehfood

The initial connection to MQTT should work fine. There is no error message and I also get all the values. The problem starts, if the MQTT server is down or restarts. Then the thread in the plugin which handles the connection crashes with the message above. After that the new connection is never established if the MQTT server comes back

How do you get it to work? It's not updating anything and that's because of connection issues.

2023-04-21 14:04:53: New connection from 192.168.0.82:55101 on port 1883. 2023-04-21 14:04:53: New client connected from 192.168.0.82:55101 as auto-9D25A369-740A-B7C4-7A9B-BC09568A722A (p2, c1, k10, u'mqtt'). 2023-04-21 14:05:13: Client auto-9D25A369-740A-B7C4-7A9B-BC09568A722A has exceeded timeout, disconnecting. error: received null username, clientid or topic, or access is equal or less than 0 for acl check error: received null username, clientid or topic, or access is equal or less than 0 for acl check

image

Leatherface75 avatar Apr 21 '23 14:04 Leatherface75

Same problem when trying with EMQX

2023-04-21T18:00:01+02:00 [SOCKET] [email protected]:36855 msg: socket_force_closed, reason: keepalive_timeout 2023-04-21T18:00:01+02:00 [PUBLISH] [email protected]:36855 msg: publish_to, topic: znet/binary_sensor/znet/hub/state, payload: offline 2023-04-21T18:00:01+02:00 [SOCKET] [email protected]:36855 msg: emqx_connection_terminated, reason: {shutdown,keepalive_timeout} 2023-04-21T18:00:13+02:00 [MQTT] [email protected]:42506 msg: mqtt_packet_received, packet: CONNECT(Q0, R0, D0, ClientId=, ProtoName=MQTT, ProtoVsn=4, CleanStart=true, KeepAlive=10, Username=mqtt, Password=, Will(Q0, R1, Topic=znet/binary_sensor/znet/hub/state Payload=offline)) 2023-04-21T18:00:13+02:00 [MQTT] [email protected]:42506 msg: mqtt_packet_sent, packet: CONNACK(Q0, R0, D0, AckFlags=0, ReasonCode=0) 2023-04-21T18:00:36+02:00 [SOCKET] [email protected]:42506 msg: socket_force_closed, reason: keepalive_timeout 2023-04-21T18:00:36+02:00 [PUBLISH] [email protected]:42506 msg: publish_to, topic: znet/binary_sensor/znet/hub/state, payload: offline 2023-04-21T18:00:36+02:00 [SOCKET] [email protected]:42506 msg: emqx_connection_terminated, reason: {shutdown,keepalive_timeout} 2023-04-21T18:00:48+02:00 [MQTT] [email protected]:45656 msg: mqtt_packet_received, packet: CONNECT(Q0, R0, D0, ClientId=, ProtoName=MQTT, ProtoVsn=4, CleanStart=true, KeepAlive=10, Username=mqtt, Password=, Will(Q0, R1, Topic=znet/binary_sensor/znet/hub/state Payload=offline)) 2023-04-21T18:00:48+02:00 [MQTT] [email protected]:45656 msg: mqtt_packet_sent, packet: CONNACK(Q0, R0, D0, AckFlags=0, ReasonCode=0) 2023-04-21T18:01:10+02:00 [SOCKET] [email protected]:45656 msg: socket_force_closed, reason: keepalive_timeout 2023-04-21T18:01:10+02:00 [PUBLISH] [email protected]:45656 msg: publish_to, topic: znet/binary_sensor/znet/hub/state, payload: offline 2023-04-21T18:01:10+02:00 [SOCKET] [email protected]:45656 msg: emqx_connection_terminated, reason: {shutdown,keepalive_timeout} 2023-04-21T18:01:22+02:00 [MQTT] [email protected]:59502 msg: mqtt_packet_received, packet: CONNECT(Q0, R0, D0, ClientId=, ProtoName=MQTT, ProtoVsn=4, CleanStart=true, KeepAlive=10, Username=mqtt, Password=******, Will(Q0, R1, Topic=znet/binary_sensor/znet/hub/state Payload=offline)) 2023-04-21T18:01:22+02:00 [MQTT] [email protected]:59502 msg: mqtt_packet_sent, packet: CONNACK(Q0, R0, D0, AckFlags=0, ReasonCode=0)

Leatherface75 avatar Apr 21 '23 16:04 Leatherface75

image

tiehfood avatar Apr 21 '23 21:04 tiehfood

image I tested something, therefore only data from noon on

tiehfood avatar Apr 21 '23 21:04 tiehfood

Basically same settings as i have but i use port 1883 instead and Topic i use znet but that should not have anything with connection timeout to do. With old 0.86 version of this addon it connects and stays connected to EMQX but i am not getting any data from EMQX to Home-Assistant. 0.90.x versions just timeouts to the broker both with EMQX and standard Mosquito broker. The strange thing is i had this working perfectly earlier. My problems started when i updated plugin to latest version and newer Home-Assistant versions.

Leatherface75 avatar Apr 22 '23 09:04 Leatherface75

I got data again from old 0.86 version but only initial and then no updates anymore. The first value i think was with newest version there it disconnects whole time normally i don't get anything at all there. As it is now it seems to only update value after a reboot. Values in Telldus Live updates as it should but that addon doesn't work good either with slow updates.

image

Leatherface75 avatar Apr 22 '23 09:04 Leatherface75

It seems it's sending data to EMQX but EMQX is dropping it and not sending to Home-Assistant except when i restart. How do i fix this?

image

Leatherface75 avatar Apr 23 '23 15:04 Leatherface75

And same thing with orignal MQTT broker so same behaviour in both EMQX and Mosquitto broker. It gets an initial value on restart and the not updating anymore. I am starting to think it's an problem with Home-Assistant but i have no idea how to fix this.

image

Leatherface75 avatar Apr 28 '23 13:04 Leatherface75

I have the same problem with the madoline sensors

flippz avatar Feb 04 '24 19:02 flippz