Tasmotized devices slow response

Murder3D · April 28, 2021, 10:21pm

Hello everyone,

nice to see some interest on this issue, so thank-you to anyone who is providing tips and suggestions.

Here’s my configuration:

The MQTT broker I am using is Mosquitto Broker official add-on for HA
Mosquitto Broker is configured like this:
The MQTT integration (which is required for the new Tasmota integration) is configured like this:

image706×641 24.1 KB

192.168.1.11 is the IP address of HA (and consequently of Mosquitto)
1883 port is the default port used by Mosquitto
username (hassio) and password are exactly the same that are specified in the Mosquitto add-on configuration options (previous screenshot)
All my tasmotized switches have fixed IP addresses manually specified by using “IPAddressX” tasmota command, fo example:

IPAddress1 192.168.1.XXX (tasmotized switch IP address)
IPADdress2 192.168.1.1 (dns)
IPAddress3 255.255.255.0 (subnet mask)
IPAddress4 192.168.1.1 (default gateway)

Router-side, there are DHCP reservations in place for each tasmotized switches’ mac address to avoid conflicts
Router-side, the 2.4GHz Wi-Fi SSID is fully dedicated to IoT / smart home devices, it’s hidden, it is on a fixed band (20Mhz) and on a fixed channel (11). And it has MAC addresses white list in place (more precisely: only the MAC addresses of my tasmotized devices are allowed to connect to that 2.4GHz SSID). All the “auto” options are disabled to ensure the best possible compatibility with IoT / smart home devices and the connection is indeed rock solid (never had a single issue like devices dropping wi-fi or stuff like that).

Today I had time to do some more testings, and I noticed that if I use the MQTT: Publish service in the developer tools to publish a simple “ON” command to a topic, the delay is absent and the corresponding light instantly turn on.

So, I created two scripts (one to turn ON all my lights and the other one to turn them OFF)

This is the payload that I am publishing:

So, if I am not mistaken:

it shouldn’t be a Wi-Fi / network / communication issue since I should experience the same delay also when I use the MQTT: Publish service
it shouldn’t be a Tasmota issue or some kind of power saving feature because of the same reason as above (if It was a Tasmota firmware issue or some power saving thing the delay should be there also when the MQTT: Publish function is used)

So, what could it be?

I am thinking of some kind of issue on how group lights are handled in HA?

If scripts calling the MQTT: Publish function are instantaneous it means that HA and Mosquitto are talking correctly and that the information to tasmotized devices is being sent correctly.

If, instead, toggling a group of lights which should do exactly the same thing is not instantaneous, could this possibly be an indication of some kind of issue with how HA handles lights group and in what way it delivers messages to every entity inside a specified group?

Thank you to anyone who is willing to help!

septillion · April 29, 2021, 9:25am

If a publish to MQTT makes them turn on instantaneous it indeed seems to be in HA itself. Can you also try with a script in which you do multiple mqtt.publish calls instead of using the group topic. Is that also instant? If not, are the time stamps of the messages again off?

PS Please, if you post code, don’t do it as an image…

Murder3D · April 29, 2021, 5:34pm

Hi Timo,

sorry for publishing the image instead of the code!

I created another script, which is an MQTT: Publish with a payload “ON” on every single device.

Here’s the YAML code:

alias: TEST ON
sequence:
  - service: mqtt.publish
    data:
      topic: cmnd/Faretti_Ingresso/POWER
      payload: 'ON'
  - service: mqtt.publish
    data:
      topic: cmnd/Faretti_Divano/POWER
      payload: 'ON'
  - service: mqtt.publish
    data:
      topic: cmnd/Faretti_Corridoio/POWER
      payload: 'ON'
  - service: mqtt.publish
    data:
      topic: cmnd/Cucina/POWER
      payload: 'ON'
  - service: mqtt.publish
    data:
      topic: cmnd/Corridoio/POWER
      payload: 'ON'
  - service: mqtt.publish
    data:
      topic: cmnd/Bagno_Piccolo/POWER
      payload: 'ON'
  - service: mqtt.publish
    data:
      topic: cmnd/Bagno_Grande/POWER
      payload: 'ON'
  - service: mqtt.publish
    data:
      topic: cmnd/Cameretta/POWER
      payload: 'ON'
  - service: mqtt.publish
    data:
      topic: cmnd/Faretti_Letto/POWER
      payload: 'ON'
  - service: mqtt.publish
    data:
      topic: cmnd/Faretti_Armadio/POWER
      payload: 'ON'
  - service: mqtt.publish
    data:
      topic: cmnd/Albero_Di_Natale/POWER
      payload: 'ON'
mode: single

Basically it does the same thing as the previous MQTT: Publish script on the group topic (turn all the lights on) but this time I definitely experienced the same delay / lag that I experience when I toggle a group of lights ON or OFF from my HA dashboard.

As for the timestamp, I had the console open on the webui for every single device and this is the exact time when the meassge is being received by every device and the state is updated:

### Livingroom Spotlight 1 ###
19:24:03.915 MQT: stat/Faretti_Ingresso/RESULT = {"POWER":"ON"}
19:24:03.918 MQT: stat/Faretti_Ingresso/POWER = ON

### Livingroom Spotlight 2 ###
19:24:03.502 MQT: stat/Faretti_Divano/RESULT = {"POWER":"ON"}
19:24:03.505 MQT: stat/Faretti_Divano/POWER = ON

### Livingroom Spotlight 3 ###
19:24:04.556 MQT: stat/Faretti_Corridoio/RESULT = {"POWER":"ON"}
19:24:04.559 MQT: stat/Faretti_Corridoio/POWER = ON

### Kitchen ###
19:24:04.351 MQT: stat/Cucina/RESULT = {"POWER":"ON"}
19:24:04.354 MQT: stat/Cucina/POWER = ON

### Hallway ###
19:24:04.828 MQT: stat/Corridoio/RESULT = {"POWER":"ON"}
19:24:04.832 MQT: stat/Corridoio/POWER = ON

### Guest Bathroom ###
19:24:05.245 MQT: stat/Bagno_Piccolo/RESULT = {"POWER":"ON"}
19:24:05.249 MQT: stat/Bagno_Piccolo/POWER = ON

### Master Bathroom ###
19:24:06.273 MQT: stat/Bagno_Grande/RESULT = {"POWER":"ON"}
19:24:06.276 MQT: stat/Bagno_Grande/POWER = ON

### Guest Bedroom ###
19:24:06.448 MQT: stat/Cameretta/RESULT = {"POWER":"ON"}
19:24:06.452 MQT: stat/Cameretta/POWER = ON

### Master Bedroom Spotlight 1 ###
19:24:07.175 MQT: stat/Faretti_Letto/RESULT = {"POWER":"ON"}
19:24:07.179 MQT: stat/Faretti_Letto/POWER = ON

### Master Bedroom Spotlight 2 ###
19:24:06.840 MQT: stat/Faretti_Armadio/RESULT = {"POWER":"ON"}
19:24:06.843 MQT: stat/Faretti_Armadio/POWER = ON

### Christmas Tree ###
19:24:07.770 MQT: stat/Albero_Di_Natale/RESULT = {"POWER":"ON"}
19:24:07.774 MQT: stat/Albero_Di_Natale/POWER = ON

So… If I publish the “TURN ON” payload to the group topic, everything is instantant. If I publish the “TURN ON” payload to every single device there’s the 4 seconds delay.

What does this mean?

maxym · April 29, 2021, 7:59pm

if you have Mqtt Explorer, check is there are some anomalies when using it. For example unexpected disconnections from mqtt.
Also you can activate debug log to check if there are any issues related with mqtt (like ACK)
It would confirm the issue with add-on v5.1.1

septillion · April 29, 2021, 8:48pm

The MQTT broker or HA is taking long…

If you make it an automation instead of a script you can use the tracer to see if HA takes some time to execute all the actions. For now, the tracer isn’t supported for scripts (yet).

Murder3D · May 1, 2021, 10:12am

Hi all, I’m not at home right now so I cannot verify the delay using tracer with an automation, I’ll do it as soon as I am back home.

I do have some random socket error and disconnection / reconnection for multiple devices in the mosquitto log:

1619811715: New connection from 192.168.1.101 on port 1883.
1619811715: New client connected from 192.168.1.101 as DVES_69C4B9 (p2, c1, k30, u'hassio').
1619811716: New connection from 192.168.1.100 on port 1883.
1619811716: New client connected from 192.168.1.100 as DVES_864893 (p2, c1, k30, u'hassio').
1619811716: New connection from 192.168.1.102 on port 1883.
1619811716: New client connected from 192.168.1.102 as DVES_8597F1 (p2, c1, k30, u'hassio').
1619811717: New connection from 192.168.1.104 on port 1883.
1619811717: New client connected from 192.168.1.104 as DVES_86547B (p2, c1, k30, u'hassio').
1619811717: New connection from 192.168.1.103 on port 1883.
1619811717: New client connected from 192.168.1.103 as DVES_D5422B (p2, c1, k30, u'hassio').
1619811718: New connection from 192.168.1.111 on port 1883.
1619811718: New client connected from 192.168.1.111 as DVES_6F567C (p2, c1, k30, u'hassio').
1619811719: New connection from 192.168.1.110 on port 1883.
1619811719: New client connected from 192.168.1.110 as DVES_376D6F (p2, c1, k30, u'hassio').
1619811753: Socket error on client DVES_864893, disconnecting.
1619811758: New connection from 192.168.1.100 on port 1883.
1619811758: New client connected from 192.168.1.100 as DVES_864893 (p2, c1, k30, u'hassio').
1619811781: Socket error on client DVES_864893, disconnecting.
1619811785: New connection from 192.168.1.100 on port 1883.
1619811785: New client connected from 192.168.1.100 as DVES_864893 (p2, c1, k30, u'hassio').
1619811849: Socket error on client DVES_864893, disconnecting.
1619811852: Socket error on client DVES_69C4B9, disconnecting.
1619811853: New connection from 192.168.1.100 on port 1883.
1619811853: New client connected from 192.168.1.100 as DVES_864893 (p2, c1, k30, u'hassio').
1619811854: Socket error on client DVES_8597F1, disconnecting.
1619811856: Socket error on client DVES_D5422B, disconnecting.
1619811856: New connection from 192.168.1.101 on port 1883.
1619811856: New client connected from 192.168.1.101 as DVES_69C4B9 (p2, c1, k30, u'hassio').
1619811858: New connection from 192.168.1.102 on port 1883.
1619811858: New client connected from 192.168.1.102 as DVES_8597F1 (p2, c1, k30, u'hassio').
1619811859: Socket error on client DVES_86547B, disconnecting.
1619811861: New connection from 192.168.1.103 on port 1883.
1619811861: New client connected from 192.168.1.103 as DVES_D5422B (p2, c1, k30, u'hassio').
1619811862: Socket error on client DVES_55F8AD, disconnecting.
1619811862: New connection from 192.168.1.104 on port 1883.
1619811862: New client connected from 192.168.1.104 as DVES_86547B (p2, c1, k30, u'hassio').
1619811863: Socket error on client DVES_865207, disconnecting.
1619811866: Socket error on client DVES_63A571, disconnecting.
1619811866: New connection from 192.168.1.105 on port 1883.
1619811866: New client connected from 192.168.1.105 as DVES_55F8AD (p2, c1, k30, u'hassio').
1619811866: New connection from 192.168.1.106 on port 1883.
1619811866: New client connected from 192.168.1.106 as DVES_865207 (p2, c1, k30, u'hassio').
1619811867: Socket error on client DVES_F799F7, disconnecting.
1619811870: New connection from 192.168.1.107 on port 1883.
1619811870: New client connected from 192.168.1.107 as DVES_63A571 (p2, c1, k30, u'hassio').
1619811870: Socket error on client DVES_456E2F, disconnecting.
1619811871: New connection from 192.168.1.108 on port 1883.
1619811871: New client connected from 192.168.1.108 as DVES_F799F7 (p2, c1, k30, u'hassio').
1619811873: Socket error on client DVES_376D6F, disconnecting.
1619811874: New connection from 192.168.1.109 on port 1883.
1619811874: New client connected from 192.168.1.109 as DVES_456E2F (p2, c1, k30, u'hassio').
1619811876: Socket error on client DVES_6F567C, disconnecting.
1619811877: New connection from 192.168.1.110 on port 1883.
[21:44:38] INFO: [INFO] found hassio on local database
1619811878: New client connected from 192.168.1.110 as DVES_376D6F (p2, c1, k30, u'hassio').
1619811880: New connection from 192.168.1.111 on port 1883.
1619811880: New client connected from 192.168.1.111 as DVES_6F567C (p2, c1, k30, u'hassio').
1619811904: Socket error on client DVES_865207, disconnecting.
1619811905: Socket error on client DVES_63A571, disconnecting.
1619811905: Socket error on client DVES_55F8AD, disconnecting.
1619811907: Socket error on client DVES_456E2F, disconnecting.
1619811910: Socket error on client DVES_F799F7, disconnecting.
1619811914: New connection from 192.168.1.106 on port 1883.
1619811914: New client connected from 192.168.1.106 as DVES_865207 (p2, c1, k30, u'hassio').
1619811915: New connection from 192.168.1.107 on port 1883.
1619811915: New client connected from 192.168.1.107 as DVES_63A571 (p2, c1, k30, u'hassio').
1619811915: New connection from 192.168.1.105 on port 1883.
1619811915: New client connected from 192.168.1.105 as DVES_55F8AD (p2, c1, k30, u'hassio').
1619811917: New connection from 192.168.1.109 on port 1883.
1619811917: New client connected from 192.168.1.109 as DVES_456E2F (p2, c1, k30, u'hassio').
1619811920: New connection from 192.168.1.108 on port 1883.
1619811920: New client connected from 192.168.1.108 as DVES_F799F7 (p2, c1, k30, u'hassio').
1619812960: Saving in-memory database to /data/mosquitto.db.
1619814761: Saving in-memory database to /data/mosquitto.db.
1619816562: Saving in-memory database to /data/mosquitto.db.
1619818363: Saving in-memory database to /data/mosquitto.db.
1619820164: Saving in-memory database to /data/mosquitto.db.
1619821965: Saving in-memory database to /data/mosquitto.db.
1619823766: Saving in-memory database to /data/mosquitto.db.
1619825567: Saving in-memory database to /data/mosquitto.db.
1619827368: Saving in-memory database to /data/mosquitto.db.
1619829169: Saving in-memory database to /data/mosquitto.db.
1619830970: Saving in-memory database to /data/mosquitto.db.
1619832771: Saving in-memory database to /data/mosquitto.db.
1619834572: Saving in-memory database to /data/mosquitto.db.
1619836373: Saving in-memory database to /data/mosquitto.db.
1619838174: Saving in-memory database to /data/mosquitto.db.
1619839975: Saving in-memory database to /data/mosquitto.db.
1619841776: Saving in-memory database to /data/mosquitto.db.
1619843577: Saving in-memory database to /data/mosquitto.db.
1619845378: Saving in-memory database to /data/mosquitto.db.
1619847179: Saving in-memory database to /data/mosquitto.db.
1619848980: Saving in-memory database to /data/mosquitto.db.
1619850781: Saving in-memory database to /data/mosquitto.db.
1619852582: Saving in-memory database to /data/mosquitto.db.
1619854383: Saving in-memory database to /data/mosquitto.db.
1619856184: Saving in-memory database to /data/mosquitto.db.
1619857985: Saving in-memory database to /data/mosquitto.db.
1619859786: Saving in-memory database to /data/mosquitto.db.
1619861587: Saving in-memory database to /data/mosquitto.db.

I’ve seen the same entries on mosquitto log the other day and taking the client on the 192.168.1.109 ip address for example, I cannot see a wifi signal drop in the tasmota console:

11:14:40.430 MQT: tele/Faretti_Armadio/STATE = {"Time":"2021-05-01T11:14:40","Uptime":"0T13:30:10","UptimeSec":48610,"Heap":27,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":19,"MqttCount":2,"POWER":"OFF","Wifi":{"AP":1,"SSId":"MySSID","BSSId":"xx:xx:xx:xx:xx:xx","Channel":11,"RSSI":84,"Signal":-58,"LinkCount":1,"Downtime":"0T00:00:03"}}
11:14:40.436 MQT: tele/Faretti_Armadio/SENSOR = {"Time":"2021-05-01T11:14:40","Switch1":"OFF"}
11:19:40.422 MQT: tele/Faretti_Armadio/STATE = {"Time":"2021-05-01T11:19:40","Uptime":"0T13:35:10","UptimeSec":48910,"Heap":27,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":19,"MqttCount":2,"POWER":"OFF","Wifi":{"AP":1,"SSId":"MySSID","BSSId":"xx:xx:xx:xx:xx:xx","Channel":11,"RSSI":86,"Signal":-57,"LinkCount":1,"Downtime":"0T00:00:03"}}
11:19:40.429 MQT: tele/Faretti_Armadio/SENSOR = {"Time":"2021-05-01T11:19:40","Switch1":"OFF"}
11:24:40.410 MQT: tele/Faretti_Armadio/STATE = {"Time":"2021-05-01T11:24:40","Uptime":"0T13:40:10","UptimeSec":49210,"Heap":27,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":19,"MqttCount":2,"POWER":"OFF","Wifi":{"AP":1,"SSId":"MySSID","BSSId":"xx:xx:xx:xx:xx:xx","Channel":11,"RSSI":86,"Signal":-57,"LinkCount":1,"Downtime":"0T00:00:03"}}
11:24:40.416 MQT: tele/Faretti_Armadio/SENSOR = {"Time":"2021-05-01T11:24:40","Switch1":"OFF"}
11:29:40.416 MQT: tele/Faretti_Armadio/STATE = {"Time":"2021-05-01T11:29:40","Uptime":"0T13:45:10","UptimeSec":49510,"Heap":27,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":19,"MqttCount":2,"POWER":"OFF","Wifi":{"AP":1,"SSId":"MySSID","BSSId":"xx:xx:xx:xx:xx:xx","Channel":11,"RSSI":86,"Signal":-57,"LinkCount":1,"Downtime":"0T00:00:03"}}
11:29:40.423 MQT: tele/Faretti_Armadio/SENSOR = {"Time":"2021-05-01T11:29:40","Switch1":"OFF"}
11:34:40.426 MQT: tele/Faretti_Armadio/STATE = {"Time":"2021-05-01T11:34:40","Uptime":"0T13:50:10","UptimeSec":49810,"Heap":27,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":19,"MqttCount":2,"POWER":"OFF","Wifi":{"AP":1,"SSId":"MySSID","BSSId":"xx:xx:xx:xx:xx:xx","Channel":11,"RSSI":86,"Signal":-57,"LinkCount":1,"Downtime":"0T00:00:03"}}
11:34:40.432 MQT: tele/Faretti_Armadio/SENSOR = {"Time":"2021-05-01T11:34:40","Switch1":"OFF"}
11:39:40.406 MQT: tele/Faretti_Armadio/STATE = {"Time":"2021-05-01T11:39:40","Uptime":"0T13:55:10","UptimeSec":50110,"Heap":27,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":19,"MqttCount":2,"POWER":"OFF","Wifi":{"AP":1,"SSId":"MySSID","BSSId":"xx:xx:xx:xx:xx:xx","Channel":11,"RSSI":86,"Signal":-57,"LinkCount":1,"Downtime":"0T00:00:03"}}
11:39:40.413 MQT: tele/Faretti_Armadio/SENSOR = {"Time":"2021-05-01T11:39:40","Switch1":"OFF"}
11:44:40.398 MQT: tele/Faretti_Armadio/STATE = {"Time":"2021-05-01T11:44:40","Uptime":"0T14:00:10","UptimeSec":50410,"Heap":27,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":19,"MqttCount":2,"POWER":"OFF","Wifi":{"AP":1,"SSId":"MySSID","BSSId":"xx:xx:xx:xx:xx:xx","Channel":11,"RSSI":86,"Signal":-57,"LinkCount":1,"Downtime":"0T00:00:03"}}
11:44:40.404 MQT: tele/Faretti_Armadio/SENSOR = {"Time":"2021-05-01T11:44:40","Switch1":"OFF"}
11:49:40.396 MQT: tele/Faretti_Armadio/STATE = {"Time":"2021-05-01T11:49:40","Uptime":"0T14:05:10","UptimeSec":50710,"Heap":27,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":19,"MqttCount":2,"POWER":"OFF","Wifi":{"AP":1,"SSId":"MySSID","BSSId":"xx:xx:xx:xx:xx:xx","Channel":11,"RSSI":78,"Signal":-61,"LinkCount":1,"Downtime":"0T00:00:03"}}
11:49:40.402 MQT: tele/Faretti_Armadio/SENSOR = {"Time":"2021-05-01T11:49:40","Switch1":"OFF"}
11:54:40.391 MQT: tele/Faretti_Armadio/STATE = {"Time":"2021-05-01T11:54:40","Uptime":"0T14:10:10","UptimeSec":51010,"Heap":27,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":19,"MqttCount":2,"POWER":"OFF","Wifi":{"AP":1,"SSId":"MySSID","BSSId":"xx:xx:xx:xx:xx:xx","Channel":11,"RSSI":80,"Signal":-60,"LinkCount":1,"Downtime":"0T00:00:03"}}
11:54:40.397 MQT: tele/Faretti_Armadio/SENSOR = {"Time":"2021-05-01T11:54:40","Switch1":"OFF"}
11:59:40.415 MQT: tele/Faretti_Armadio/STATE = {"Time":"2021-05-01T11:59:40","Uptime":"0T14:15:10","UptimeSec":51310,"Heap":27,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":19,"MqttCount":2,"POWER":"OFF","Wifi":{"AP":1,"SSId":"MySSID","BSSId":"xx:xx:xx:xx:xx:xx","Channel":11,"RSSI":82,"Signal":-59,"LinkCount":1,"Downtime":"0T00:00:03"}}
11:59:40.422 MQT: tele/Faretti_Armadio/SENSOR = {"Time":"2021-05-01T11:59:40","Switch1":"OFF"}

As you can see the downtime of this device is just 3 seconds and that’s because I do have rebooted it yesterday.

I cannot understand the timestamps on the mosquitto log to be honest. So I don’t know if the multiple connection and disconnection and socket errors are from yesterday while I was rebooting both my tasmotized devices and my AiMesh setup due to config changes or something else.

So, If I am not mistaken, what those log entries mean is that it seems that for some reason clients are dropping and restoring the connection with mosquitto broker even if they are correctly connected to my wifi?

maxym · May 1, 2021, 12:27pm

If it’s Mosquito v5.1.1 there is no solution other than install v5.1. But I don’t know how to achieve that other way than from backup.
Developers have been informed about this issue several months ago but ignored that, except of rejecting option to rollback the faulty component to last working one. There is no fix published in the meantime but there are more and more impacted users instead. Obviously not enough to take any actions.

Here is github issue. Don’t expect any answer from devs. Maybe you can try discord. But afaik there is no solution so far.

tteck · May 1, 2021, 1:00pm

@Murder3D Out of curiosity, is SetOption13 on or off?

SetOption13	Allow immediate action on single button press
0 = single, multi-press and hold button actions (default)
1 = only single press action for immediate response (i.e., disable multipress detection).

Murder3D · May 2, 2021, 5:20pm

@maxym well that sucks… Didn’t know of the existence of those issues with the latest Mosquitto broker… I assume it’s my fault, I should have searched better. Thanks for the GitHub issue link, I’ve posted there as well and I’ve linked this thread. There’s even a user that did a fresh installation of HA and it’s having problems. I had in mind to wipe everything off and start from scratch as a last resort but I’ll wait for a broker update at this point, which hopefully will solve all those issues

@tteck SetOption13 is enabled (1) on all the devices because I want them to instantly turn on (or off) the light as soon as I single-press the button

Pedro_Trancoso · December 23, 2021, 3:24pm

Thanks!

i was trying to understand why after flash to tasmota my switchs take about “half a second” to turn on/off

"SetOption13 on " solved