Hello!
Some introduction first. I first started with z-wave in 2017 in a previous home, with great satisfaction, for years I have never had any issue. Then I had to move and leave all behind, and in the next home because I was renting an apartment I just installed some shelly (wifi) and all worked great. Then I bought home some weeks ago and the builder installed zigbee switches.
And this is the first experience with zigbee and I am wondering if something’s wrong or is the protocol that is unreliable.
Setup
- Home Assistant Yellow, with Zigbee2mqtt 1.39.1, ember driver, coordinator revision 7.4.3 [GA]
- The devices are well placed and LQI are optimal, WiFi interference is unlikely since I am the only one living in the building right now and I changed channels accordingly.
What Happens
- If I power off the devices, some do not come back online and are unreachable
- If I reboot HAOS, some devices do not come back online and are unreachable
- There’s no way to wake up unreachable devices
- There’s no way to rebuild zigbee network
- The only way to restore them is to reset them
One example of one device offline since I rebooted HAOS yesterday:
2024-08-31 10:58:59z2m: Failed to ping 'Luce terrazzo sala' (attempt 1/1, ZCL command 0xf4ce36c553d84b7a/10 genBasic.read(["zclVersion"], {"timeout":10000,"disableResponse":false,"disableRecovery":true,"disableDefaultResponse":true,"direction":0,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":null,"writeUndiv":false}) failed (Delivery failed for {"profileId":260,"clusterId":0,"sourceEndpoint":1,"destinationEndpoint":10,"options":4160,"groupId":0,"sequence":224}))
Debug logs if I try to turn on/off the device:
[2024-08-31 11:22:22] info: z2m: Successfully changed options
[2024-08-31 11:22:22] info: z2m:mqtt: MQTT publish: topic 'zigbee2mqtt/bridge/response/options', payload '{"data":{"restart_required":false},"status":"ok","transaction":"2q3jc-1"}'
[2024-08-31 11:22:28] debug: z2m:mqtt: Received MQTT message on 'zigbee2mqtt/Luce terrazzo sala/set' with data '{"state":"ON"}'
[2024-08-31 11:22:28] debug: z2m: Publishing 'set' 'state' to 'Luce terrazzo sala'
[2024-08-31 11:22:28] debug: zh:controller:endpoint: ZCL command 0xf4ce36c553d84b7a/10 genOnOff.on({}, {"timeout":10000,"disableResponse":false,"disableRecovery":false,"disableDefaultResponse":false,"direction":0,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":null,"writeUndiv":false})
[2024-08-31 11:22:28] debug: zh:ember: ~~~> [ZCL to=2131 apsFrame={"profileId":260,"clusterId":6,"sourceEndpoint":1,"destinationEndpoint":10,"options":4416,"groupId":0,"sequence":0} header={"frameControl":{"reservedBits":0,"frameType":1,"direction":0,"disableDefaultResponse":false,"manufacturerSpecific":false},"manufacturerCode":null,"transactionSequenceNumber":222,"commandIdentifier":1}]
[2024-08-31 11:22:28] debug: zh:ember:ezsp: ===> [FRAME: ID=52:"SEND_UNICAST" Seq=251 Len=24]
[2024-08-31 11:22:28] debug: zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=3 frmRx=1](ackRx=3)
[2024-08-31 11:22:28] debug: zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-08-31 11:22:28] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=4](ackRx=3 frmTx=4)
[2024-08-31 11:22:28] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=4 frmNum=1](frmRx=1) Added to rxQueue
[2024-08-31 11:22:28] debug: zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=2](ackRx=4)
[2024-08-31 11:22:28] debug: zh:ember:ezsp: <=== [FRAME: ID=52:"SEND_UNICAST" Seq=251 Len=7]
[2024-08-31 11:22:28] debug: zh:ember:ezsp: ~~~> [SENT type=DIRECT apsSequence=130 messageTag=15 status=OK]
[2024-08-31 11:22:33] debug: zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-08-31 11:22:33] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=4](ackRx=4 frmTx=4)
[2024-08-31 11:22:33] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=4 frmNum=2](frmRx=2) Added to rxQueue
[2024-08-31 11:22:33] debug: zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=3](ackRx=4)
[2024-08-31 11:22:33] debug: zh:ember:ezsp: <=== [CBFRAME: ID=63:"MESSAGE_SENT_HANDLER" Seq=251 Len=22]
[2024-08-31 11:22:33] debug: zh:ember:ezsp: ezspMessageSentHandler(): callback called with: [status=ZIGBEE_DELIVERY_FAILED], [type=DIRECT], [indexOrDestination=2131], [apsFrame={"profileId":260,"clusterId":6,"sourceEndpoint":1,"destinationEndpoint":10,"options":4160,"groupId":0,"sequence":130}], [messageTag=15]
[2024-08-31 11:22:33] debug: zh:controller:endpoint: Error: ZCL command 0xf4ce36c553d84b7a/10 genOnOff.on({}, {"timeout":10000,"disableResponse":false,"disableRecovery":false,"disableDefaultResponse":false,"direction":0,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":null,"writeUndiv":false}) failed (Delivery failed for {"profileId":260,"clusterId":6,"sourceEndpoint":1,"destinationEndpoint":10,"options":4160,"groupId":0,"sequence":130})
[2024-08-31 11:22:33] error: z2m: Publish 'set' 'state' to 'Luce terrazzo sala' failed: 'Error: ZCL command 0xf4ce36c553d84b7a/10 genOnOff.on({}, {"timeout":10000,"disableResponse":false,"disableRecovery":false,"disableDefaultResponse":false,"direction":0,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":null,"writeUndiv":false}) failed (Delivery failed for {"profileId":260,"clusterId":6,"sourceEndpoint":1,"destinationEndpoint":10,"options":4160,"groupId":0,"sequence":130})'
[2024-08-31 11:22:33] debug: z2m: Error: ZCL command 0xf4ce36c553d84b7a/10 genOnOff.on({}, {"timeout":10000,"disableResponse":false,"disableRecovery":false,"disableDefaultResponse":false,"direction":0,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":null,"writeUndiv":false}) failed (Delivery failed for {"profileId":260,"clusterId":6,"sourceEndpoint":1,"destinationEndpoint":10,"options":4160,"groupId":0,"sequence":130})
at EmberOneWaitress.deliveryFailedFor (/app/node_modules/zigbee-herdsman/src/adapter/ember/adapter/oneWaitress.ts:98:31)
at EmberAdapter.onMessageSent (/app/node_modules/zigbee-herdsman/src/adapter/ember/adapter/emberAdapter.ts:454:42)
at Ezsp.emit (node:events:517:28)
at Ezsp.ezspMessageSentHandler (/app/node_modules/zigbee-herdsman/src/adapter/ember/ezsp/ezsp.ts:5016:14)
at Ezsp.callbackDispatch (/app/node_modules/zigbee-herdsman/src/adapter/ember/ezsp/ezsp.ts:770:26)
at Ezsp.onAshFrame (/app/node_modules/zigbee-herdsman/src/adapter/ember/ezsp/ezsp.ts:430:22)
at UartAsh.emit (node:events:517:28)
at Immediate.<anonymous> (/app/node_modules/zigbee-herdsman/src/adapter/ember/uart/ash.ts:1187:45)
at processImmediate (node:internal/timers:476:21)
[2024-08-31 11:22:36] debug: z2m:mqtt: Received MQTT message on 'zigbee2mqtt/Luce terrazzo sala/set' with data '{"state":"OFF"}'
[2024-08-31 11:22:36] debug: z2m: Publishing 'set' 'state' to 'Luce terrazzo sala'
[2024-08-31 11:22:36] debug: zh:controller:endpoint: ZCL command 0xf4ce36c553d84b7a/10 genOnOff.off({}, {"timeout":10000,"disableResponse":false,"disableRecovery":false,"disableDefaultResponse":false,"direction":0,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":null,"writeUndiv":false})
[2024-08-31 11:22:36] debug: zh:ember: ~~~> [ZCL to=2131 apsFrame={"profileId":260,"clusterId":6,"sourceEndpoint":1,"destinationEndpoint":10,"options":4416,"groupId":0,"sequence":0} header={"frameControl":{"reservedBits":0,"frameType":1,"direction":0,"disableDefaultResponse":false,"manufacturerSpecific":false},"manufacturerCode":null,"transactionSequenceNumber":223,"commandIdentifier":0}]
[2024-08-31 11:22:36] debug: zh:ember:ezsp: ===> [FRAME: ID=52:"SEND_UNICAST" Seq=252 Len=24]
[2024-08-31 11:22:36] debug: zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=4 frmRx=3](ackRx=4)
[2024-08-31 11:22:36] debug: zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-08-31 11:22:36] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=5](ackRx=4 frmTx=5)
[2024-08-31 11:22:36] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=5 frmNum=3](frmRx=3) Added to rxQueue
[2024-08-31 11:22:36] debug: zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=4](ackRx=5)
[2024-08-31 11:22:36] debug: zh:ember:ezsp: <=== [FRAME: ID=52:"SEND_UNICAST" Seq=252 Len=7]
[2024-08-31 11:22:36] debug: zh:ember:ezsp: ~~~> [SENT type=DIRECT apsSequence=131 messageTag=16 status=OK]
[2024-08-31 11:22:41] debug: zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-08-31 11:22:41] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=5](ackRx=5 frmTx=5)
[2024-08-31 11:22:41] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=5 frmNum=4](frmRx=4) Added to rxQueue
[2024-08-31 11:22:41] debug: zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=5](ackRx=5)
[2024-08-31 11:22:41] debug: zh:ember:ezsp: <=== [CBFRAME: ID=63:"MESSAGE_SENT_HANDLER" Seq=252 Len=22]
[2024-08-31 11:22:41] debug: zh:ember:ezsp: ezspMessageSentHandler(): callback called with: [status=ZIGBEE_DELIVERY_FAILED], [type=DIRECT], [indexOrDestination=2131], [apsFrame={"profileId":260,"clusterId":6,"sourceEndpoint":1,"destinationEndpoint":10,"options":4160,"groupId":0,"sequence":131}], [messageTag=16]
[2024-08-31 11:22:41] debug: zh:controller:endpoint: Error: ZCL command 0xf4ce36c553d84b7a/10 genOnOff.off({}, {"timeout":10000,"disableResponse":false,"disableRecovery":false,"disableDefaultResponse":false,"direction":0,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":null,"writeUndiv":false}) failed (Delivery failed for {"profileId":260,"clusterId":6,"sourceEndpoint":1,"destinationEndpoint":10,"options":4160,"groupId":0,"sequence":131})
[2024-08-31 11:22:41] error: z2m: Publish 'set' 'state' to 'Luce terrazzo sala' failed: 'Error: ZCL command 0xf4ce36c553d84b7a/10 genOnOff.off({}, {"timeout":10000,"disableResponse":false,"disableRecovery":false,"disableDefaultResponse":false,"direction":0,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":null,"writeUndiv":false}) failed (Delivery failed for {"profileId":260,"clusterId":6,"sourceEndpoint":1,"destinationEndpoint":10,"options":4160,"groupId":0,"sequence":131})'
[2024-08-31 11:22:41] debug: z2m: Error: ZCL command 0xf4ce36c553d84b7a/10 genOnOff.off({}, {"timeout":10000,"disableResponse":false,"disableRecovery":false,"disableDefaultResponse":false,"direction":0,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":null,"writeUndiv":false}) failed (Delivery failed for {"profileId":260,"clusterId":6,"sourceEndpoint":1,"destinationEndpoint":10,"options":4160,"groupId":0,"sequence":131})
at EmberOneWaitress.deliveryFailedFor (/app/node_modules/zigbee-herdsman/src/adapter/ember/adapter/oneWaitress.ts:98:31)
at EmberAdapter.onMessageSent (/app/node_modules/zigbee-herdsman/src/adapter/ember/adapter/emberAdapter.ts:454:42)
at Ezsp.emit (node:events:517:28)
at Ezsp.ezspMessageSentHandler (/app/node_modules/zigbee-herdsman/src/adapter/ember/ezsp/ezsp.ts:5016:14)
at Ezsp.callbackDispatch (/app/node_modules/zigbee-herdsman/src/adapter/ember/ezsp/ezsp.ts:770:26)
at Ezsp.onAshFrame (/app/node_modules/zigbee-herdsman/src/adapter/ember/ezsp/ezsp.ts:430:22)
at UartAsh.emit (node:events:517:28)
at Immediate.<anonymous> (/app/node_modules/zigbee-herdsman/src/adapter/ember/uart/ash.ts:1187:45)
at processImmediate (node:internal/timers:476:21)
[2024-08-31 11:22:44] debug: z2m:mqtt: Received MQTT message on 'zigbee2mqtt/bridge/request/options' with data '{"options":{"advanced":{"log_level":"warning"}},"transaction":"2q3jc-2"}'
So I am wondering if this is normal. And if it’s not, what can I do to improve the reliability?