Version 1.16.0 overall slow network response

[Imaginous]

What happened

When pressing a zigbee button or sending in MQTT command to a lamp takes about 1.5 seconds. When sending 2 commands directly after one another to turn on 2 lights. They will turn on about 1.5 - 2.0 seconds after each other.

This started since version 1.16.0. Copied back my 1.15.0 version and everything runs smoothly again.

What did you expect to happen

Thate the commands would be almost instantanious.

How to reproduce it (minimal and precise)

Upgrade to version 1.16.0 -> zigbee network becomes slow.
Restore to version 1.15.0 -> zigbee network is fast again.

No devices have been added or changed between the upgrade.

Debug info

Zigbee2MQTT version: 1.16.0
Adapter hardware: Conbee II
Adapter firmware version: 0x26660700
Hardware: Raspberry Pi 3

[Koenkk]

@ChrisHae has anything changed in the Conbee implementation that could cause this?

[Imaginous]

@Koenkk is there a possibility for you to build a 1.16.1 version with the old 1.15.0 Deconz code in it?

I can then try if that runs smoothly and maybe pinpoint the problem a bit better.

[2x4ever]

I can confirm that Zigbee network became much slower in 1.6.X version.
I've used conbeeII adapter and light switch responses are slowed down some time up to 5-10 seconds, while in 1.5 it was around 10s of milliseconds.
I thought it was due to the fact that I had a lot of devices (around 30 actually) and conbeeII adapter works with Baudrate of 38400.
Then i switched the network to ZZH, repaired all devices, but nothing changed.
I noticed that log files became flooded by repeated 'attrubuteReports' from the same device. It looks like it is just multiplied several times. And the more network is running the more reports are multiplied.
https://pastebin.com/Rurtm4LK
Same is for a dimmer action.
This is for example dimmer ON action response:
https://pastebin.com/RkXjYBEP

One ON action leads to network flood with attributeReports.
Being repeated several times (2-3 switch presses) slows down reaction to 5-10 seconds.

[Koenkk]

@Imaginous if running bare metal, you can downgrade the zigbee-herdsman library (which contain the driver code) to the 1.15.0 version when executing in /opt/zigbee2mqtt npm install zigbee-herdsman@0.13.11

@2x4ever does downgrading to 1.15.0 fix your issue?

[srnoth]

Can confirm the same slowdown on 1.6.X with a conbee II adapter. Looking at the MQTT feed, there would be anywhere from 0.5 to several seconds delay between pressing a button, and the corresponding MQTT message showing up.

Return to 1.5.X and the response time immediately returned to normal (MQTT message appears almost immediately as a button is pressed).

Did not have a chance to do any further troubleshooting but I'd be happy to run any diagnostics that would help narrow this down.

[Imaginous]

@Koenkk I have done a couple of test. I run bare metal, so I have downgraded herdsman to 0.13.11 in my 1.16.0 installation.

As I can conclude, the difference must be somewhere in the herdsman code. Since the problem disappears after downgrading the herdsman code.

Note: When the button is pressed I send 2 individual MQTT commands to the 2 gang dimmer module to turn on each lamp.

BTW: is there a json command to set both states at the same time?

Here are the results of different installations.

Hybrid version: 1.16.0 with downgraded herdsman 0.13.11, reacts normal

Single press on, on the Ikea button:

Nov 08 12:00:21 domoticapi1 npm[24022]: Zigbee2MQTT:info 2020-11-08 12:00:21: MQTT publish: topic 'zigbee2mqtt/Alarm_Knop_IKEA', payload '{"action":"on","battery":74,"click":"on","linkquality":5,"update":{"state":"idle"},"update_available":false}' Nov 08 12:00:22 domoticapi1 npm[24022]: Zigbee2MQTT:info 2020-11-08 12:00:22: MQTT publish: topic 'zigbee2mqtt/Slaapkamer1_Verlichting', payload '{"brightness":0,"brightness_l1":254,"brightness_l2":254,"linkquality":14,"state":"OFF","state_l1":"ON","state_l2":"OFF"}' Nov 08 12:00:22 domoticapi1 npm[24022]: Zigbee2MQTT:info 2020-11-08 12:00:22: MQTT publish: topic 'zigbee2mqtt/Slaapkamer1_Verlichting', payload '{"brightness":0,"brightness_l1":254,"brightness_l2":254,"linkquality":14,"state":"OFF","state_l1":"ON","state_l2":"ON"}' Nov 08 12:00:22 domoticapi1 npm[24022]: Zigbee2MQTT:info 2020-11-08 12:00:22: MQTT publish: topic 'zigbee2mqtt/Slaapkamer1_Verlichting', payload '{"brightness":0,"brightness_l1":254,"brightness_l2":254,"linkquality":14,"state":"OFF","state_l1":"ON","state_l2":"ON"}' Nov 08 12:00:22 domoticapi1 npm[24022]: Zigbee2MQTT:info 2020-11-08 12:00:22: MQTT publish: topic 'zigbee2mqtt/Slaapkamer1_Verlichting', payload '{"brightness":0,"brightness_l1":254,"brightness_l2":254,"linkquality":14,"state":"OFF","state_l1":"ON","state_l2":"ON"}' Nov 08 12:00:25 domoticapi1 npm[24022]: Zigbee2MQTT:info 2020-11-08 12:00:25: MQTT publish: topic 'zigbee2mqtt/Slaapkamer1_Verlichting', payload '{"brightness":0,"brightness_l1":254,"brightness_l2":254,"linkquality":14,"state":"OFF","state_l1":"ON","state_l2":"ON"}' Nov 08 12:00:25 domoticapi1 npm[24022]: Zigbee2MQTT:info 2020-11-08 12:00:25: MQTT publish: topic 'zigbee2mqtt/Slaapkamer1_Verlichting', payload '{"brightness":0,"brightness_l1":254,"brightness_l2":254,"linkquality":14,"state":"OFF","state_l1":"ON","state_l2":"ON"}'

Single press off on the Ikea button:

Nov 08 12:01:11 domoticapi1 npm[24022]: Zigbee2MQTT:info 2020-11-08 12:01:11: MQTT publish: topic 'zigbee2mqtt/Alarm_Knop_IKEA', payload '{"action":"off","battery":74,"click":"off","linkquality":5,"update":{"state":"idle"},"update_available":false}' Nov 08 12:01:11 domoticapi1 npm[24022]: Zigbee2MQTT:info 2020-11-08 12:01:11: MQTT publish: topic 'zigbee2mqtt/Slaapkamer1_Verlichting', payload '{"brightness":0,"brightness_l1":254,"brightness_l2":254,"linkquality":14,"state":"OFF","state_l1":"OFF","state_l2":"ON"}' Nov 08 12:01:11 domoticapi1 npm[24022]: Zigbee2MQTT:info 2020-11-08 12:01:11: MQTT publish: topic 'zigbee2mqtt/Slaapkamer1_Verlichting', payload '{"brightness":0,"brightness_l1":254,"brightness_l2":254,"linkquality":14,"state":"OFF","state_l1":"OFF","state_l2":"ON"}' Nov 08 12:01:12 domoticapi1 npm[24022]: Zigbee2MQTT:info 2020-11-08 12:01:12: MQTT publish: topic 'zigbee2mqtt/Slaapkamer1_Verlichting', payload '{"brightness":0,"brightness_l1":254,"brightness_l2":254,"linkquality":14,"state":"OFF","state_l1":"OFF","state_l2":"OFF"}'

Version: 1.16.1, reacts slow

Single press on, on the Ikea button:

Nov 08 12:52:40 domoticapi1 npm[31538]: Zigbee2MQTT:info 2020-11-08 12:52:40: MQTT publish: topic 'zigbee2mqtt/Alarm_Knop_IKEA', payload '{"action":"on","battery":87,"click":"on","linkquality":200,"update":{"state":"idle"},"update_available":false}' Nov 08 12:52:41 domoticapi1 npm[31538]: Zigbee2MQTT:info 2020-11-08 12:52:41: MQTT publish: topic 'zigbee2mqtt/Slaapkamer1_Verlichting', payload '{"brightness":0,"brightness_l1":254,"brightness_l2":254,"linkquality":200,"state":"OFF","state_l1":"ON","state_l2":"OFF"}' Nov 08 12:52:41 domoticapi1 npm[31538]: Zigbee2MQTT:info 2020-11-08 12:52:41: MQTT publish: topic 'zigbee2mqtt/Slaapkamer1_Verlichting', payload '{"brightness":0,"brightness_l1":254,"brightness_l2":254,"linkquality":198,"state":"OFF","state_l1":"ON","state_l2":"ON"}' Nov 08 12:52:42 domoticapi1 npm[31538]: Zigbee2MQTT:info 2020-11-08 12:52:42: MQTT publish: topic 'zigbee2mqtt/Slaapkamer1_Verlichting', payload '{"brightness":0,"brightness_l1":254,"brightness_l2":254,"linkquality":200,"state":"OFF","state_l1":"ON","state_l2":"ON"}' Nov 08 12:52:42 domoticapi1 npm[31538]: Zigbee2MQTT:info 2020-11-08 12:52:42: MQTT publish: topic 'zigbee2mqtt/Slaapkamer1_Verlichting', payload '{"brightness":0,"brightness_l1":254,"brightness_l2":254,"linkquality":200,"state":"OFF","state_l1":"ON","state_l2":"ON"}' Nov 08 12:52:45 domoticapi1 npm[31538]: Zigbee2MQTT:info 2020-11-08 12:52:45: MQTT publish: topic 'zigbee2mqtt/Slaapkamer1_Verlichting', payload '{"brightness":0,"brightness_l1":254,"brightness_l2":254,"linkquality":200,"state":"OFF","state_l1":"ON","state_l2":"ON"}' Nov 08 12:52:45 domoticapi1 npm[31538]: Zigbee2MQTT:info 2020-11-08 12:52:45: MQTT publish: topic 'zigbee2mqtt/Slaapkamer1_Verlichting', payload '{"brightness":0,"brightness_l1":254,"brightness_l2":254,"linkquality":200,"state":"OFF","state_l1":"ON","state_l2":"ON"}' Nov 08 12:52:45 domoticapi1 npm[31538]: Zigbee2MQTT:info 2020-11-08 12:52:45: MQTT publish: topic 'zigbee2mqtt/Slaapkamer1_Verlichting', payload '{"brightness":0,"brightness_l1":254,"brightness_l2":254,"linkquality":200,"state":"OFF","state_l1":"ON","state_l2":"ON"}' Nov 08 12:52:46 domoticapi1 npm[31538]: Zigbee2MQTT:info 2020-11-08 12:52:46: MQTT publish: topic 'zigbee2mqtt/Slaapkamer1_Verlichting', payload '{"brightness":0,"brightness_l1":254,"brightness_l2":254,"linkquality":200,"state":"OFF","state_l1":"ON","state_l2":"ON"}' Nov 08 12:52:46 domoticapi1 npm[31538]: Zigbee2MQTT:info 2020-11-08 12:52:46: MQTT publish: topic 'zigbee2mqtt/Slaapkamer1_Verlichting', payload '{"brightness":0,"brightness_l1":254,"brightness_l2":254,"linkquality":200,"state":"OFF","state_l1":"ON","state_l2":"ON"}' Nov 08 12:52:46 domoticapi1 npm[31538]: Zigbee2MQTT:info 2020-11-08 12:52:46: MQTT publish: topic 'zigbee2mqtt/Slaapkamer1_Verlichting', payload '{"brightness":0,"brightness_l1":254,"brightness_l2":254,"linkquality":200,"state":"OFF","state_l1":"ON","state_l2":"ON"}'

Single press off, on the Ikea button:

'Nov 08 12:53:29 domoticapi1 npm[31538]: Zigbee2MQTT:info 2020-11-08 12:53:29: MQTT publish: topic 'zigbee2mqtt/Alarm_Knop_IKEA', payload '{"action":"off","battery":87,"click":"off","linkquality":200,"update":{"state":"idle"},"update_available":false}'
Nov 08 12:53:30 domoticapi1 npm[31538]: Zigbee2MQTT:info 2020-11-08 12:53:30: MQTT publish: topic 'zigbee2mqtt/Slaapkamer1_Verlichting', payload '{"brightness":0,"brightness_l1":254,"brightness_l2":254,"linkquality":200,"state":"OFF","state_l1":"OFF","state_l2":"ON"}'
Nov 08 12:53:30 domoticapi1 npm[31538]: Zigbee2MQTT:info 2020-11-08 12:53:30: MQTT publish: topic 'zigbee2mqtt/Slaapkamer1_Verlichting', payload '{"brightness":0,"brightness_l1":254,"brightness_l2":254,"linkquality":198,"state":"OFF","state_l1":"OFF","state_l2":"ON"}'
Nov 08 12:53:30 domoticapi1 npm[31538]: Zigbee2MQTT:info 2020-11-08 12:53:30: MQTT publish: topic 'zigbee2mqtt/Slaapkamer1_Verlichting', payload '{"brightness":0,"brightness_l1":254,"brightness_l2":254,"linkquality":200,"state":"OFF","state_l1":"OFF","state_l2":"OFF"}'
Nov 08 12:53:31 domoticapi1 npm[31538]: Zigbee2MQTT:info 2020-11-08 12:53:31: MQTT publish: topic 'zigbee2mqtt/Slaapkamer1_Verlichting', payload '{"brightness":0,"brightness_l1":254,"brightness_l2":254,"linkquality":198,"state":"OFF","state_l1":"OFF","state_l2":"OFF"}''

Version: 1.16.0, reacts slow

Single press on, on the Ikea button:

'Nov 08 12:47:07 domoticapi1 npm[31093]: Zigbee2MQTT:info 2020-11-08 12:47:07: MQTT publish: topic 'zigbee2mqtt/Alarm_Knop_IKEA', payload '{"action":"on","battery":87,"click":"on","linkquality":199,"update":{"state":"idle"},"update_available":false}'
Nov 08 12:47:08 domoticapi1 npm[31093]: Zigbee2MQTT:info 2020-11-08 12:47:08: MQTT publish: topic 'zigbee2mqtt/Slaapkamer1_Verlichting', payload '{"brightness":0,"brightness_l1":254,"brightness_l2":254,"linkquality":198,"state":"OFF","state_l1":"ON","state_l2":"OFF"}'
Nov 08 12:47:08 domoticapi1 npm[31093]: Zigbee2MQTT:info 2020-11-08 12:47:08: MQTT publish: topic 'zigbee2mqtt/Slaapkamer1_Verlichting', payload '{"brightness":0,"brightness_l1":254,"brightness_l2":254,"linkquality":198,"state":"OFF","state_l1":"ON","state_l2":"ON"}'
Nov 08 12:47:08 domoticapi1 npm[31093]: Zigbee2MQTT:info 2020-11-08 12:47:08: MQTT publish: topic 'zigbee2mqtt/Slaapkamer1_Verlichting', payload '{"brightness":0,"brightness_l1":254,"brightness_l2":254,"linkquality":199,"state":"OFF","state_l1":"ON","state_l2":"ON"}'
Nov 08 12:47:09 domoticapi1 npm[31093]: Zigbee2MQTT:info 2020-11-08 12:47:09: MQTT publish: topic 'zigbee2mqtt/Slaapkamer1_Verlichting', payload '{"brightness":0,"brightness_l1":254,"brightness_l2":254,"linkquality":198,"state":"OFF","state_l1":"ON","state_l2":"ON"}'
Nov 08 12:47:12 domoticapi1 npm[31093]: Zigbee2MQTT:info 2020-11-08 12:47:12: MQTT publish: topic 'zigbee2mqtt/Slaapkamer1_Verlichting', payload '{"brightness":0,"brightness_l1":254,"brightness_l2":254,"linkquality":199,"state":"OFF","state_l1":"ON","state_l2":"ON"}'
Nov 08 12:47:12 domoticapi1 npm[31093]: Zigbee2MQTT:info 2020-11-08 12:47:12: MQTT publish: topic 'zigbee2mqtt/Slaapkamer1_Verlichting', payload '{"brightness":0,"brightness_l1":254,"brightness_l2":254,"linkquality":199,"state":"OFF","state_l1":"ON","state_l2":"ON"}'
Nov 08 12:47:12 domoticapi1 npm[31093]: Zigbee2MQTT:info 2020-11-08 12:47:12: MQTT publish: topic 'zigbee2mqtt/Slaapkamer1_Verlichting', payload '{"brightness":0,"brightness_l1":254,"brightness_l2":254,"linkquality":199,"state":"OFF","state_l1":"ON","state_l2":"ON"}'
Nov 08 12:47:12 domoticapi1 npm[31093]: Zigbee2MQTT:info 2020-11-08 12:47:12: MQTT publish: topic 'zigbee2mqtt/Slaapkamer1_Verlichting', payload '{"brightness":0,"brightness_l1":254,"brightness_l2":254,"linkquality":199,"state":"OFF","state_l1":"ON","state_l2":"ON"}'
Nov 08 12:47:13 domoticapi1 npm[31093]: Zigbee2MQTT:info 2020-11-08 12:47:13: MQTT publish: topic 'zigbee2mqtt/Slaapkamer1_Verlichting', payload '{"brightness":0,"brightness_l1":254,"brightness_l2":254,"linkquality":199,"state":"OFF","state_l1":"ON","state_l2":"ON"}'
Nov 08 12:47:13 domoticapi1 npm[31093]: Zigbee2MQTT:info 2020-11-08 12:47:13: MQTT publish: topic 'zigbee2mqtt/Slaapkamer1_Verlichting', payload '{"brightness":0,"brightness_l1":254,"brightness_l2":254,"linkquality":199,"state":"OFF","state_l1":"ON","state_l2":"ON"}''

Single press off, on the Ikea button:

'Nov 08 12:47:54 domoticapi1 npm[31093]: Zigbee2MQTT:info 2020-11-08 12:47:54: MQTT publish: topic 'zigbee2mqtt/Alarm_Knop_IKEA', payload '{"action":"off","battery":87,"click":"off","linkquality":199,"update":{"state":"idle"},"update_available":false}'
Nov 08 12:47:54 domoticapi1 npm[31093]: Zigbee2MQTT:info 2020-11-08 12:47:54: MQTT publish: topic 'zigbee2mqtt/Slaapkamer1_Verlichting', payload '{"brightness":0,"brightness_l1":254,"brightness_l2":254,"linkquality":199,"state":"OFF","state_l1":"OFF","state_l2":"ON"}'
Nov 08 12:47:55 domoticapi1 npm[31093]: Zigbee2MQTT:info 2020-11-08 12:47:55: MQTT publish: topic 'zigbee2mqtt/Slaapkamer1_Verlichting', payload '{"brightness":0,"brightness_l1":254,"brightness_l2":254,"linkquality":198,"state":"OFF","state_l1":"OFF","state_l2":"ON"}'
Nov 08 12:47:55 domoticapi1 npm[31093]: Zigbee2MQTT:info 2020-11-08 12:47:55: MQTT publish: topic 'zigbee2mqtt/Slaapkamer1_Verlichting', payload '{"brightness":0,"brightness_l1":254,"brightness_l2":254,"linkquality":199,"state":"OFF","state_l1":"OFF","state_l2":"OFF"}'
Nov 08 12:47:55 domoticapi1 npm[31093]: Zigbee2MQTT:info 2020-11-08 12:47:55: MQTT publish: topic 'zigbee2mqtt/Slaapkamer1_Verlichting', payload '{"brightness":0,"brightness_l1":254,"brightness_l2":254,"linkquality":198,"state":"OFF","state_l1":"OFF","state_l2":"OFF"}''

Version: 1.15.0, reacts normal

Single press on, on the Ikea button:

'Nov 08 12:40:57 domoticapi1 npm[30463]: Zigbee2MQTT:info 2020-11-08 12:40:57: MQTT publish: topic 'zigbee2mqtt/Alarm_Knop_IKEA', payload '{"action":"on","battery":87,"click":"on","linkquality":199,"update":{"state":"idle"},"update_available":false}'
Nov 08 12:40:58 domoticapi1 npm[30463]: Zigbee2MQTT:info 2020-11-08 12:40:58: MQTT publish: topic 'zigbee2mqtt/Slaapkamer1_Verlichting', payload '{"brightness":0,"brightness_l1":254,"brightness_l2":254,"linkquality":0,"state":"OFF","state_l1":"ON","state_l2":"OFF"}'
Nov 08 12:40:58 domoticapi1 npm[30463]: Zigbee2MQTT:info 2020-11-08 12:40:58: MQTT publish: topic 'zigbee2mqtt/Slaapkamer1_Verlichting', payload '{"brightness":0,"brightness_l1":254,"brightness_l2":254,"linkquality":0,"state":"OFF","state_l1":"ON","state_l2":"ON"}'
Nov 08 12:40:58 domoticapi1 npm[30463]: Zigbee2MQTT:info 2020-11-08 12:40:58: MQTT publish: topic 'zigbee2mqtt/Slaapkamer1_Verlichting', payload '{"brightness":0,"brightness_l1":254,"brightness_l2":254,"linkquality":0,"state":"OFF","state_l1":"ON","state_l2":"ON"}'
Nov 08 12:40:58 domoticapi1 npm[30463]: Zigbee2MQTT:info 2020-11-08 12:40:58: MQTT publish: topic 'zigbee2mqtt/Slaapkamer1_Verlichting', payload '{"brightness":0,"brightness_l1":254,"brightness_l2":254,"linkquality":0,"state":"OFF","state_l1":"ON","state_l2":"ON"}'
Nov 08 12:41:01 domoticapi1 npm[30463]: Zigbee2MQTT:info 2020-11-08 12:41:01: MQTT publish: topic 'zigbee2mqtt/Slaapkamer1_Verlichting', payload '{"brightness":0,"brightness_l1":254,"brightness_l2":254,"linkquality":199,"state":"OFF","state_l1":"ON","state_l2":"ON"}'
Nov 08 12:41:01 domoticapi1 npm[30463]: Zigbee2MQTT:info 2020-11-08 12:41:01: MQTT publish: topic 'zigbee2mqtt/Slaapkamer1_Verlichting', payload '{"brightness":0,"brightness_l1":254,"brightness_l2":254,"linkquality":199,"state":"OFF","state_l1":"ON","state_l2":"ON"}''

Single press off, on the Ikea button:

'Nov 08 12:41:35 domoticapi1 npm[30463]: Zigbee2MQTT:info 2020-11-08 12:41:35: MQTT publish: topic 'zigbee2mqtt/Alarm_Knop_IKEA', payload '{"action":"off","battery":87,"click":"off","linkquality":199,"update":{"state":"idle"},"update_available":false}'
Nov 08 12:41:36 domoticapi1 npm[30463]: Zigbee2MQTT:info 2020-11-08 12:41:36: MQTT publish: topic 'zigbee2mqtt/Slaapkamer1_Verlichting', payload '{"brightness":0,"brightness_l1":254,"brightness_l2":254,"linkquality":199,"state":"OFF","state_l1":"OFF","state_l2":"ON"}'
Nov 08 12:41:36 domoticapi1 npm[30463]: Zigbee2MQTT:info 2020-11-08 12:41:36: MQTT publish: topic 'zigbee2mqtt/Slaapkamer1_Verlichting', payload '{"brightness":0,"brightness_l1":254,"brightness_l2":254,"linkquality":199,"state":"OFF","state_l1":"OFF","state_l2":"ON"}'
Nov 08 12:41:36 domoticapi1 npm[30463]: Zigbee2MQTT:info 2020-11-08 12:41:36: MQTT publish: topic 'zigbee2mqtt/Slaapkamer1_Verlichting', payload '{"brightness":0,"brightness_l1":254,"brightness_l2":254,"linkquality":199,"state":"OFF","state_l1":"OFF","state_l2":"OFF"}''

[Koenkk]

@ChrisHae there seems to be some regression in performance for the Conbee II in herdsman 0.13.11 - 0.13.26, can you investigate this?

[Imaginous]

@Koenkk I have found another strange behavior, I don't think it is directly related.
When I send 2 MQTT commands to turn on each light separately they turn on directly after one another with version 1.15.0.

However when I send:
{ "state_l1": "on", "state_l2": "on" }

So turn both lights on in one command, there is the same 1-1.5 second delay between turning on each lamp as in version 1.16.0, but in this case it also happens in version 1.15.0.

Don't know if it is related, but maybe it is.

Later this week, if I find some time, I will try another Raspberry Pi with a Slaesh CC2652 Stick.
To see if it behaves differently.

[ChrisHae]

I have slowed down data transmit a bit to improve stability when sending many commands at once (Some devices did not respond when sending many requests to fast). I could tweak the times to make it a bit faster again. Delay should be around 1sec. 3 or more seconds would indicate a very busy network I think.

You could also use group commands when controlling many lights at once. This should be much faster.

@Imaginous How do I use that command: { "state_l1": "on", "state_l2": "on" }
to control two lights with one command. I would like to test this. How is the exact syntax and topic?
in z2mqtt doc I only found this: zigbee2mqtt/[FRIENDLY_NAME]/set

[Imaginous]

@ChrisHae would it be possible to make the delay a parameter in the settings of zigbee2mqtt?

As a programmer I think delays are best avoided.
I don't know if there is a way to check if a command has been send?

If you can point me to the source code, I can have a look at it.

I send commands directly after one another and never experienced any problems. On the other hand the zigbee protocol should take care of resends.

The command is send to a single zigbee device with 2 lamps.
I send it to: zigbee2mqtt/[FRIENDLY_NAME]/set
And a json payload of: { "state_l1": "on", "state_l2": "on" }

[Imaginous]

@Koenkk Tonight I have tested V1.16.1 with a Slaesh stick.
Then everything works perfectly normal. So it is clearly the timing adjustment made by @ChrisHae.

I don't want to "bash" anyone, I'm just wanting to help and improve the great work you guys do!

[ChrisHae]

There were Issues of user who sent many requests (about 10 -20) nearly at the same time (#4215) . Some devices did not respond or the messages did not arrived there. I think it is best to use group commands then but never the less I think there should be some time between the messages so that the devices and the coordinator can better handle it.

So did not hard coded a delay between the sending of the messages but instead the coordinator waited until a data request got confirmed before sending the next one. This usualy took about 800ms.

Now I have added a parameter that defines the delay between two requests. I have halved the time and it still works pretty stable. You could test it if the speed is acceptable now. It is in the newest herdsman commit.

It would be also possible to let the user change this parameter in the configuration if @Koenkk would let me add this parameter to the configuration.yaml. Let's call it packet_spacing or send_delay or so.

[srnoth]

From an end user perspective 800ms is a massive delay. E.g. I did not get full buy-in from the wife until I changed "multiple_press_timeout" on the Philips Hue remotes from 250ms to 0.

250ms meant the difference between walking into a room, turning on a light and it almost immediately turning on, vs. pressing and consciously waiting for the light to turn on.

I agree that a user configurable value would make more sense.

[2x4ever]

@Imaginous if running bare metal, you can downgrade the zigbee-herdsman library (which contain the driver code) to the 1.15.0 version when executing in /opt/zigbee2mqtt npm install zigbee-herdsman@0.13.11

@2x4ever does downgrading to 1.15.0 fix your issue?

Sorry for the long answer. Was looking for a way to downgrade the hass.io add-on version.
Switched to bare metal version, downgraded to 1.15.0 and problem disappeared.
So I don't think it is only conbeeii problem, because I switched to zzh stick.
I think that reduced conbee transmit rate is only making it worse (triggers it earler).

[ChrisHae]

@2x4ever I'm speaking about a delay from about 400ms to 1s. Some User reported several seconds. This should be another issue here. Also pressing a button on a zigbee remote should not be affected by this. Remotes are bound and communicate directly to the lights.

[srnoth]

@ChrisHae not all use cases allow remotes to be bound directly to lights. Previous to this change, using a remote to trigger automations in HASS was still pretty snappy, especially with "multiple_press_timeout" set to 0ms.

[Imaginous]

@ChrisHae My Ikea button does not communicate directly to the lights. The button press is caught by my software and then the 2 commands are send to the lights. I would say that the delay with the 1.16.0 version might be 1 second. I did not time it.

How can I clone / add only the latest Herdsman version into the existing version?
Do I just copy the git files to the /opt/zigbee2mqtt folder and re-run npm ci?

[ChrisHae]

@Imaginous I can't say if this also works. I cloned the zigbee-herdsman repository to my raspberry and added the path to /opt/zigbee2mqtt/lib/zigbee.js
const ZigbeeHerdsman = require('/home/pi/zigbee-herdsman');

Or you wait until Koenkk merged this into the newest version of zigbee2mqtt

[Koenkk]

@ChrisHae I don't see any new commits to https://github.com/Koenkk/zigbee-herdsman/commits/master ?

[ChrisHae]

@Koenkk Oh sorry forgot to push. Now it's online.

[Koenkk]

It's in the latest dev now.

@ChrisHae next time you make a change to zigbee-herdsman, you can trigger a new release by going to https://github.com/Koenkk/zigbee-herdsman/actions?query=workflow%3A%22Create+new+release%22 , press "Run workflow" -> press "Run workflow" (you can leave Release type patch as is). This will automatically create a new release and makes a PR to Zigbee2MQTT to update zigbee-herdsman (which I will get a notification for).

[juslex]

I recently left the zzh and returned to conbee 2, however, as I was used to the delay of the zzh, when I returned to conbee 2, I noticed some delay of this in relation to the zzh. What's the reason for that? (Ps. I'm running the herdsman version to 0.13.11 with the conbee.

[Imaginous]

@Koenkk, @ChrisHae

Today I installed the latest dev version of 1.16.1. If I understood correctly this should contain the latest modifications of Chris.

git checkout HEAD -- npm-shrinkwrap.json
git fetch
git checkout dev # Change 'dev' to 'master' to switch back to the release version
git pull
npm ci

This version has still got the slow response with the Conbee II stick. Maybe I did something wrong, please let me know if so.

[juslex]

After my previous post, To fix the home assistant bug, I updated yesterday the dev version, which removed the herdsman version to 0.13.11. And I noticed that the slowness continues. I went back to the herdsman version to 0.13.11.

[srnoth]

As long as there are still delays added (even if they are halved) there will be a noticeable slowness. Even the adjustable 250ms delay on the Hue Dimmer Remote was noticeable.

@ChrisHae @Koenkk do you think we will be able to get a user-customizable option to remove the delays added with this fix? It seems a pity to negatively impact usability for use cases that benefit from response time over reliability, just to fix the use case where someone wants to send commands to many zigbee devices simultaneously. Is there a reason they can't use group messaging in that scenario?

[ChrisHae]

@Imaginous The version 1.16.1 is released 16 days ago, so I think it does not contain the new code.
@juslex how bis is the delay of that you talk? about 1 second, or severall seconds?

I think it would be nice if I could add a parameter to the configuration.yaml. Where the user could chosse a delay between 10 to 1000ms. it could default to 200 if not specified. @Koenkk Is it possible for me to do that? in my driver.ts of deconz adapter there is already a variable for it.

[snippem]

Hi wanted to test the adjustments in the adapterdelay settings and updated the dev coming from a build yesterday.
Now my setup does not start anymore.
see the log:

Zigbee2MQTT:info 2021-02-09 09:34:27: MQTT publish: topic 'homeassistant/sensor/0x842e14fffe3daeed/energy/config', payload '{"availability":[{"topic":"zigbee2mqtt/bridge/state"}],"device":{"identifiers":["zigbee2mqtt_0x842e14fffe3daeed"],"manufacturer":"TuYa","model":"10A UK or 16A EU smart plug (TS0121_plug)","name":"eettafel apparaten","sw_version":"Zigbee2MQTT 1.17.1-dev"},"device_class":"energy","json_attributes_topic":"zigbee2mqtt/eettafel apparaten","name":"eettafel apparaten energy","state_topic":"zigbee2mqtt/eettafel apparaten","unique_id":"0x842e14fffe3daeed_energy_zigbee2mqtt","unit_of_measurement":"kWh","value_template":"{{ value_json.energy }}"}'
Zigbee2MQTT:info 2021-02-09 09:34:27: MQTT publish: topic 'homeassistant/sensor/0x842e14fffe3daeed/power_outage_memory/config', payload '{"availability":[{"topic":"zigbee2mqtt/bridge/state"}],"device":{"identifiers":["zigbee2mqtt_0x842e14fffe3daeed"],"manufacturer":"TuYa","model":"10A UK or 16A EU smart plug (TS0121_plug)","name":"eettafel apparaten","sw_version":"Zigbee2MQTT 1.17.1-dev"},"json_attributes_topic":"zigbee2mqtt/eettafel apparaten","name":"eettafel apparaten power outage memory","state_topic":"zigbee2mqtt/eettafel apparaten","unique_id":"0x842e14fffe3daeed_power_outage_memory_zigbee2mqtt","value_template":"{{ value_json.power_outage_memory }}"}'
Zigbee2MQTT:info 2021-02-09 09:34:27: MQTT publish: topic 'homeassistant/sensor/0x842e14fffe3daeed/linkquality/config', payload '{"availability":[{"topic":"zigbee2mqtt/bridge/state"}],"device":{"identifiers":["zigbee2mqtt_0x842e14fffe3daeed"],"manufacturer":"TuYa","model":"10A UK or 16A EU smart plug (TS0121_plug)","name":"eettafel apparaten","sw_version":"Zigbee2MQTT 1.17.1-dev"},"icon":"mdi:signal","json_attributes_topic":"zigbee2mqtt/eettafel apparaten","name":"eettafel apparaten linkquality","state_topic":"zigbee2mqtt/eettafel apparaten","unique_id":"0x842e14fffe3daeed_linkquality_zigbee2mqtt","unit_of_measurement":"lqi","value_template":"{{ value_json.linkquality }}"}'
Zigbee2MQTT:error 2021-02-09 09:35:21: Failed to disable reporting for '0x00158d0004147a7e' - Error: Unbind 0x00158d0004147a7e/1 genOnOff from '0x00212effff05221b/1' failed (waiting for response TIMEOUT)
at DeconzAdapter. (/app/node_modules/zigbee-herdsman/dist/adapter/deconz/adapter/deconzAdapter.js:755:23)
at Generator.throw ()
at rejected (/app/node_modules/zigbee-herdsman/dist/adapter/deconz/adapter/deconzAdapter.js:25:65)
at runMicrotasks ()
at runNextTicks (internal/process/task_queues.js:58:5)
at processTimers (internal/timers.js:494:9)
Zigbee2MQTT:error 2021-02-09 09:35:39: Publish 'set' 'brightness' to 'keuken werkblad' failed: 'Error: Command 0x90fd9ffffe17ea2a/1 genLevelCtrl.moveToLevelWithOnOff({"level":26,"transtime":20}, {"timeout":10000,"disableResponse":false,"disableRecovery":false,"disableDefaultResponse":false,"direction":0,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":null,"writeUndiv":false}) failed (no response received)'
Zigbee2MQTT:info 2021-02-09 09:35:39: MQTT publish: topic 'zigbee2mqtt/bridge/log', payload '{"message":"Publish 'set' 'brightness' to 'keuken werkblad' failed: 'Error: Command 0x90fd9ffffe17ea2a/1 genLevelCtrl.moveToLevelWithOnOff({"level":26,"transtime":20}, {"timeout":10000,"disableResponse":false,"disableRecovery":false,"disableDefaultResponse":false,"direction":0,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":null,"writeUndiv":false}) failed (no response received)'","meta":{"friendly_name":"keuken werkblad"},"type":"zigbee_publish_error"}'
Zigbee2MQTT:error 2021-02-09 09:36:22: Failed to disable reporting for '0x00158d00041477d9' - Error: Unbind 0x00158d00041477d9/1 genOnOff from '0x00212effff05221b/1' failed (waiting for response TIMEOUT)
at DeconzAdapter. (/app/node_modules/zigbee-herdsman/dist/adapter/deconz/adapter/deconzAdapter.js:755:23)
at Generator.throw ()
at rejected (/app/node_modules/zigbee-herdsman/dist/adapter/deconz/adapter/deconzAdapter.js:25:65)
at runMicrotasks ()
at runNextTicks (internal/process/task_queues.js:58:5)
at processTimers (internal/timers.js:494:9)

Could this be related to the changes made which has been made related with the adapter delay settings?

(running the non dev build now btw and that works)

[sjuxax]

fwiw, I've found that adapter_delay: 30 keeps things working pretty well. This is with the commits from earlier today. When I try with adapter_delay: 0, I get many timeouts and z2m struggles to do anything, and eventually stops responding almost entirely. adapter_delay: 30 seems to keep the adapter happy enough and the lag doesn't really seem noticeable, but even if it was, it's better than not being usable at all, which is what I was experiencing with adapter_delay: 0.

[ChrisHae]

@snippem yes sorry, a bug slipped through while commiting my code yesterday. I have uploaded a fix now.
a workaround for now is to use adapter_delay: 1 or any other number in configuration.yaml

[Koenkk]

Fix will be in dev in 1 hour from now.

[srnoth]

Current dev version is still unstable. Even with adapter_delay set to 30 it gets bogged down (especially when adjusting light groups) and eventually crashes. Required physical reboot of the conbee stick.

Going back to version 15 is 99.9% stable. It seems as if the changes made in v16 were solving for a very rare problem and have ended up breaking usability for a much larger group of users. Maybe best to go back to v15 and review what changes are actually needed or not.

[srnoth]

Ok updated finding: current dev version with no value specified for adapter_delay works fine (and is very quick) for devices that I know are connected directly to the Conbee.

The issues arise for devices that are going through another router to get to the conbee - with those I am getting issues such as half the bulbs in a room turning off while the others stay on (with group messaging all should turn off simultaneously).

Still getting missed group messaged even with adapter_delay set at 100.

Again, whatever values were used in v15 seemed ideal - response time was almost instantaneous and I never had issues with devices missing group messages. Perhaps we could return to these values by default (when no adapter_delay is specified) so that only those who need the increased delay can add it as needed?

Getting delayed/missed group messages even when rolled back to v15. Too many variables - think my zigbee network may need time to settle down.

Going back to dev version, no value set for adapter_delay, and will give it 24 hours to settle.

[juslex]

@Imaginous Did you tested the last dev version with the @ChrisHae latest fix?

[Imaginous]

@Imaginous Did you tested the last dev version with the @ChrisHae latest fix?

I will try it tonight... @Koenkk Will keep you informed.

Something came up... will test Thursday evening.

[srnoth]

After 12 hours or so I can say the current Dev version is mostly stable. Definitely faster than the old values in v15. That speed does seem to lead to more missed commands (e.g. having to press remote buttons twice) but as long as you're not pressing multiple buttons repeatedly it seems fine.

[Imaginous]

@Koenkk I did some testing with the latest Dev version. All seems okay. I didn't have any missed events (button presses). Every thing is as smooth as with my edited driver.js. For me this dev version seems a go.

I don't have any groups, so every device gets it's own packets. Can't elaborate on the issues of @srnoth. However it seems that he is being hunted by multiple factors at once ;)

[srnoth]

@Imaginous all is mostly well with the new settings. The only issue seems to be with automations that send multiple Zigbee commands one after the other. For example I have a remote bound to a light (so the on/off commands are straight from the remote to the light) but I also have an automation that sets the light to a predefined color when the "on" button is pressed. These new settings are so fast that the "color" command is being received too soon after the "on" command, and is being ignored. Added a delay to the automation and now it's working fine.

Not complaining though, folks use their zigbee networks in different ways and I guess that's where having a tunable delay value is best.

[Imaginous]

@Imaginous all is mostly well with the new settings. The only issue seems to be with automations that send multiple Zigbee commands one after the other. For example I have a remote bound to a light (so the on/off commands are straight from the remote to the light) but I also have an automation that sets the light to a predefined color when the "on" button is pressed. These new settings are so fast that the "color" command is being received too soon after the "on" command, and is being ignored. Added a delay to the automation and now it's working fine.

@srnoth I have my own automation behind it and I do the same thing for some lights, when I get an On event of a lamp I adjust the brightness to a certain level, did not experience any strange behavior... But maybe my code is just slow ;)

[srnoth]

@Imaginous lol! I should add that the only light that is giving this trouble is one that I know for a fact is behind a repeater/router rather than directly connected to the conbee.

[Imaginous]

@srnoth Non of my tested lights or switches are directly connected to the Conbee II, they al have at least one hop.
So I didn't experience any problems with that. Just to let you know.

[srnoth]

Happy to report mostly smooth sailing for 3 days now. Changed my automations to avoid any "swarm" of commands being sent all at once and have had zero issues since.

Hopefully the last changes have put this issue to bed once and for all! Thanks for the all the hard work @Imaginous, @ChrisHae and @Koenkk .

[juslex]

everything is perfect here and faster. very good job!

[julioyg]

I've just tested the latest form dev, I've got a network of 46 devices, when I tell google to turn off all the lights, with that version, it leaves some of the off. I dunno if this helps in any way, but I can get the logs if you want :)

[snippem]

Information you could share is for example you settings in the configuration.yaml.
What setup you use for example are we talking about a setup with a conbee 2.
Log you Mqtt command when you give the command to see if your broker misses the commands.
Also it helps if you create groups for lights etc that switch on or off with one command.
Not that this is a solution that solves the mqtt commands that are not executed but sure helps not overflowing your mqtt server.

[julioyg]

sorry, yeah, it's conbee 2,

and here are the logs:

Zigbee2MQTT:debug 2021-02-22 22:09:21: Received MQTT message on 'zigbee2mqtt/switch_hallway_1/l1/set' with data 'OFF'
Zigbee2MQTT:debug 2021-02-22 22:09:21: Received MQTT message on 'zigbee2mqtt/light_entrance/set' with data '{"state": "OFF"}'
Zigbee2MQTT:debug 2021-02-22 22:09:21: Received MQTT message on 'zigbee2mqtt/switch_attic/l2/set' with data 'OFF'
Zigbee2MQTT:debug 2021-02-22 22:09:21: Received MQTT message on 'zigbee2mqtt/lamp_bedroom_julio/set' with data '{"state": "OFF"}'
Zigbee2MQTT:debug 2021-02-22 22:09:21: Received MQTT message on 'zigbee2mqtt/switch_interior_patio/l1/set' with data 'OFF'
Zigbee2MQTT:debug 2021-02-22 22:09:21: Received MQTT message on 'zigbee2mqtt/lamp_living_room/set' with data '{"state": "OFF"}'
Zigbee2MQTT:debug 2021-02-22 22:09:21: Received MQTT message on 'zigbee2mqtt/switch_living_room/l2/set' with data 'OFF'
Zigbee2MQTT:debug 2021-02-22 22:09:21: Received MQTT message on 'zigbee2mqtt/light_parking/set' with data '{"state": "OFF"}'
Zigbee2MQTT:debug 2021-02-22 22:09:21: Received MQTT message on 'zigbee2mqtt/switch_bathroom_1/l1/set' with data 'OFF'
Zigbee2MQTT:debug 2021-02-22 22:09:21: Received MQTT message on 'zigbee2mqtt/lamp_bedroom_ale/set' with data '{"state": "OFF"}'
Zigbee2MQTT:debug 2021-02-22 22:09:21: Received MQTT message on 'zigbee2mqtt/switch_hallway_0/l2/set' with data 'OFF'
Zigbee2MQTT:debug 2021-02-22 22:09:21: Received MQTT message on 'zigbee2mqtt/switch_restroom/set' with data 'OFF'
Zigbee2MQTT:debug 2021-02-22 22:09:21: Received MQTT message on 'zigbee2mqtt/switch_kitchen/l1/set' with data 'OFF'
Zigbee2MQTT:debug 2021-02-22 22:09:21: Received MQTT message on 'zigbee2mqtt/lamp_attic_bedroom/set' with data '{"state": "OFF"}'
Zigbee2MQTT:debug 2021-02-22 22:09:21: Received MQTT message on 'zigbee2mqtt/switch_main_bedroom/l1/set' with data 'OFF'
Zigbee2MQTT:debug 2021-02-22 22:09:21: Received MQTT message on 'zigbee2mqtt/switch_main_bedroom_bathroom/l1/set' with data 'OFF'
Zigbee2MQTT:debug 2021-02-22 22:09:21: Received MQTT message on 'zigbee2mqtt/switch_office/l1/set' with data 'OFF'
Zigbee2MQTT:debug 2021-02-22 22:09:21: Received MQTT message on 'zigbee2mqtt/switch_main_bedroom/l2/set' with data 'OFF'
Zigbee2MQTT:debug 2021-02-22 22:09:21: Received MQTT message on 'zigbee2mqtt/switch_light_attic_bathroom/set' with data 'OFF'
Zigbee2MQTT:debug 2021-02-22 22:09:21: Received MQTT message on 'zigbee2mqtt/switch_living_room/l1/set' with data 'OFF'
Zigbee2MQTT:debug 2021-02-22 22:09:21: Received MQTT message on 'zigbee2mqtt/switch_patio/l1/set' with data 'OFF'
Zigbee2MQTT:debug 2021-02-22 22:09:21: Received MQTT message on 'zigbee2mqtt/switch_hallway_1/l2/set' with data 'OFF'
Zigbee2MQTT:debug 2021-02-22 22:09:21: Received MQTT message on 'zigbee2mqtt/switch_hallway_0/l1/set' with data 'OFF'
Zigbee2MQTT:debug 2021-02-22 22:09:21: Received MQTT message on 'zigbee2mqtt/switch_attic_bedroom/l1/set' with data 'OFF'

Also the reason for me not do this by creating a group is because this happens when I tell google home to turn off al the lights of the house 😅

[ChrisHae]

@julioyg Does google home can not turn off a group?

[julioyg]

@ChrisHae i see what you mean, yeah I could, but then i'd have to create a group to group all the lights in the house and add them manually each time a I add a new one, then I could expose that group to google home, but... it doesnt feel like a solution, more of a workaround I guess 😅.
It works alright if i set the adapter_delay to 300

[ChrisHae]

@julioyg But that's the purpose of a group - controling many lights at once. That is the reason there is such thing as group commands in the zigbee protocol. Controlling many lights with single commands will always produce high network traffic and cause problems. Ok but therefore I added the higher adapter_delay setting. Good to hear that it helps to reduce the failures - of course the tradeoff is the speed.

[srnoth]

@julioyg lights can also be part of multiple zigbee groups - e.g. my four kitchen lights are part of both a "kitchen" group and a "downstairs" group. That way I can turn the entire downstairs on/off with one zigbee command instead of dozens of commands to individual bulbs. As your number of devices expands, it becomes impractical to send individual commands to each bulb.

One other advantage of zigbee groups - all the bulbs in a group turn on/off in sync - which is visually much nicer than noticing the different bulbs turning on/off at slightly different times.

[github-actions]

This issue is stale because it has been open 30 days with no activity. Remove stale label or comment or this will be closed in 7 days

[Stooovie]

Hi, is it possible that the Adapter Delay parameter in Z2M GUI in HA is inactive? The actual delay doesn’t change at all no matter what I set there, even numbers like 3000. Z2M 1.28.2.0.