1.35.1 Breaking on Startup

thenoid commented 8 months ago

What happened?

Multipan and Zigbee2mqtt images were updated. Multipan appears to be talking to the adapter correctly, but suddenly zigbee2mqtt fails to talk over ezsp.

root@donnager:~# docker images | egrep -i "zig|multi" | sort
b2un0/silabs-multipan-docker                       latest       4f3bb23b68ca   31 minutes ago   392MB
b2un0/silabs-multipan-docker                       <none>       9d5c108a551c   25 hours ago     392MB
b2un0/silabs-multipan-docker                       wtf          5d72916dd7e3   2 days ago       392MB
koenkk/zigbee2mqtt                                 1.35.0       f10bce5e79ef   6 days ago       115MB
koenkk/zigbee2mqtt                                 latest-dev   ec34474dbc25   18 hours ago     115MB
koenkk/zigbee2mqtt                                 latest       ff3a7c92f585   19 hours ago     115MB

zigbee2mqtt      | Using '/app/data' as data directory
zigbee2mqtt      | Zigbee2MQTT:error 2024-01-08 00:21:36: Error while starting zigbee-herdsman
zigbee2mqtt      | Zigbee2MQTT:error 2024-01-08 00:21:36: Failed to start zigbee
zigbee2mqtt      | Zigbee2MQTT:error 2024-01-08 00:21:36: Check https://www.zigbee2mqtt.io/guide/installation/20_zigbee2mqtt-fails-to-start.html for possible solutions
zigbee2mqtt      | Zigbee2MQTT:error 2024-01-08 00:21:36: Exiting...
zigbee2mqtt      | Zigbee2MQTT:error 2024-01-08 00:21:36: Error: Failure send version:{"type":"Buffer","data":[1,0,1,0,0,12]}
zigbee2mqtt      |     at /app/node_modules/zigbee-herdsman/src/adapter/ezsp/driver/ezsp.ts:562:23
zigbee2mqtt      |     at Queue.executeNext (/app/node_modules/zigbee-herdsman/src/utils/queue.ts:32:32)
zigbee2mqtt      | Using '/app/data' as data directory
zigbee2mqtt      | Assertion failed: Command (setConfigurationValue) returned unexpected state: [object Object]
zigbee2mqtt      | Assertion failed: Command (setValue) returned unexpected state: 55
zigbee2mqtt      | Using '/app/data' as data directory
zigbee2mqtt      | Assertion failed: Command (setConfigurationValue) returned unexpected state: [object Object]
zigbee2mqtt      | Assertion failed: Command (setValue) returned unexpected state: 55

What did you expect to happen?

zigbee herdsman to startup

How to reproduce it (minimal and precise)

Now that it's updated i can't stop reproducing it.

Zigbee2MQTT version

1.35.1

Adapter firmware version

7.3.1.0 build 0

Adapter

Sonoff Zigbee 3.0 USB Dongle Plus V2

Debug log

No response

thenoid commented 8 months ago

Well somewhere in trying dev containers, restarting, rebooting, updating, mysteriously it started working again.

Computers were a mistake.

dso2ng commented 8 months ago

My environment is Homeassistant Yellow, using Sillicon Labs Multiprotocol as Zigbee backend, I have two sets of this, both are runing fine before and now the starting log shows:

[10:24:16] INFO: Preparing to start...
[10:24:17] INFO: Socat not enabled
[10:24:19] INFO: Starting Zigbee2MQTT...
Zigbee2MQTT:info  2024-01-13 10:24:26: Logging to console and directory: '/config/zigbee2mqtt/log/2024-01-13.10-24-26' filename: log.txt
Zigbee2MQTT:info  2024-01-13 10:24:26: Starting Zigbee2MQTT version 1.35.1 (commit #unknown)
Zigbee2MQTT:info  2024-01-13 10:24:26: Starting zigbee-herdsman (0.30.0)
Assertion failed: Command (setConfigurationValue) returned unexpected state: [object Object]
Assertion failed: Command (setValue) returned unexpected state: 55
Error: {"address":0,"clusterId":32770,"sequence":2} after 10000ms
    at Timeout._onTimeout (/app/node_modules/zigbee-herdsman/src/utils/waitress.ts:64:35)
    at listOnTimeout (node:internal/timers:569:17)
    at processTimers (node:internal/timers:512:7)

Please advise what should I further check to reveal more information?

thenoid commented 8 months ago

zigbee2mqtt      | Assertion failed: Command (setValue) returned unexpected state: 55
zigbee2mqtt      | Error: {"address":0,"clusterId":32770,"sequence":2} after 10000ms
zigbee2mqtt      |     at Timeout._onTimeout (/app/node_modules/zigbee-herdsman/src/utils/waitress.ts:64:35)
zigbee2mqtt      |     at listOnTimeout (node:internal/timers:569:17)
zigbee2mqtt      |     at processTimers (node:internal/timers:512:7)

hmm yeah, left for a long weekend, came back and suddnely it's doing it again.

Koenkk commented 8 months ago

This is probably because your adapter updated it's firmware (you probably updated the multi protocol HA addon). The new firmware is not supported by z2m 1.35.1 but has been fixed in the dev branch already.

thenoid commented 8 months ago

That would be a bingo, downgraded everything and we are back in business. Automatic updates are such a love hate thing.

Koenkk / zigbee2mqtt