1.40.0/1.40.1

[Koenkk]

Feel free to discuss the 1.40.0 and 1.40.1 release here!

[mremedi2023]

Hi everyone, since I updated I started getting errors...

[Zayeen]

I'm having the same problem. In my setup the Tuya TV02-Zigbee is the cause somehow. If i try to change a setting or it updates the error comes up. I hope this helps resolve the bug.

[Koenkk]

Please create a new issue with the debug logging attached.

See this on how to enable debug logging.

[mremedi2023]

I'm seeing what's happening with some Tuya ZY-M100-S_2 / Tuya MTG075-ZB-RL presence sensors

[jivasko]

Hi getting error on all devices after update 1.40.

2024-09-02 13:45:12] error: 	z2m: Publish 'set' 'state' to 'Switch3g_Obyvacka' failed: 'Error: ZCL command 0xa4c1382dab4358c1/3 genOnOff.on({}, {"timeout":10000,"disableResponse":false,"disableRecovery":false,"disableDefaultResponse":false,"direction":0,"reservedBits":0,"writeUndiv":false}) failed (Delivery failed for {"profileId":260,"clusterId":6,"sourceEndpoint":1,"destinationEndpoint":3,"options":4160,"groupId":0,"sequence":61})'
[2024-09-02 14:34:05] error: 	z2m: Publish 'set' 'state' to 'Switch3g_Obyvacka' failed: 'Error: ZCL command 0xa4c1382dab4358c1/3 genOnOff.on({}, {"timeout":10000,"disableResponse":false,"disableRecovery":false,"disableDefaultResponse":false,"direction":0,"reservedBits":0,"writeUndiv":false}) failed (Delivery failed for {"profileId":260,"clusterId":6,"sourceEndpoint":1,"destinationEndpoint":3,"options":4160,"groupId":0,"sequence":27})'

[jivasko]

Downgraded to 1.39 but the same issue, most probably issue with my sonoff dongle

[Nerivec]

From the error, I'm assuming Sonoff Dongle-E. If so, try using ember-zli to leave the network on the adapter. Since you have a backup created in your zigbee2mqtt data folder from last time you shut it down properly (make sure you do before leaving the network!), it will force z2m to restore the network on the adapter next time you start it. Hopefully, that will solve your problem.

[jjarven]

I had showstopper issue last night while updated to 1.40.0.
It originally worked ok but then, I updated my TI based usb zigbee stick firmware to the latest (20240710) and then started the system - only to find out the 1.40.0 does something differently while restoring the stick configuration and it can't start.

Flashed the usb stick back to previous version but still same problem while starting.

As a last resort, I restored zigbee2mqtt from backup to 1.39.1 and system started.

• Noticed the usb stick works with older and newer firmwares (but with 1.39.1 version).

I have zigbee2mqtt fail logs if needed (added snippet below)
Just a heads up when you experience this.

NOT WORKING (1.40.0 version):
[2024-09-02 22:08:21] debug: zh:zstack:unpi:parser: --> parsed 3 - 2 - 15 - 128 - [0,2,0] - 206
[2024-09-02 22:08:21] debug: zh:zstack:znp: AREQ: <-- APP_CNF - bdbComissioningNotifcation - {"status":0}
[2024-09-02 22:08:21] debug: zh:zstack:unpi:parser: --- parseNext []
[2024-09-02 22:08:21] debug: zh:adapter:zstack:manager: waiting for NIB to settle
[2024-09-02 22:08:22] error: z2m: Error while starting zigbee-herdsman
[2024-09-02 22:08:22] error: z2m: Failed to start zigbee
[2024-09-02 22:08:22] error: z2m: Check https://www.zigbee2mqtt.io/guide/installation/20_zigbee2mqtt-fails-to-start.html for possible solutions
[2024-09-02 22:08:22] error: z2m: Exiting...
[2024-09-02 22:08:22] error: z2m: Error: SRSP - SYS - stackTune after 6000ms
at Object.start (/app/node_modules/zigbee-herdsman/src/utils/waitress.ts:59:23)
at /app/node_modules/zigbee-herdsman/src/adapter/z-stack/znp/znp.ts:300:45
at Queue.execute (/app/node_modules/zigbee-herdsman/src/utils/queue.ts:36:26)
at /app/node_modules/zigbee-herdsman/src/adapter/z-stack/adapter/zStackAdapter.ts:1111:13
at Queue.execute (/app/node_modules/zigbee-herdsman/src/utils/queue.ts:36:20)
at ZStackAdapter.start (/app/node_modules/zigbee-herdsman/src/adapter/z-stack/adapter/zStackAdapter.ts:165:13)
at Controller.start (/app/node_modules/zigbee-herdsman/src/controller/controller.ts:138:29)
at Zigbee.start (/app/lib/zigbee.ts:64:27)
at Controller.start (/app/lib/controller.ts:140:27)
at start (/app/index.js:154:5)

WORKING (1.39.1 version):
[2024-09-02 23:06:14] debug: zh:zstack:unpi:parser: --> parsed 3 - 2 - 15 - 128 - [0,2,0] - 206
[2024-09-02 23:06:14] debug: zh:zstack:znp: AREQ: <-- APP_CNF - bdbComissioningNotifcation - {"status":0}
[2024-09-02 23:06:14] debug: zh:zstack:unpi:parser: --- parseNext []
[2024-09-02 23:06:17] debug: zh:zstack:znp: SREQ: --> SYS - osalNvLength - {"id":33}
[2024-09-02 23:06:17] debug: zh:zstack:unpi:writer: --> frame [254,2,33,19,33,0,17]
.. and continues as it should

--
Days later - not sure how, I believe I did not update to 1.40.0 but now my hass say it is updated. Anyways, seems when full network restore to zigbee stick is not needed, the problem did not appear.

[Ramotny]

Yesterday after 1.40 update Z2M did NOT want to open UI ("addon not started") - but after backup restore to 1.39, re-update and third "retry" it started and now works ok.

[Nerivec]

What system do you run z2m on (hardware+software)?
Looks like something might have gone wrong during the first update.
With HA, you can also try to uninstall the add-on, then re-install it when something like this happens.

[mremedi2023]

It seems to work fine in the development version. Thank you

[chris-1243]

@Koenkk

Would you check #23814 ? It seems ZGP in deconz only is not working anymore.

I checked zstack and ember and everything is working well👍

[jamesonuk]

I think the MQTT rework may have broken client certificates.
Did the upgrade and I just got this is mosquitto logs

2024-09-03T21:07:30.319026863Z 1725397650: New connection from 10.99.99.8:36552 on port 8883.
2024-09-03T21:07:30.380147134Z 1725397650: OpenSSL Error[0]: error:14FFF0C7:SSL routines:(UNKNOWN)SSL_internal:peer did not return a certificate### 

reverted to 1.39.1 and all working again.

Will attempt to do some debugging tomorrow but I need to get lights working before the wife kills me....

[Nerivec]

I don't see any change at all in mqtt class from 1.39.1 to 1.40.0.

[jamesonuk]

I was rushing to get the lights working and saw #23072 and thought it was under 1.40. will try the upgrade again later today and do some more debugging

[jamesonuk]

It worked this time so no issue but I am struggling to work out what happened. Mosquitto was definitely saying Z2M wasn't sending client certificate and could not connect but can't have been anything like Docker not mounting volume properly as the certificate files are in the same volume as the config...

I suspect I will never be able to replicate it or see what happened but is working now so the family are happy :D

[Nerivec]

Something about the network between z2m<>mosquitto containers, temporary failure of some kind?
Or the dog ate it... 😝

[R-ens]

Setup

Zigbee2MQTT version [1.40.0]
Coordinator type EmberZNet
Coordinator revision 7.4.3 [GA]
Frontend version 0.7.4
zigbee-herdsman-converters version 20.8.4
zigbee-herdsman version 0.57.1

Coordinator: SkyConnect / Connect ZBT-1

---

Issue

Reconfigure / Interview / OTA - All these requests are failing for all my devices.
I'm not sure if it's related to Z2M version 1.40.0, never had this issue before.
Who can help me out?

Reconfigure request:

info 2024-09-06 09:02:40z2m: Configuring 'Hue Switch'
error 2024-09-06 09:02:45z2m: Failed to configure 'Hue Switch', attempt 1 (Error: Bind 0x001788010bd878f1/1 genOnOff from '0x287681fffef07395/1' failed (Delivery failed for {"profileId":0,"clusterId":33,"sourceEndpoint":0,"destinationEndpoint":0,"options":4416,"groupId":0,"sequence":195}) at EmberOneWaitress.deliveryFailedFor (/app/node_modules/zigbee-herdsman/src/adapter/ember/adapter/oneWaitress.ts:101:31) at EmberAdapter.onMessageSent (/app/node_modules/zigbee-herdsman/src/adapter/ember/adapter/emberAdapter.ts:480:42) at Ezsp.emit (node:events:517:28) at Ezsp.ezspMessageSentHandler (/app/node_modules/zigbee-herdsman/src/adapter/ember/ezsp/ezsp.ts:4982:14) at Ezsp.callbackDispatch (/app/node_modules/zigbee-herdsman/src/adapter/ember/ezsp/ezsp.ts:738:26) at Ezsp.onAshFrame (/app/node_modules/zigbee-herdsman/src/adapter/ember/ezsp/ezsp.ts:398:22) at UartAsh.emit (node:events:517:28) at Immediate.<anonymous> (/app/node_modules/zigbee-herdsman/src/adapter/ember/uart/ash.ts:1169:45) at processImmediate (node:internal/timers:476:21))
info 2024-09-06 09:02:45z2m:mqtt: MQTT publish: topic 'zigbee2mqtt/bridge/response/device/configure', payload '{"data":{"id":"Hue Switch"},"error":"Failed to configure (Bind 0x001788010bd878f1/1 genOnOff from '0x287681fffef07395/1' failed (Delivery failed for {\"profileId\":0,\"clusterId\":33,\"sourceEndpoint\":0,\"destinationEndpoint\":0,\"options\":4416,\"groupId\":0,\"sequence\":195}))","status":"error","transaction":"aco6c-1"}'
info 2024-09-06 09:02:48zh:ember:ezsp: Received network/route error ROUTE_ERROR_INDIRECT_TRANSACTION_EXPIRY for "65163".

Interview request:

info 2024-09-06 09:04:01z2m: Interviewing 'Hue Switch'
info 2024-09-06 09:04:10zh:ember:ezsp: Received network/route error ROUTE_ERROR_INDIRECT_TRANSACTION_EXPIRY for "65163".
error 2024-09-06 09:04:13z2m: Request 'zigbee2mqtt/bridge/request/device/interview' failed with error: 'interview of 'Hue Switch' (0x001788010bd878f1) failed: Error: Interview failed because can not get active endpoints ('0x001788010bd878f1')'
info 2024-09-06 09:04:13z2m:mqtt: MQTT publish: topic 'zigbee2mqtt/bridge/response/device/interview', payload '{"data":{},"error":"interview of 'Hue Switch' (0x001788010bd878f1) failed: Error: Interview failed because can not get active endpoints ('0x001788010bd878f1')","status":"error","transaction":"aco6c-2"}'
info 2024-09-06 09:04:13zh:ember:ezsp: Received network/route error ROUTE_ERROR_INDIRECT_TRANSACTION_EXPIRY for "65163".
info 2024-09-06 09:04:15zh:ember:ezsp: Received network/route error ROUTE_ERROR_INDIRECT_TRANSACTION_EXPIRY for "65163".
info 2024-09-06 09:04:16zh:ember:ezsp: Received network/route error ROUTE_ERROR_INDIRECT_TRANSACTION_EXPIRY for "65163".

OTA request:

info 2024-09-06 09:04:56z2m: Checking if update available for 'Hue Switch'
info 2024-09-06 09:05:04zh:ember:ezsp: Received network/route error ROUTE_ERROR_INDIRECT_TRANSACTION_EXPIRY for "65163".
info 2024-09-06 09:05:56z2m:mqtt: MQTT publish: topic 'zigbee2mqtt/bridge/response/device/ota_update/check', payload '{"data":{"id":"Hue Switch"},"error":"Failed to check if update available for 'Hue Switch' (Device didn't respond to OTA request)","status":"error","transaction":"aco6c-3"}'
error 2024-09-06 09:05:56z2m: Failed to check if update available for 'Hue Switch' (Device didn't respond to OTA request)

[Koenkk]

I added some more logging, could you provide the debug logging again with the latest dev branch?

See this on how to enable debug logging.

Changes will be available in the dev branch in a few hours from now.

[R-ens]

@Koenkk My log

debug 2024-09-06 14:49:09z2m:mqtt: Received MQTT message on 'zigbee2mqtt/bridge/request/device/ota_update/check' with data '{"id":"Hue Plug","transaction":"8dehz-2"}'
info 2024-09-06 14:49:09z2m: Checking if update available for 'Hue Plug'
debug 2024-09-06 14:49:09zhc:ota:common: Checking if an update is available for '0x001788010ca0d6b9' (LOM007)
debug 2024-09-06 14:49:09zhc:ota:common: Using endpoint '11'
debug 2024-09-06 14:49:09zh:controller:endpoint: CommandResponse 0x001788010ca0d6b9/11 genOta.imageNotify({"payloadType":0,"queryJitter":100}, {"timeout":10000,"disableResponse":false,"disableRecovery":false,"disableDefaultResponse":true,"direction":1,"reservedBits":0,"writeUndiv":false,"sendPolicy":"immediate"})
debug 2024-09-06 14:49:09zh:ember: ~~~> [ZCL to=58203 apsFrame={"profileId":260,"clusterId":25,"sourceEndpoint":1,"destinationEndpoint":11,"options":4352,"groupId":0,"sequence":0} header={"frameControl":{"reservedBits":0,"frameType":1,"direction":1,"disableDefaultResponse":true,"manufacturerSpecific":false},"transactionSequenceNumber":10,"commandIdentifier":0}]
debug 2024-09-06 14:49:09zh:ember:ezsp: ===> [FRAME: ID=52:"SEND_UNICAST" Seq=58 Len=26]
debug 2024-09-06 14:49:09zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=2 frmRx=3](ackRx=2)
debug 2024-09-06 14:49:09zh:ember:uart:ash: <--- [FRAME type=DATA]
debug 2024-09-06 14:49:09zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=3](ackRx=2 frmTx=3)
debug 2024-09-06 14:49:09zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=3 frmNum=3](frmRx=3) Added to rxQueue
debug 2024-09-06 14:49:09zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=4](ackRx=3)
debug 2024-09-06 14:49:09zh:ember:ezsp: <=== [FRAME: ID=52:"SEND_UNICAST" Seq=58 Len=7]
debug 2024-09-06 14:49:09zh:ember:ezsp: ~~~> [SENT type=DIRECT apsSequence=225 messageTag=21 status=OK]
debug 2024-09-06 14:49:09zh:ember:uart:ash: <--- [FRAME type=DATA]
debug 2024-09-06 14:49:09zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=3](ackRx=3 frmTx=3)
debug 2024-09-06 14:49:09zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=3 frmNum=4](frmRx=4) Added to rxQueue
debug 2024-09-06 14:49:09zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=5](ackRx=3)
debug 2024-09-06 14:49:09zh:ember:ezsp: <=== [CBFRAME: ID=63:"MESSAGE_SENT_HANDLER" Seq=58 Len=22]
debug 2024-09-06 14:49:09zh:ember:ezsp: ezspMessageSentHandler(): callback called with: [status=OK], [type=DIRECT], [indexOrDestination=58203], [apsFrame={"profileId":260,"clusterId":25,"sourceEndpoint":1,"destinationEndpoint":11,"options":4352,"groupId":0,"sequence":225}], [messageTag=21]
debug 2024-09-06 14:49:09zh:ember:uart:ash: <--- [FRAME type=DATA]
debug 2024-09-06 14:49:09zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=3](ackRx=3 frmTx=3)
debug 2024-09-06 14:49:09zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=3 frmNum=5](frmRx=5) Added to rxQueue
debug 2024-09-06 14:49:09zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=6](ackRx=3)
debug 2024-09-06 14:49:09zh:ember:ezsp: <=== [CBFRAME: ID=89:"INCOMING_ROUTE_RECORD_HANDLER" Seq=58 Len=18]
debug 2024-09-06 14:49:09zh:ember:ezsp: ezspIncomingRouteRecordHandler(): callback called with: [source=58203], [sourceEui=0x001788010ca0d6b9], [lastHopLqi=112], [lastHopRssi=-72], [relayCount=0], [relayList=]
debug 2024-09-06 14:49:09zh:ember:uart:ash: <--- [FRAME type=DATA]
debug 2024-09-06 14:49:09zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=3](ackRx=3 frmTx=3)
debug 2024-09-06 14:49:09zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=3 frmNum=6](frmRx=6) Added to rxQueue
debug 2024-09-06 14:49:09zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=7](ackRx=3)
debug 2024-09-06 14:49:09zh:ember:ezsp: <=== [CBFRAME: ID=69:"INCOMING_MESSAGE_HANDLER" Seq=58 Len=37]
debug 2024-09-06 14:49:09zh:ember:ezsp: ezspIncomingMessageHandler(): callback called with: [type=UNICAST], [apsFrame={"profileId":260,"clusterId":25,"sourceEndpoint":11,"destinationEndpoint":1,"options":256,"groupId":0,"sequence":211}], [packetInfo:{"senderShortId":58203,"senderLongId":"0xFFFFFFFFFFFFFFFF","bindingIndex":255,"addressIndex":255,"lastHopLqi":108,"lastHopRssi":-73,"lastHopTimestamp":0}], [messageContents=01e201000b101a01000e0001]
debug 2024-09-06 14:49:09zh:controller: Received payload: clusterID=25, address=58203, groupID=0, endpoint=11, destinationEndpoint=1, wasBroadcast=false, linkQuality=108, frame={"header":{"frameControl":{"frameType":1,"manufacturerSpecific":false,"direction":0,"disableDefaultResponse":false,"reservedBits":0},"transactionSequenceNumber":226,"commandIdentifier":1},"payload":{"fieldControl":0,"manufacturerCode":4107,"imageType":282,"fileVersion":16780800},"command":{"ID":1,"response":2,"parameters":[{"name":"fieldControl","type":32},{"name":"manufacturerCode","type":33},{"name":"imageType","type":33},{"name":"fileVersion","type":35}],"name":"queryNextImageRequest"}}
debug 2024-09-06 14:49:09z2m: Received Zigbee message from 'Hue Plug', type 'commandQueryNextImageRequest', cluster 'genOta', data '{"fieldControl":0,"fileVersion":16780800,"imageType":282,"manufacturerCode":4107}' from endpoint 11 with groupID 0
info 2024-09-06 14:49:09z2m:mqtt: MQTT publish: topic 'zigbee2mqtt/Hue Plug', payload '{"last_seen":"2024-09-06T14:49:06+02:00","linkquality":108,"state":"OFF","update":{"installed_version":16780800,"latest_version":16780800,"state":"idle"},"update_available":null}'
debug 2024-09-06 14:49:09zhc:ota:common: Got request '{"fieldControl":0,"manufacturerCode":4107,"imageType":282,"fileVersion":16780800}'
debug 2024-09-06 14:49:09zhc:ota:common: Is new image available for '0x001788010ca0d6b9' (LOM007), current '{"fieldControl":0,"manufacturerCode":4107,"imageType":282,"fileVersion":16780800}'
debug 2024-09-06 14:49:09zhc:ota: Getting image metadata for 'LOM007'
info 2024-09-06 14:49:14z2m:mqtt: MQTT publish: topic 'zigbee2mqtt/bridge/response/device/ota_update/check', payload '{"data":{"id":"Hue Plug"},"error":"Failed to check if update available for 'Hue Plug' (Cannot destructure property 'data' of '(intermediate value)' as it is undefined.)","status":"error","transaction":"8dehz-2"}'
error 2024-09-06 14:49:14z2m: Failed to check if update available for 'Hue Plug' (Cannot destructure property 'data' of '(intermediate value)' as it is undefined.)
debug 2024-09-06 14:49:14z2m: TypeError: Cannot destructure property 'data' of '(intermediate value)' as it is undefined. at getIndex (/app/node_modules/zigbee-herdsman-converters/src/lib/ota/zigbeeOTA.ts:40:18) at processTicksAndRejections (node:internal/process/task_queues:95:5) at getImageMeta (/app/node_modules/zigbee-herdsman-converters/src/lib/ota/zigbeeOTA.ts:59:20) at Object.isNewImageAvailable (/app/node_modules/zigbee-herdsman-converters/src/lib/ota/common.ts:529:18) at Object.isUpdateAvailable (/app/node_modules/zigbee-herdsman-converters/src/lib/ota/common.ts:510:29) at OTAUpdate.onMQTTMessage (/app/lib/extension/otaUpdate.ts:211:45) at EventEmitter.wrappedCallback (/app/lib/eventBus.ts:174:17)

[Koenkk]

What happens if you do a wget https://raw.githubusercontent.com/Koenkk/zigbee-OTA/master/index.json?

[R-ens]

Sorry.... my bad, it was my DNS server. It's running now.

[Nerivec]

[ZDO] Device 'xyz' is only compliant to revision 'pre-21' of the ZigBee specification is a detection during interview for "older devices". Usually when it says 21 or above, those should not cause trouble, but when it says pre-21, those can sometimes create issues (they use an old ZigBee spec that may not like the new protocols in place in later versions, as used by adapters).
This is only an indication. It does not necessarily mean "trouble".

https://www.zigbee2mqtt.io/guide/adapters/emberznet.html#logging-specific-to-this-stack