Been getting some error logs since I updated Zigbee2Mqtt

[felipejfc]

What happened?

Everything was fine but then yesterday I decided to update z2m to latest dev image on docker hub and ever since updating I've been getting error like these in my logs:

[2024-04-16 10:18:48] error:    zh:ezsp:ezsp: Frame changeSourceRouteHandler parsing error: RangeError: Attempt to access memory outside buffer bounds
    at new NodeError (node:internal/errors:405:5)
    at boundsError (node:internal/buffer:86:11)
    at Buffer.readUInt16LE (node:internal/buffer:245:5)
    at Buffer.readUIntLE (node:internal/buffer:182:17)
    at Function.deserialize (/app/node_modules/zigbee-herdsman/src/adapter/ezsp/driver/types/basic.ts:19:67)
    at new EZSPFrameData (/app/node_modules/zigbee-herdsman/src/adapter/ezsp/driver/ezsp.ts:180:54)
    at /app/node_modules/zigbee-herdsman/src/adapter/ezsp/driver/ezsp.ts:154:23
    at Array.every (<anonymous>)
    at Function.createFrame (/app/node_modules/zigbee-herdsman/src/adapter/ezsp/driver/ezsp.ts:148:15)
    at Ezsp.onFrameReceived (/app/node_modules/zigbee-herdsman/src/adapter/ezsp/driver/ezsp.ts:439:35)
[2024-04-16 10:18:48] error:    zh:ezsp:ezsp: Unparsed frame 0xc4. Skipped

[2024-04-16 10:20:46] info:     z2m: Zigbee: disabling joining new devices.
[2024-04-16 10:20:46] error:    zh:controller:greenpower: Received undefined command from '0'
[2024-04-16 10:20:46] info:     z2m: Zigbee: disabling joining new devices.
[2024-04-16 10:20:46] error:    zh:controller:greenpower: Received undefined command from '0'

Apart from updating z2m, the only other thing that changed is I added one of new sensor to my network: https://www.zigbee2mqtt.io/devices/DY-RQ500A.html#dygsm-dy-rq500a

What did you expect to happen?

Errors stop happening.

How to reproduce it (minimal and precise)

No response

Zigbee2MQTT version

1.36.1-dev commit: 172aa74

Adapter firmware version

6.10.3.0 build 297

Adapter

EZSP v8

Setup

Dockerized with latest dev image

Debug log

No response

[og-gh]

I'm facing the same after upgrade to latest DEV: 1.36.1-dev commit: [cdbbe0d]

[Koenkk]

Could you check if this is fixed now in the dev branch?

[felipejfc]

Updated today to "koenkk/zigbee2mqtt:latest-dev" And the error seems to still be present:

Error 2024-04-23 14:23:20Received undefined command from '0'
Error 2024-04-23 14:24:17Frame changeSourceRouteHandler parsing error: RangeError: Attempt to access memory outside buffer bounds at new NodeError (node:internal/errors:405:5) at boundsError (node:internal/buffer:86:11) at Buffer.readUInt16LE (node:internal/buffer:245:5) at Buffer.readUIntLE (node:internal/buffer:182:17) at Function.deserialize (/app/node_modules/zigbee-herdsman/src/adapter/ezsp/driver/types/basic.ts:19:67) at new EZSPFrameData (/app/node_modules/zigbee-herdsman/src/adapter/ezsp/driver/ezsp.ts:180:54) at /app/node_modules/zigbee-herdsman/src/adapter/ezsp/driver/ezsp.ts:154:23 at Array.every (<anonymous>) at Function.createFrame (/app/node_modules/zigbee-herdsman/src/adapter/ezsp/driver/ezsp.ts:148:15) at Ezsp.onFrameReceived (/app/node_modules/zigbee-herdsman/src/adapter/ezsp/driver/ezsp.ts:439:35)
Error 2024-04-23 14:24:17Unparsed frame 0xc4. Skipped

[Koenkk]

could you provide the debug log of this?

See this on how to enable debug logging.

[localboast]

I'm seeing the same error when clikcing Permit Join, just destroyed and reinstalled z2m edge and same result on latest. @Koenkk I'm running HAOS in a VM in Proxmox, if you can give a little more detail around adding the debug to Herdsman at docker run I can try to debug there. Debug in z2m didn't show any additional details.

[og-gh]

Hi Koen,

attached my DEBUG logs

Thanks!

Am Do., 25. Apr. 2024 um 21:31 Uhr schrieb Koen Kanters < @.***>:

could you provide the debug log of this?

See this https://www.zigbee2mqtt.io/guide/usage/debug.html on how to enable debug logging.

— Reply to this email directly, view it on GitHub https://github.com/Koenkk/zigbee2mqtt/issues/22226#issuecomment-2078032368, or unsubscribe https://github.com/notifications/unsubscribe-auth/AX7PQ2K6W3V6CEXAED2HJCLY7FKYXAVCNFSM6AAAAABGJLPHJCVHI2DSMVQWIX3LMV43OSLTON2WKQ3PNVWWK3TUHMZDANZYGAZTEMZWHA . You are receiving this because you are subscribed to this thread.Message ID: @.***>

[2024-04-26 07:47:22] info: z2m: Successfully changed options [2024-04-26 07:47:22] debug: z2m: MQTT publish: topic 'zigbee2mqtt/bridge/response/options', payload '{"data":{"restart_required":false},"status":"ok","transaction":"nzw96-1"}' [2024-04-26 07:47:25] info: zh:ezsp:ezsp: Time to watchdog ... 0 [2024-04-26 07:47:25] info: zh:ezsp:ezsp: ==> nop: null [2024-04-26 07:47:25] info: zh:ezsp:ezsp: ==> {"cls":"nop","id":5,"isRequest":true} [2024-04-26 07:47:25] debug: zh:ezsp:uart: --> DATA (7,3,0): 1f00010500 [2024-04-26 07:47:25] debug: zh:ezsp:uart: --> [735d21a9512a6b757e] [2024-04-26 07:47:25] debug: zh:ezsp:uart: -?- waiting (0) [2024-04-26 07:47:25] debug: zh:ezsp:uart: <-- [305da1a9512a12bd7e] [2024-04-26 07:47:25] debug: zh:ezsp:uart: <-- DATA (3,0,0): 305da1a9512a12bd7e [2024-04-26 07:47:25] debug: zh:ezsp:uart: --> ACK (4) [2024-04-26 07:47:25] debug: zh:ezsp:uart: --> [8430fc7e] [2024-04-26 07:47:25] debug: zh:ezsp:uart: <-- ACK (0): 305da1a9512a12bd7e [2024-04-26 07:47:25] info: zh:ezsp:ezsp: <== Frame: 1f80010500 [2024-04-26 07:47:25] info: zh:ezsp:ezsp: <== 0x5: {"cls":"nop","id":5,"isRequest":false} [2024-04-26 07:47:25] debug: zh:ezsp:uart: -+- waiting (0) success [2024-04-26 07:47:26] debug: zh:ezsp:uart: <-- [405db1a97d312a7d31b259924a25aa55] [2024-04-26 07:47:26] debug: zh:ezsp:uart: <-- [93499ca97b7d3819c69874f4ba9e76f8] [2024-04-26 07:47:26] debug: zh:ezsp:uart: <-- [7f3ebeebcdda85f17e] [2024-04-26 07:47:26] debug: zh:ezsp:uart: <-- DATA (4,0,0): 405db1a9112a11b259924a25aa5593499ca97b1819c69874f4ba9e76f87f3ebeebcdda85f17e [2024-04-26 07:47:26] debug: zh:ezsp:uart: --> ACK (5) [2024-04-26 07:47:26] debug: zh:ezsp:uart: --> [8520dd7e] [2024-04-26 07:47:26] debug: zh:ezsp:uart: <-- ACK (0): 405db1a9112a11b259924a25aa5593499ca97b1819c69874f4ba9e76f87f3ebeebcdda85f17e [2024-04-26 07:47:26] info: zh:ezsp:ezsp: <== Frame: 1f900145000400000600000000010000e75cb3f408ffff097cfdff04010119000004 [2024-04-26 07:47:26] info: zh:ezsp:ezsp: <== 0x45: {"cls":"incomingMessageHandler","id":69,"isRequest":false,"type":4,"apsFrame":{"profileId":0,"sequence":231,"clusterId":6,"sourceEndpoint":0,"destinationEndpoint":0,"groupId":0,"options":256},"lastHopLqi":92,"lastHopRssi":-77,"sender":2292,"bindingIndex":255,"addressIndex":255,"message":{"type":"Buffer","data":[124,253,255,4,1,1,25,0,0]}} [2024-04-26 07:47:26] debug: zh:ezsp: processMessage: {"messageType":4,"apsFrame":{"profileId":0,"sequence":231,"clusterId":6,"sourceEndpoint":0,"destinationEndpoint":0,"groupId":0,"options":256},"lqi":92,"rssi":-77,"sender":2292,"bindingIndex":255,"addressIndex":255,"message":{"type":"Buffer","data":[124,253,255,4,1,1,25,0,0]}} [2024-04-26 07:47:26] debug: zh:ezsp:uart: <-- [505db1a90d2ae1ba46df5625aaed43b9] [2024-04-26 07:47:26] debug: zh:ezsp:uart: <-- [14f02616095e037e] [2024-04-26 07:47:26] debug: zh:ezsp:uart: <-- DATA (5,0,0): 505db1a90d2ae1ba46df5625aaed43b914f02616095e037e [2024-04-26 07:47:26] debug: zh:ezsp:uart: --> ACK (6) [2024-04-26 07:47:26] debug: zh:ezsp:uart: --> [8610be7e] [2024-04-26 07:47:26] debug: zh:ezsp:uart: <-- ACK (0): 505db1a90d2ae1ba46df5625aaed43b914f02616095e037e [2024-04-26 07:47:26] info: zh:ezsp:ezsp: <== Frame: 1f90015900f4081f4b1c0000b8d1f088be01bde4 [2024-04-26 07:47:26] info: zh:ezsp:ezsp: <== 0x59: {"cls":"incomingRouteRecordHandler","id":89,"isRequest":false,"source":2292,"longId":{"type":"Buffer","data":[240,209,184,0,0,28,75,31]},"lastHopLqi":136,"lastHopRssi":-66,"relay":{"type":"Buffer","data":[189]}} [2024-04-26 07:47:26] info: zh:ezsp:driver: handleRouteRecord: nwk=2292, ieee=�ѸK, lqi=136, rssi=-66, relays=� [2024-04-26 07:47:27] debug: zh:controller:endpoint: ZCL command 0xf0d1b800001c4b1f/1 genBasic.read(["zclVersion"], {"timeout":10000,"disableResponse":false,"disableRecovery":true,"disableDefaultResponse":true,"direction":0,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":null,"writeUndiv":false}) [2024-04-26 07:47:27] debug: zh:ezsp: sendZclFrameToEndpointInternal 0xf0d1b800001c4b1f:2292/1 (0,0,1), timeout=10000 [2024-04-26 07:47:27] info: zh:ezsp:ezsp: ==> sendUnicast: {"type":0,"indexOrDestination":2292,"apsFrame":{"profileId":260,"sequence":111,"clusterId":0,"sourceEndpoint":1,"destinationEndpoint":1,"groupId":0,"options":256},"messageTag":112,"message":{"type":"Buffer","data":[16,80,0,0,0]}} [2024-04-26 07:47:27] info: zh:ezsp:ezsp: ==> {"cls":"sendUnicast","id":52,"isRequest":true,"type":0,"indexOrDestination":2292,"apsFrame":{"profileId":260,"sequence":111,"clusterId":0,"sourceEndpoint":1,"destinationEndpoint":1,"groupId":0,"options":256},"messageTag":112,"message":{"type":"Buffer","data":[16,80,0,0,0]}} [2024-04-26 07:47:27] debug: zh:ezsp:uart: --> DATA (0,6,0): 200001340000f408040100000101000100006f70051050000000 [2024-04-26 07:47:27] debug: zh:ezsp:uart: --> [066221a9602a154651904b25aa5493499d4e27c49dcb77dbfdc66399017e] [2024-04-26 07:47:27] debug: zh:ezsp:uart: -?- waiting (1) [2024-04-26 07:47:27] debug: zh:ezsp:uart: <-- [6162a1a9602a15f445f47e] [2024-04-26 07:47:27] debug: zh:ezsp:uart: <-- DATA (6,1,0): 6162a1a9602a15f445f47e [2024-04-26 07:47:27] debug: zh:ezsp:uart: --> ACK (7) [2024-04-26 07:47:27] debug: zh:ezsp:uart: --> [87009f7e] [2024-04-26 07:47:27] debug: zh:ezsp:uart: <-- ACK (1): 6162a1a9602a15f445f47e [2024-04-26 07:47:27] info: zh:ezsp:ezsp: <== Frame: 20800134000046 [2024-04-26 07:47:27] info: zh:ezsp:ezsp: <== 0x34: {"cls":"sendUnicast","id":52,"isRequest":false,"status":0,"sequence":70} [2024-04-26 07:47:27] debug: zh:ezsp:uart: -+- waiting (1) success [2024-04-26 07:47:27] debug: zh:ezsp:uart: <-- [7162b5a96b2a154651904b25aa549349] [2024-04-26 07:47:27] debug: zh:ezsp:uart: <-- [9d4e27ed9dce672f3b7e] [2024-04-26 07:47:27] debug: zh:ezsp:uart: <-- DATA (7,1,0): 7162b5a96b2a154651904b25aa5493499d4e27ed9dce672f3b7e [2024-04-26 07:47:27] debug: zh:ezsp:uart: --> ACK (0) [2024-04-26 07:47:27] debug: zh:ezsp:uart: --> [8070787e] [2024-04-26 07:47:27] debug: zh:ezsp:uart: <-- ACK (1): 7162b5a96b2a154651904b25aa5493499d4e27ed9dce672f3b7e [2024-04-26 07:47:27] info: zh:ezsp:ezsp: <== Frame: 2094013f0000f4080401000001010001000046700000 [2024-04-26 07:47:27] info: zh:ezsp:ezsp: <== 0x3f: {"cls":"messageSentHandler","id":63,"isRequest":false,"type":0,"indexOrDestination":2292,"apsFrame":{"profileId":260,"sequence":70,"clusterId":0,"sourceEndpoint":1,"destinationEndpoint":1,"groupId":0,"options":256},"messageTag":112,"status":0,"message":{"type":"Buffer","data":[]}} [2024-04-26 07:47:27] debug: zh:ezsp:uart: <-- [0162b1a96b2a7d334fa6944a23aa5592499d4e274c12ce676b0a7e] [2024-04-26 07:47:27] debug: zh:ezsp:uart: <-- DATA (0,1,0): 0162b1a96b2a134fa6944a23aa5592499d4e274c12ce676b0a7e [2024-04-26 07:47:27] debug: zh:ezsp:uart: --> ACK (1) [2024-04-26 07:47:27] debug: zh:ezsp:uart: --> [8160597e] [2024-04-26 07:47:27] debug: zh:ezsp:uart: <-- ACK (1): 0162b1a96b2a134fa6944a23aa5592499d4e274c12ce676b0a7e [2024-04-26 07:47:27] info: zh:ezsp:ezsp: <== Frame: 2090013f0006fdff00000600000000010000e7ff0000 [2024-04-26 07:47:27] info: zh:ezsp:ezsp: <== 0x3f: {"cls":"messageSentHandler","id":63,"isRequest":false,"type":6,"indexOrDestination":65533,"apsFrame":{"profileId":0,"sequence":231,"clusterId":6,"sourceEndpoint":0,"destinationEndpoint":0,"groupId":0,"options":256},"messageTag":255,"status":0,"message":{"type":"Buffer","data":[]}} [2024-04-26 07:47:27] debug: zh:ezsp:uart: <-- [7d3162b1a97d312a15b658944a24ab15] [2024-04-26 07:47:27] debug: zh:ezsp:uart: <-- [93499ca6af1519c69874f5ce3388fc7d] [2024-04-26 07:47:27] debug: zh:ezsp:uart: <-- [5e3f87e8c9fab77e] [2024-04-26 07:47:27] debug: zh:ezsp:uart: <-- DATA (1,1,0): 1162b1a9112a15b658944a24ab1593499ca6af1519c69874f5ce3388fc7e3f87e8c9fab77e [2024-04-26 07:47:27] debug: zh:ezsp:uart: --> ACK (2) [2024-04-26 07:47:27] debug: zh:ezsp:uart: --> [82503a7e] [2024-04-26 07:47:27] debug: zh:ezsp:uart: <-- ACK (1): 1162b1a9112a15b658944a24ab1593499ca6af1519c69874f5ce3388fc7e3f87e8c9fab77e [2024-04-26 07:47:27] info: zh:ezsp:ezsp: <== Frame: 20900145000004010000010140010000e888bef408ffff08085001000000200304 [2024-04-26 07:47:27] info: zh:ezsp:ezsp: <== 0x45: {"cls":"incomingMessageHandler","id":69,"isRequest":false,"type":0,"apsFrame":{"profileId":260,"sequence":232,"clusterId":0,"sourceEndpoint":1,"destinationEndpoint":1,"groupId":0,"options":320},"lastHopLqi":136,"lastHopRssi":-66,"sender":2292,"bindingIndex":255,"addressIndex":255,"message":{"type":"Buffer","data":[8,80,1,0,0,0,32,3]}} [2024-04-26 07:47:27] debug: zh:ezsp: processMessage: {"messageType":0,"apsFrame":{"profileId":260,"sequence":232,"clusterId":0,"sourceEndpoint":1,"destinationEndpoint":1,"groupId":0,"options":320},"lqi":136,"rssi":-66,"sender":2292,"bindingIndex":255,"addressIndex":255,"message":{"type":"Buffer","data":[8,80,1,0,0,0,32,3]}} [2024-04-26 07:47:27] debug: zh:controller: Received 'zcl' data '{"frame":{"Header":{"frameControl":{"frameType":0,"manufacturerSpecific":false,"direction":1,"disableDefaultResponse":false,"reservedBits":0},"transactionSequenceNumber":80,"manufacturerCode":null,"commandIdentifier":1},"Payload":[{"attrId":0,"status":0,"dataType":32,"attrData":3}],"Command":{"ID":1,"name":"readRsp","parameters":[{"name":"attrId","type":33},{"name":"status","type":32},{"name":"dataType","type":32,"conditions":[{"type":"statusEquals","value":0}]},{"name":"attrData","type":1000,"conditions":[{"type":"statusEquals","value":0}]}]}},"address":2292,"endpoint":1,"linkquality":136,"groupID":0,"wasBroadcast":false,"destinationEndpoint":1}' [2024-04-26 07:47:27] debug: zh:controller:endpoint: ZCL command 0xf0d1b800001c4b1f/1 genBasic.defaultRsp({"cmdId":1,"statusCode":0}, {"timeout":10000,"disableResponse":false,"disableRecovery":false,"disableDefaultResponse":true,"direction":1,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":80,"writeUndiv":false}) [2024-04-26 07:47:27] debug: z2m: Received Zigbee message from 'Ledvance_Garage', type 'readResponse', cluster 'genBasic', data '{"zclVersion":3}' from endpoint 1 with groupID 0 [2024-04-26 07:47:27] debug: zh:ezsp: sendZclFrameToEndpointInternal 0xf0d1b800001c4b1f:2292/1 (0,0,1), timeout=10000 [2024-04-26 07:47:27] info: zh:ezsp:ezsp: ==> sendUnicast: {"type":0,"indexOrDestination":2292,"apsFrame":{"profileId":260,"sequence":112,"clusterId":0,"sourceEndpoint":1,"destinationEndpoint":1,"groupId":0,"options":256},"messageTag":113,"message":{"type":"Buffer","data":[24,80,11,1,0]}} [2024-04-26 07:47:27] info: zh:ezsp:ezsp: ==> {"cls":"sendUnicast","id":52,"isRequest":true,"type":0,"indexOrDestination":2292,"apsFrame":{"profileId":260,"sequence":112,"clusterId":0,"sourceEndpoint":1,"destinationEndpoint":1,"groupId":0,"options":256},"messageTag":113,"message":{"type":"Buffer","data":[24,80,11,1,0]}} [2024-04-26 07:47:27] debug: zh:ezsp:uart: --> DATA (1,2,0): 210001340000f4080401000001010001000070710518500b0100 [2024-04-26 07:47:27] debug: zh:ezsp:uart: --> [126321a9602a154651904b25aa5493499d4e27db9ccb7fdbf6c763bb437e] [2024-04-26 07:47:27] debug: zh:ezsp:uart: -?- waiting (2) [2024-04-26 07:47:27] debug: z2m: Successfully pinged 'Ledvance_Garage' (attempt 1/2) [2024-04-26 07:47:27] debug: zh:ezsp:uart: <-- [2263a1a9602a15f5d37d317e] [2024-04-26 07:47:27] debug: zh:ezsp:uart: <-- DATA (2,2,0): 2263a1a9602a15f5d3117e [2024-04-26 07:47:27] debug: zh:ezsp:uart: --> ACK (3) [2024-04-26 07:47:27] debug: zh:ezsp:uart: --> [83401b7e] [2024-04-26 07:47:27] debug: zh:ezsp:uart: <-- ACK (2): 2263a1a9602a15f5d3117e [2024-04-26 07:47:27] info: zh:ezsp:ezsp: <== Frame: 21800134000047 [2024-04-26 07:47:27] info: zh:ezsp:ezsp: <== 0x34: {"cls":"sendUnicast","id":52,"isRequest":false,"status":0,"sequence":71} [2024-04-26 07:47:27] debug: zh:ezsp:uart: -+- waiting (2) success [2024-04-26 07:47:27] debug: zh:ezsp:uart: <-- [3263b1a96b2a154651904b25aa549349] [2024-04-26 07:47:27] debug: zh:ezsp:uart: <-- [9d4e27ec9cce670a197e] [2024-04-26 07:47:27] debug: zh:ezsp:uart: <-- DATA (3,2,0): 3263b1a96b2a154651904b25aa5493499d4e27ec9cce670a197e [2024-04-26 07:47:27] debug: zh:ezsp:uart: --> ACK (4) [2024-04-26 07:47:27] debug: zh:ezsp:uart: --> [8430fc7e] [2024-04-26 07:47:27] debug: zh:ezsp:uart: <-- ACK (2): 3263b1a96b2a154651904b25aa5493499d4e27ec9cce670a197e [2024-04-26 07:47:27] info: zh:ezsp:ezsp: <== Frame: 2190013f0000f4080401000001010001000047710000 [2024-04-26 07:47:27] info: zh:ezsp:ezsp: <== 0x3f: {"cls":"messageSentHandler","id":63,"isRequest":false,"type":0,"indexOrDestination":2292,"apsFrame":{"profileId":260,"sequence":71,"clusterId":0,"sourceEndpoint":1,"destinationEndpoint":1,"groupId":0,"options":256},"messageTag":113,"status":0,"message":{"type":"Buffer","data":[]}} [2024-04-26 07:47:27] debug: zh:ezsp:uart: <-- [4263b1a90d2ade914412017f896d53ed] [2024-04-26 07:47:27] debug: zh:ezsp:uart: <-- [d4e026e974b1357e] [2024-04-26 07:47:27] debug: zh:ezsp:uart: <-- DATA (4,2,0): 4263b1a90d2ade914412017f896d53edd4e026e974b1357e [2024-04-26 07:47:27] debug: zh:ezsp:uart: --> ACK (5) [2024-04-26 07:47:27] debug: zh:ezsp:uart: --> [8520dd7e] [2024-04-26 07:47:27] debug: zh:ezsp:uart: <-- ACK (2): 4263b1a90d2ade914412017f896d53edd4e026e974b1357e [2024-04-26 07:47:27] info: zh:ezsp:ezsp: <== Frame: 2190015900cb231d864b5a2338c1a448ae014299 [2024-04-26 07:47:27] info: zh:ezsp:ezsp: <== 0x59: {"cls":"incomingRouteRecordHandler","id":89,"isRequest":false,"source":9163,"longId":{"type":"Buffer","data":[164,193,56,35,90,75,134,29]},"lastHopLqi":72,"lastHopRssi":-82,"relay":{"type":"Buffer","data":[66]}} [2024-04-26 07:47:27] info: zh:ezsp:driver: handleRouteRecord: nwk=9163, ieee=��8#ZK�, lqi=72, rssi=-82, relays=B [2024-04-26 07:47:27] debug: zh:ezsp:uart: <-- [5263b1a97d312a15b658904124ab5593] [2024-04-26 07:47:27] debug: zh:ezsp:uart: <-- [499c9a6b0426ed9874efce5a83f97b1e] [2024-04-26 07:47:27] debug: zh:ezsp:uart: <-- [40ebc5db4e8fffccdefcd2698800a37e] [2024-04-26 07:47:27] debug: zh:ezsp:uart: <-- DATA (5,2,0): 5263b1a9112a15b658904124ab5593499c9a6b0426ed9874efce5a83f97b1e40ebc5db4e8fffccdefcd2698800a37e [2024-04-26 07:47:27] debug: zh:ezsp:uart: --> ACK (6) [2024-04-26 07:47:27] debug: zh:ezsp:uart: --> [8610be7e] [2024-04-26 07:47:27] debug: zh:ezsp:uart: <-- ACK (2): 5263b1a9112a15b658904124ab5593499c9a6b0426ed9874efce5a83f97b1e40ebc5db4e8fffccdefcd2698800a37e [2024-04-26 07:47:27] info: zh:ezsp:ezsp: <== Frame: 2190014500000401040b010100010000d44cafcb23ffff1208390a050521e70008052100000b0529000004 [2024-04-26 07:47:27] info: zh:ezsp:ezsp: <== 0x45: {"cls":"incomingMessageHandler","id":69,"isRequest":false,"type":0,"apsFrame":{"profileId":260,"sequence":212,"clusterId":2820,"sourceEndpoint":1,"destinationEndpoint":1,"groupId":0,"options":256},"lastHopLqi":76,"lastHopRssi":-81,"sender":9163,"bindingIndex":255,"addressIndex":255,"message":{"type":"Buffer","data":[8,57,10,5,5,33,231,0,8,5,33,0,0,11,5,41,0,0]}} [2024-04-26 07:47:27] debug: zh:ezsp: processMessage: {"messageType":0,"apsFrame":{"profileId":260,"sequence":212,"clusterId":2820,"sourceEndpoint":1,"destinationEndpoint":1,"groupId":0,"options":256},"lqi":76,"rssi":-81,"sender":9163,"bindingIndex":255,"addressIndex":255,"message":{"type":"Buffer","data":[8,57,10,5,5,33,231,0,8,5,33,0,0,11,5,41,0,0]}} [2024-04-26 07:47:27] debug: zh:controller: Received 'zcl' data '{"frame":{"Header":{"frameControl":{"frameType":0,"manufacturerSpecific":false,"direction":1,"disableDefaultResponse":false,"reservedBits":0},"transactionSequenceNumber":57,"manufacturerCode":null,"commandIdentifier":10},"Payload":[{"attrId":1285,"dataType":33,"attrData":231},{"attrId":1288,"dataType":33,"attrData":0},{"attrId":1291,"dataType":41,"attrData":0}],"Command":{"ID":10,"name":"report","parameters":[{"name":"attrId","type":33},{"name":"dataType","type":32},{"name":"attrData","type":1000}]}},"address":9163,"endpoint":1,"linkquality":76,"groupID":0,"wasBroadcast":false,"destinationEndpoint":1}' [2024-04-26 07:47:27] debug: zh:controller:endpoint: ZCL command 0xa4c138235a4b861d/1 haElectricalMeasurement.defaultRsp({"cmdId":10,"statusCode":0}, {"timeout":10000,"disableResponse":false,"disableRecovery":false,"disableDefaultResponse":true,"direction":1,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":57,"writeUndiv":false}) [2024-04-26 07:47:27] debug: zh:ezsp: sendZclFrameToEndpointInternal 0xa4c138235a4b861d:9163/1 (0,0,1), timeout=10000 [2024-04-26 07:47:27] debug: z2m: Received Zigbee message from 'Tuya_Infrarotheizung', type 'attributeReport', cluster 'haElectricalMeasurement', data '{"activePower":0,"rmsCurrent":0,"rmsVoltage":231}' from endpoint 1 with groupID 0 [2024-04-26 07:47:27] info: zh:ezsp:ezsp: ==> sendUnicast: {"type":0,"indexOrDestination":9163,"apsFrame":{"profileId":260,"sequence":113,"clusterId":2820,"sourceEndpoint":1,"destinationEndpoint":1,"groupId":0,"options":256},"messageTag":114,"message":{"type":"Buffer","data":[24,57,11,10,0]}} [2024-04-26 07:47:27] info: zh:ezsp:ezsp: ==> {"cls":"sendUnicast","id":52,"isRequest":true,"type":0,"indexOrDestination":9163,"apsFrame":{"profileId":260,"sequence":113,"clusterId":2820,"sourceEndpoint":1,"destinationEndpoint":1,"groupId":0,"options":256},"messageTag":114,"message":{"type":"Buffer","data":[24,57,11,10,0]}} [2024-04-26 07:47:27] debug: zh:ezsp:uart: --> DATA (2,6,0): 220001340000cb230401040b01010001000071720518390b0a00 [2024-04-26 07:47:27] debug: zh:ezsp:uart: --> [266021a9602a15797a904b21a15493499d4e27da9fcb7fb2f6cc6367f77e] [2024-04-26 07:47:27] debug: zh:ezsp:uart: -?- waiting (3) [2024-04-26 07:47:27] debug: z2m: MQTT publish: topic 'zigbee2mqtt/Tuya_Infrarotheizung', payload '{"child_lock":"UNLOCK","current":0,"energy":4.55,"linkquality":76,"power":0,"state":"OFF","update":{"installed_version":192,"latest_version":192,"state":"idle"},"update_available":false,"voltage":231}' [2024-04-26 07:47:27] debug: zh:ezsp:uart: <-- [6360a1a9602a15fa4b7f7e] [2024-04-26 07:47:27] debug: zh:ezsp:uart: <-- DATA (6,3,0): 6360a1a9602a15fa4b7f7e [2024-04-26 07:47:27] debug: zh:ezsp:uart: --> ACK (7) [2024-04-26 07:47:27] debug: zh:ezsp:uart: --> [87009f7e] [2024-04-26 07:47:27] debug: zh:ezsp:uart: <-- ACK (3): 6360a1a9602a15fa4b7f7e [2024-04-26 07:47:27] info: zh:ezsp:ezsp: <== Frame: 22800134000048 [2024-04-26 07:47:27] info: zh:ezsp:ezsp: <== 0x34: {"cls":"sendUnicast","id":52,"isRequest":false,"status":0,"sequence":72} [2024-04-26 07:47:27] debug: zh:ezsp:uart: -+- waiting (3) success [2024-04-26 07:47:27] debug: zh:ezsp:uart: <-- [7360b1a96b2a15797a904b21a1549349] [2024-04-26 07:47:27] debug: zh:ezsp:uart: <-- [9d4e27e39fce6707cc7e] [2024-04-26 07:47:27] debug: zh:ezsp:uart: <-- DATA (7,3,0): 7360b1a96b2a15797a904b21a15493499d4e27e39fce6707cc7e [2024-04-26 07:47:27] debug: zh:ezsp:uart: --> ACK (0) [2024-04-26 07:47:27] debug: zh:ezsp:uart: --> [8070787e] [2024-04-26 07:47:27] debug: zh:ezsp:uart: <-- ACK (3): 7360b1a96b2a15797a904b21a15493499d4e27e39fce6707cc7e [2024-04-26 07:47:27] info: zh:ezsp:ezsp: <== Frame: 2290013f0000cb230401040b01010001000048720000 [2024-04-26 07:47:27] info: zh:ezsp:ezsp: <== 0x3f: {"cls":"messageSentHandler","id":63,"isRequest":false,"type":0,"indexOrDestination":9163,"apsFrame":{"profileId":260,"sequence":72,"clusterId":2820,"sourceEndpoint":1,"destinationEndpoint":1,"groupId":0,"options":256},"messageTag":114,"status":0,"message":{"type":"Buffer","data":[]}} [2024-04-26 07:47:27] debug: zh:ezsp:uart: <-- [0360b1a97d312a15b658964d24ab5593] [2024-04-26 07:47:27] debug: zh:ezsp:uart: <-- [499c9b6b0426ed9874f1ce5983fc7d5e] [2024-04-26 07:47:27] debug: zh:ezsp:uart: <-- [7d3a60eacdde6f8ffba8287e] [2024-04-26 07:47:27] debug: zh:ezsp:uart: <-- DATA (0,3,0): 0360b1a9112a15b658964d24ab5593499c9b6b0426ed9874f1ce5983fc7e1a60eacdde6f8ffba8287e [2024-04-26 07:47:27] debug: zh:ezsp:uart: --> ACK (1) [2024-04-26 07:47:27] debug: zh:ezsp:uart: --> [8160597e] [2024-04-26 07:47:27] debug: zh:ezsp:uart: <-- ACK (3): 0360b1a9112a15b658964d24ab5593499c9b6b0426ed9874f1ce5983fc7e1a60eacdde6f8ffba8287e [2024-04-26 07:47:27] info: zh:ezsp:ezsp: <== Frame: 22900145000004010207010100010000d54cafcb23ffff0c083a0a000025c7010000000004 [2024-04-26 07:47:27] info: zh:ezsp:ezsp: <== 0x45: {"cls":"incomingMessageHandler","id":69,"isRequest":false,"type":0,"apsFrame":{"profileId":260,"sequence":213,"clusterId":1794,"sourceEndpoint":1,"destinationEndpoint":1,"groupId":0,"options":256},"lastHopLqi":76,"lastHopRssi":-81,"sender":9163,"bindingIndex":255,"addressIndex":255,"message":{"type":"Buffer","data":[8,58,10,0,0,37,199,1,0,0,0,0]}} [2024-04-26 07:47:27] debug: zh:ezsp: processMessage: {"messageType":0,"apsFrame":{"profileId":260,"sequence":213,"clusterId":1794,"sourceEndpoint":1,"destinationEndpoint":1,"groupId":0,"options":256},"lqi":76,"rssi":-81,"sender":9163,"bindingIndex":255,"addressIndex":255,"message":{"type":"Buffer","data":[8,58,10,0,0,37,199,1,0,0,0,0]}} [2024-04-26 07:47:27] debug: zh:controller: Received 'zcl' data '{"frame":{"Header":{"frameControl":{"frameType":0,"manufacturerSpecific":false,"direction":1,"disableDefaultResponse":false,"reservedBits":0},"transactionSequenceNumber":58,"manufacturerCode":null,"commandIdentifier":10},"Payload":[{"attrId":0,"dataType":37,"attrData":[0,455]}],"Command":{"ID":10,"name":"report","parameters":[{"name":"attrId","type":33},{"name":"dataType","type":32},{"name":"attrData","type":1000}]}},"address":9163,"endpoint":1,"linkquality":76,"groupID":0,"wasBroadcast":false,"destinationEndpoint":1}' [2024-04-26 07:47:27] debug: zh:controller:endpoint: ZCL command 0xa4c138235a4b861d/1 seMetering.defaultRsp({"cmdId":10,"statusCode":0}, {"timeout":10000,"disableResponse":false,"disableRecovery":false,"disableDefaultResponse":true,"direction":1,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":58,"writeUndiv":false}) [2024-04-26 07:47:27] debug: zh:ezsp: sendZclFrameToEndpointInternal 0xa4c138235a4b861d:9163/1 (0,0,1), timeout=10000 [2024-04-26 07:47:27] debug: z2m: Received Zigbee message from 'Tuya_Infrarotheizung', type 'attributeReport', cluster 'seMetering', data '{"currentSummDelivered":[0,455]}' from endpoint 1 with groupID 0 [2024-04-26 07:47:27] info: zh:ezsp:ezsp: ==> sendUnicast: {"type":0,"indexOrDestination":9163,"apsFrame":{"profileId":260,"sequence":114,"clusterId":1794,"sourceEndpoint":1,"destinationEndpoint":1,"groupId":0,"options":256},"messageTag":115,"message":{"type":"Buffer","data":[24,58,11,10,0]}} [2024-04-26 07:47:27] info: zh:ezsp:ezsp: ==> {"cls":"sendUnicast","id":52,"isRequest":true,"type":0,"indexOrDestination":9163,"apsFrame":{"profileId":260,"sequence":114,"clusterId":1794,"sourceEndpoint":1,"destinationEndpoint":1,"groupId":0,"options":256},"messageTag":115,"message":{"type":"Buffer","data":[24,58,11,10,0]}} [2024-04-26 07:47:27] debug: zh:ezsp:uart: --> DATA (3,1,0): 230001340000cb2304010207010100010000727305183a0b0a00 [2024-04-26 07:47:27] debug: zh:ezsp:uart: --> [316121a9602a15797a904b27ad5493499d4e27d99ecb7fb1f6cc6370617e] [2024-04-26 07:47:27] debug: zh:ezsp:uart: -?- waiting (4) [2024-04-26 07:47:27] debug: z2m: MQTT publish: topic 'zigbee2mqtt/Tuya_Infrarotheizung', payload '{"child_lock":"UNLOCK","current":0,"energy":4.55,"linkquality":76,"power":0,"state":"OFF","update":{"installed_version":192,"latest_version":192,"state":"idle"},"update_available":false,"voltage":231}' [2024-04-26 07:47:27] debug: zh:ezsp:uart: <-- [7d3360b1a90d2aa0ab4fe7e425006b2235bcea27ee107e] [2024-04-26 07:47:27] debug: zh:ezsp:uart: <-- DATA (1,3,0): 1360b1a90d2aa0ab4fe7e425006b2235bcea27ee107e [2024-04-26 07:47:27] debug: zh:ezsp:uart: --> ACK (2) [2024-04-26 07:47:27] debug: zh:ezsp:uart: --> [82503a7e] [2024-04-26 07:47:27] debug: zh:ezsp:uart: <-- ACK (3): 1360b1a90d2aa0ab4fe7e425006b2235bcea27ee107e [2024-04-26 07:47:27] debug: zh:ezsp:uart: Unexpected packet sequence 3 | 4 [2024-04-26 07:47:27] info: zh:ezsp:ezsp: <== Frame: 2290015900b5191673ae00aa3eb07c20a400 [2024-04-26 07:47:27] info: zh:ezsp:ezsp: <== 0x59: {"cls":"incomingRouteRecordHandler","id":89,"isRequest":false,"source":6581,"longId":{"type":"Buffer","data":[124,176,62,170,0,174,115,22]},"lastHopLqi":32,"lastHopRssi":-92,"relay":{"type":"Buffer","data":[]}} [2024-04-26 07:47:27] info: zh:ezsp:driver: handleRouteRecord: nwk=6581, ieee=|�>��s, lqi=32, rssi=-92, relays= [2024-04-26 07:47:27] debug: zh:ezsp:uart: <-- [2360b1a97d312a15b6588d4a26ab1592499c5d030e58d79874f1d79388fc722e80ebdcdb6d8efd98a87e] [2024-04-26 07:47:27] debug: zh:ezsp:uart: <-- DATA (2,3,0): 2360b1a9112a15b6588d4a26ab1592499c5d030e58d79874f1d79388fc722e80ebdcdb6d8efd98a87e [2024-04-26 07:47:27] debug: zh:ezsp:uart: --> ACK (3) [2024-04-26 07:47:27] debug: zh:ezsp:uart: --> [83401b7e] [2024-04-26 07:47:27] debug: zh:ezsp:uart: <-- ACK (3): 2360b1a9112a15b6588d4a26ab1592499c5d030e58d79874f1d79388fc722e80ebdcdb6d8efd98a87e [2024-04-26 07:47:27] debug: zh:ezsp:uart: Unexpected packet sequence 3 | 4 [2024-04-26 07:47:27] info: zh:ezsp:ezsp: <== Frame: 229001450000040119000301400000001324a5b519ffff0c11f001000c1127001105020102 [2024-04-26 07:47:27] info: zh:ezsp:ezsp: <== 0x45: {"cls":"incomingMessageHandler","id":69,"isRequest":false,"type":0,"apsFrame":{"profileId":260,"sequence":19,"clusterId":25,"sourceEndpoint":3,"destinationEndpoint":1,"groupId":0,"options":64},"lastHopLqi":36,"lastHopRssi":-91,"sender":6581,"bindingIndex":255,"addressIndex":255,"message":{"type":"Buffer","data":[17,240,1,0,12,17,39,0,17,5,2,1]}} [2024-04-26 07:47:27] debug: zh:ezsp: processMessage: {"messageType":0,"apsFrame":{"profileId":260,"sequence":19,"clusterId":25,"sourceEndpoint":3,"destinationEndpoint":1,"groupId":0,"options":64},"lqi":36,"rssi":-91,"sender":6581,"bindingIndex":255,"addressIndex":255,"message":{"type":"Buffer","data":[17,240,1,0,12,17,39,0,17,5,2,1]}} [2024-04-26 07:47:27] debug: zh:controller: Received 'zcl' data '{"frame":{"Header":{"frameControl":{"frameType":1,"manufacturerSpecific":false,"direction":0,"disableDefaultResponse":true,"reservedBits":0},"transactionSequenceNumber":240,"manufacturerCode":null,"commandIdentifier":1},"Payload":{"fieldControl":0,"manufacturerCode":4364,"imageType":39,"fileVersion":16909585},"Command":{"ID":1,"response":2,"parameters":[{"name":"fieldControl","type":32},{"name":"manufacturerCode","type":33},{"name":"imageType","type":33},{"name":"fileVersion","type":35}],"name":"queryNextImageRequest"}},"address":6581,"endpoint":3,"linkquality":36,"groupID":0,"wasBroadcast":false,"destinationEndpoint":1}' [2024-04-26 07:47:27] debug: z2m: Received Zigbee message from 'OSRAM_Galerie_rechts', type 'commandQueryNextImageRequest', cluster 'genOta', data '{"fieldControl":0,"fileVersion":16909585,"imageType":39,"manufacturerCode":4364}' from endpoint 3 with groupID 0 [2024-04-26 07:47:27] debug: z2m: Device 'OSRAM_Galerie_rechts' requested OTA [2024-04-26 07:47:27] debug: zh:ezsp:uart: <-- [3461a1a9602a15fbef437e] [2024-04-26 07:47:27] debug: zh:ezsp:uart: <-- DATA (3,4,0): 3461a1a9602a15fbef437e [2024-04-26 07:47:27] debug: zh:ezsp:uart: --> ACK (4) [2024-04-26 07:47:27] debug: zh:ezsp:uart: --> [8430fc7e] [2024-04-26 07:47:27] debug: zh:ezsp:uart: <-- ACK (4): 3461a1a9602a15fbef437e [2024-04-26 07:47:27] info: zh:ezsp:ezsp: <== Frame: 23800134000049 [2024-04-26 07:47:27] info: zh:ezsp:ezsp: <== 0x34: {"cls":"sendUnicast","id":52,"isRequest":false,"status":0,"sequence":73} [2024-04-26 07:47:27] debug: zh:ezsp:uart: -+- waiting (4) success [2024-04-26 07:47:27] debug: zh:ezsp:uart: <-- [4461b1a96b2a15797a904b27ad5493499d4e27e29ece67a8ed7e] [2024-04-26 07:47:27] debug: zh:ezsp:uart: <-- DATA (4,4,0): 4461b1a96b2a15797a904b27ad5493499d4e27e29ece67a8ed7e [2024-04-26 07:47:27] debug: zh:ezsp:uart: --> ACK (5) [2024-04-26 07:47:27] debug: zh:ezsp:uart: --> [8520dd7e] [2024-04-26 07:47:27] debug: zh:ezsp:uart: <-- ACK (4): 4461b1a96b2a15797a904b27ad5493499d4e27e29ece67a8ed7e [2024-04-26 07:47:27] info: zh:ezsp:ezsp: <== Frame: 2390013f0000cb230401020701010001000049730000 [2024-04-26 07:47:27] info: zh:ezsp:ezsp: <== 0x3f: {"cls":"messageSentHandler","id":63,"isRequest":false,"type":0,"indexOrDestination":9163,"apsFrame":{"profileId":260,"sequence":73,"clusterId":1794,"sourceEndpoint":1,"destinationEndpoint":1,"groupId":0,"options":256},"messageTag":115,"status":0,"message":{"type":"Buffer","data":[]}} [2024-04-26 07:47:28] debug: zh:ezsp:uart: <-- [5461b1a97d312a15b6588d4a24ab1592] [2024-04-26 07:47:28] debug: zh:ezsp:uart: <-- [499ca7af1519c69874f3c71b88fdf72e] [2024-04-26 07:47:28] debug: zh:ezsp:uart: <-- [c0eb9dbb6a8dfdc7dfc4797e] [2024-04-26 07:47:28] debug: zh:ezsp:uart: <-- DATA (5,4,0): 5461b1a9112a15b6588d4a24ab1592499ca7af1519c69874f3c71b88fdf72ec0eb9dbb6a8dfdc7dfc4797e [2024-04-26 07:47:28] debug: zh:ezsp:uart: --> ACK (6) [2024-04-26 07:47:28] debug: zh:ezsp:uart: --> [8610be7e] [2024-04-26 07:47:28] debug: zh:ezsp:uart: <-- ACK (4): 5461b1a9112a15b6588d4a24ab1592499ca7af1519c69874f3c71b88fdf72ec0eb9dbb6a8dfdc7dfc4797e [2024-04-26 07:47:28] info: zh:ezsp:ezsp: <== Frame: 23900145000004011900010140000000e988bef408ffff0e017801018911670050650502020004 [2024-04-26 07:47:28] info: zh:ezsp:ezsp: <== 0x45: {"cls":"incomingMessageHandler","id":69,"isRequest":false,"type":0,"apsFrame":{"profileId":260,"sequence":233,"clusterId":25,"sourceEndpoint":1,"destinationEndpoint":1,"groupId":0,"options":64},"lastHopLqi":136,"lastHopRssi":-66,"sender":2292,"bindingIndex":255,"addressIndex":255,"message":{"type":"Buffer","data":[1,120,1,1,137,17,103,0,80,101,5,2,2,0]}} [2024-04-26 07:47:28] debug: zh:ezsp: processMessage: {"messageType":0,"apsFrame":{"profileId":260,"sequence":233,"clusterId":25,"sourceEndpoint":1,"destinationEndpoint":1,"groupId":0,"options":64},"lqi":136,"rssi":-66,"sender":2292,"bindingIndex":255,"addressIndex":255,"message":{"type":"Buffer","data":[1,120,1,1,137,17,103,0,80,101,5,2,2,0]}} [2024-04-26 07:47:28] debug: zh:controller: Received 'zcl' data '{"frame":{"Header":{"frameControl":{"frameType":1,"manufacturerSpecific":false,"direction":0,"disableDefaultResponse":false,"reservedBits":0},"transactionSequenceNumber":120,"manufacturerCode":null,"commandIdentifier":1},"Payload":{"fieldControl":1,"manufacturerCode":4489,"imageType":103,"fileVersion":33908048},"Command":{"ID":1,"response":2,"parameters":[{"name":"fieldControl","type":32},{"name":"manufacturerCode","type":33},{"name":"imageType","type":33},{"name":"fileVersion","type":35}],"name":"queryNextImageRequest"}},"address":2292,"endpoint":1,"linkquality":136,"groupID":0,"wasBroadcast":false,"destinationEndpoint":1}' [2024-04-26 07:47:28] debug: z2m: Received Zigbee message from 'Ledvance_Garage', type 'commandQueryNextImageRequest', cluster 'genOta', data '{"fieldControl":1,"fileVersion":33908048,"imageType":103,"manufacturerCode":4489}' from endpoint 1 with groupID 0 [2024-04-26 07:47:28] debug: z2m: Device 'Ledvance_Garage' requested OTA [2024-04-26 07:47:31] debug: zh:ezsp:uart: <-- [6461b1a90d2ae1ba46df5625aaed43b9] [2024-04-26 07:47:31] debug: zh:ezsp:uart: <-- [14f02616096c4e7e] [2024-04-26 07:47:31] debug: zh:ezsp:uart: <-- DATA (6,4,0): 6461b1a90d2ae1ba46df5625aaed43b914f02616096c4e7e [2024-04-26 07:47:31] debug: zh:ezsp:uart: --> ACK (7) [2024-04-26 07:47:31] debug: zh:ezsp:uart: --> [87009f7e] [2024-04-26 07:47:31] debug: zh:ezsp:uart: <-- ACK (4): 6461b1a90d2ae1ba46df5625aaed43b914f02616096c4e7e [2024-04-26 07:47:31] info: zh:ezsp:ezsp: <== Frame: 2390015900f4081f4b1c0000b8d1f088be01bde4 [2024-04-26 07:47:31] info: zh:ezsp:ezsp: <== 0x59: {"cls":"incomingRouteRecordHandler","id":89,"isRequest":false,"source":2292,"longId":{"type":"Buffer","data":[240,209,184,0,0,28,75,31]},"lastHopLqi":136,"lastHopRssi":-66,"relay":{"type":"Buffer","data":[189]}} [2024-04-26 07:47:31] info: zh:ezsp:driver: handleRouteRecord: nwk=2292, ieee=�ѸK, lqi=136, rssi=-66, relays=� [2024-04-26 07:47:31] debug: zh:ezsp:uart: <-- [7461b1a97d312a15b6588d4a24ab1592] [2024-04-26 07:47:31] debug: zh:ezsp:uart: <-- [499ca4af1519c69874f3c77d3a88fdf7] [2024-04-26 07:47:31] debug: zh:ezsp:uart: <-- [2ec0eb9dbb6a8dfdc7df07197e] [2024-04-26 07:47:31] debug: zh:ezsp:uart: <-- DATA (7,4,0): 7461b1a9112a15b6588d4a24ab1592499ca4af1519c69874f3c71a88fdf72ec0eb9dbb6a8dfdc7df07197e [2024-04-26 07:47:31] debug: zh:ezsp:uart: --> ACK (0) [2024-04-26 07:47:31] debug: zh:ezsp:uart: --> [8070787e] [2024-04-26 07:47:31] debug: zh:ezsp:uart: <-- ACK (4): 7461b1a9112a15b6588d4a24ab1592499ca4af1519c69874f3c71a88fdf72ec0eb9dbb6a8dfdc7df07197e [2024-04-26 07:47:31] info: zh:ezsp:ezsp: <== Frame: 23900145000004011900010140000000ea88bef408ffff0e017901018911670050650502020004 [2024-04-26 07:47:31] info: zh:ezsp:ezsp: <== 0x45: {"cls":"incomingMessageHandler","id":69,"isRequest":false,"type":0,"apsFrame":{"profileId":260,"sequence":234,"clusterId":25,"sourceEndpoint":1,"destinationEndpoint":1,"groupId":0,"options":64},"lastHopLqi":136,"lastHopRssi":-66,"sender":2292,"bindingIndex":255,"addressIndex":255,"message":{"type":"Buffer","data":[1,121,1,1,137,17,103,0,80,101,5,2,2,0]}} [2024-04-26 07:47:31] debug: zh:ezsp: processMessage: {"messageType":0,"apsFrame":{"profileId":260,"sequence":234,"clusterId":25,"sourceEndpoint":1,"destinationEndpoint":1,"groupId":0,"options":64},"lqi":136,"rssi":-66,"sender":2292,"bindingIndex":255,"addressIndex":255,"message":{"type":"Buffer","data":[1,121,1,1,137,17,103,0,80,101,5,2,2,0]}} [2024-04-26 07:47:31] debug: zh:controller: Received 'zcl' data '{"frame":{"Header":{"frameControl":{"frameType":1,"manufacturerSpecific":false,"direction":0,"disableDefaultResponse":false,"reservedBits":0},"transactionSequenceNumber":121,"manufacturerCode":null,"commandIdentifier":1},"Payload":{"fieldControl":1,"manufacturerCode":4489,"imageType":103,"fileVersion":33908048},"Command":{"ID":1,"response":2,"parameters":[{"name":"fieldControl","type":32},{"name":"manufacturerCode","type":33},{"name":"imageType","type":33},{"name":"fileVersion","type":35}],"name":"queryNextImageRequest"}},"address":2292,"endpoint":1,"linkquality":136,"groupID":0,"wasBroadcast":false,"destinationEndpoint":1}' [2024-04-26 07:47:31] debug: z2m: Received Zigbee message from 'Ledvance_Garage', type 'commandQueryNextImageRequest', cluster 'genOta', data '{"fieldControl":1,"fileVersion":33908048,"imageType":103,"manufacturerCode":4489}' from endpoint 1 with groupID 0 [2024-04-26 07:47:31] debug: z2m: Device 'Ledvance_Garage' requested OTA [2024-04-26 07:47:34] debug: zh:ezsp:uart: <-- [0461b1a90d2ae1ba46df5625aaed43b914f02616097a837e] [2024-04-26 07:47:34] debug: zh:ezsp:uart: <-- DATA (0,4,0): 0461b1a90d2ae1ba46df5625aaed43b914f02616097a837e [2024-04-26 07:47:34] debug: zh:ezsp:uart: --> ACK (1) [2024-04-26 07:47:34] debug: zh:ezsp:uart: --> [8160597e] [2024-04-26 07:47:34] debug: zh:ezsp:uart: <-- ACK (4): 0461b1a90d2ae1ba46df5625aaed43b914f02616097a837e [2024-04-26 07:47:34] info: zh:ezsp:ezsp: <== Frame: 2390015900f4081f4b1c0000b8d1f088be01bde4 [2024-04-26 07:47:34] info: zh:ezsp:ezsp: <== 0x59: {"cls":"incomingRouteRecordHandler","id":89,"isRequest":false,"source":2292,"longId":{"type":"Buffer","data":[240,209,184,0,0,28,75,31]},"lastHopLqi":136,"lastHopRssi":-66,"relay":{"type":"Buffer","data":[189]}} [2024-04-26 07:47:34] info: zh:ezsp:driver: handleRouteRecord: nwk=2292, ieee=�ѸK, lqi=136, rssi=-66, relays=� [2024-04-26 07:47:34] debug: zh:ezsp:uart: <-- [1461b1a97d312a15b6588d4a24ab1592] [2024-04-26 07:47:34] debug: zh:ezsp:uart: <-- [499ca5af1519c69874f3c71988fdf72e] [2024-04-26 07:47:34] debug: zh:ezsp:uart: <-- [c0eb9dbb6a8dfdc7dfd6957e] [2024-04-26 07:47:34] debug: zh:ezsp:uart: <-- DATA (1,4,0): 1461b1a9112a15b6588d4a24ab1592499ca5af1519c69874f3c71988fdf72ec0eb9dbb6a8dfdc7dfd6957e [2024-04-26 07:47:34] debug: zh:ezsp:uart: --> ACK (2) [2024-04-26 07:47:34] debug: zh:ezsp:uart: --> [82503a7e] [2024-04-26 07:47:34] debug: zh:ezsp:uart: <-- ACK (4): 1461b1a9112a15b6588d4a24ab1592499ca5af1519c69874f3c71988fdf72ec0eb9dbb6a8dfdc7dfd6957e [2024-04-26 07:47:34] info: zh:ezsp:ezsp: <== Frame: 23900145000004011900010140000000eb88bef408ffff0e017a01018911670050650502020004 [2024-04-26 07:47:34] info: zh:ezsp:ezsp: <== 0x45: {"cls":"incomingMessageHandler","id":69,"isRequest":false,"type":0,"apsFrame":{"profileId":260,"sequence":235,"clusterId":25,"sourceEndpoint":1,"destinationEndpoint":1,"groupId":0,"options":64},"lastHopLqi":136,"lastHopRssi":-66,"sender":2292,"bindingIndex":255,"addressIndex":255,"message":{"type":"Buffer","data":[1,122,1,1,137,17,103,0,80,101,5,2,2,0]}} [2024-04-26 07:47:34] debug: zh:ezsp: processMessage: {"messageType":0,"apsFrame":{"profileId":260,"sequence":235,"clusterId":25,"sourceEndpoint":1,"destinationEndpoint":1,"groupId":0,"options":64},"lqi":136,"rssi":-66,"sender":2292,"bindingIndex":255,"addressIndex":255,"message":{"type":"Buffer","data":[1,122,1,1,137,17,103,0,80,101,5,2,2,0]}} [2024-04-26 07:47:34] debug: zh:controller: Received 'zcl' data '{"frame":{"Header":{"frameControl":{"frameType":1,"manufacturerSpecific":false,"direction":0,"disableDefaultResponse":false,"reservedBits":0},"transactionSequenceNumber":122,"manufacturerCode":null,"commandIdentifier":1},"Payload":{"fieldControl":1,"manufacturerCode":4489,"imageType":103,"fileVersion":33908048},"Command":{"ID":1,"response":2,"parameters":[{"name":"fieldControl","type":32},{"name":"manufacturerCode","type":33},{"name":"imageType","type":33},{"name":"fileVersion","type":35}],"name":"queryNextImageRequest"}},"address":2292,"endpoint":1,"linkquality":136,"groupID":0,"wasBroadcast":false,"destinationEndpoint":1}' [2024-04-26 07:47:34] debug: z2m: Received Zigbee message from 'Ledvance_Garage', type 'commandQueryNextImageRequest', cluster 'genOta', data '{"fieldControl":1,"fileVersion":33908048,"imageType":103,"manufacturerCode":4489}' from endpoint 1 with groupID 0 [2024-04-26 07:47:34] debug: z2m: Device 'Ledvance_Garage' requested OTA [2024-04-26 07:47:35] info: zh:ezsp:ezsp: Time to watchdog ... 0 [2024-04-26 07:47:35] info: zh:ezsp:ezsp: ==> nop: null [2024-04-26 07:47:35] info: zh:ezsp:ezsp: ==> {"cls":"nop","id":5,"isRequest":true} [2024-04-26 07:47:35] debug: zh:ezsp:uart: --> DATA (4,2,0): 2400010500 [2024-04-26 07:47:35] debug: zh:ezsp:uart: --> [426621a9512ae1487e] [2024-04-26 07:47:35] debug: zh:ezsp:uart: -?- waiting (5) [2024-04-26 07:47:35] debug: zh:ezsp:uart: <-- [2566a1a9512aab297e] [2024-04-26 07:47:35] debug: zh:ezsp:uart: <-- DATA (2,5,0): 2566a1a9512aab297e [2024-04-26 07:47:35] debug: zh:ezsp:uart: --> ACK (3) [2024-04-26 07:47:35] debug: zh:ezsp:uart: --> [83401b7e] [2024-04-26 07:47:35] debug: zh:ezsp:uart: <-- ACK (5): 2566a1a9512aab297e [2024-04-26 07:47:35] info: zh:ezsp:ezsp: <== Frame: 2480010500 [2024-04-26 07:47:35] info: zh:ezsp:ezsp: <== 0x5: {"cls":"nop","id":5,"isRequest":false} [2024-04-26 07:47:35] debug: zh:ezsp:uart: -+- waiting (5) success [2024-04-26 07:47:37] debug: zh:ezsp:uart: <-- [3566b1a97d312a15b6588d4a24ab1592] [2024-04-26 07:47:37] debug: zh:ezsp:uart: <-- [499ca2af1519c69874f3c77d3888fdf7] [2024-04-26 07:47:37] debug: zh:ezsp:uart: <-- [2ec0eb9dbb6a8dfdc7df8e0a7e] [2024-04-26 07:47:37] debug: zh:ezsp:uart: <-- DATA (3,5,0): 3566b1a9112a15b6588d4a24ab1592499ca2af1519c69874f3c71888fdf72ec0eb9dbb6a8dfdc7df8e0a7e [2024-04-26 07:47:37] debug: zh:ezsp:uart: --> ACK (4) [2024-04-26 07:47:37] debug: zh:ezsp:uart: --> [8430fc7e] [2024-04-26 07:47:37] debug: zh:ezsp:uart: <-- ACK (5): 3566b1a9112a15b6588d4a24ab1592499ca2af1519c69874f3c71888fdf72ec0eb9dbb6a8dfdc7df8e0a7e [2024-04-26 07:47:37] info: zh:ezsp:ezsp: <== Frame: 24900145000004011900010140000000ec88bef408ffff0e017b01018911670050650502020004 [2024-04-26 07:47:37] info: zh:ezsp:ezsp: <== 0x45: {"cls":"incomingMessageHandler","id":69,"isRequest":false,"type":0,"apsFrame":{"profileId":260,"sequence":236,"clusterId":25,"sourceEndpoint":1,"destinationEndpoint":1,"groupId":0,"options":64},"lastHopLqi":136,"lastHopRssi":-66,"sender":2292,"bindingIndex":255,"addressIndex":255,"message":{"type":"Buffer","data":[1,123,1,1,137,17,103,0,80,101,5,2,2,0]}} [2024-04-26 07:47:37] debug: zh:ezsp: processMessage: {"messageType":0,"apsFrame":{"profileId":260,"sequence":236,"clusterId":25,"sourceEndpoint":1,"destinationEndpoint":1,"groupId":0,"options":64},"lqi":136,"rssi":-66,"sender":2292,"bindingIndex":255,"addressIndex":255,"message":{"type":"Buffer","data":[1,123,1,1,137,17,103,0,80,101,5,2,2,0]}} [2024-04-26 07:47:37] debug: zh:controller: Received 'zcl' data '{"frame":{"Header":{"frameControl":{"frameType":1,"manufacturerSpecific":false,"direction":0,"disableDefaultResponse":false,"reservedBits":0},"transactionSequenceNumber":123,"manufacturerCode":null,"commandIdentifier":1},"Payload":{"fieldControl":1,"manufacturerCode":4489,"imageType":103,"fileVersion":33908048},"Command":{"ID":1,"response":2,"parameters":[{"name":"fieldControl","type":32},{"name":"manufacturerCode","type":33},{"name":"imageType","type":33},{"name":"fileVersion","type":35}],"name":"queryNextImageRequest"}},"address":2292,"endpoint":1,"linkquality":136,"groupID":0,"wasBroadcast":false,"destinationEndpoint":1}' [2024-04-26 07:47:37] debug: z2m: Received Zigbee message from 'Ledvance_Garage', type 'commandQueryNextImageRequest', cluster 'genOta', data '{"fieldControl":1,"fileVersion":33908048,"imageType":103,"manufacturerCode":4489}' from endpoint 1 with groupID 0 [2024-04-26 07:47:37] debug: z2m: Device 'Ledvance_Garage' requested OTA [2024-04-26 07:47:38] debug: zh:ezsp:uart: <-- [4566b1a90d2abce08bbb530caa1e8049] [2024-04-26 07:47:38] debug: zh:ezsp:uart: <-- [d0e126e974f4157e] [2024-04-26 07:47:38] debug: zh:ezsp:uart: <-- DATA (4,5,0): 4566b1a90d2abce08bbb530caa1e8049d0e126e974f4157e [2024-04-26 07:47:38] debug: zh:ezsp:uart: --> ACK (5) [2024-04-26 07:47:38] debug: zh:ezsp:uart: --> [8520dd7e] [2024-04-26 07:47:38] debug: zh:ezsp:uart: <-- ACK (5): 4566b1a90d2abce08bbb530caa1e8049d0e126e974f4157e [2024-04-26 07:47:38] info: zh:ezsp:ezsp: <== Frame: 2490015900a952d22f1929004b12004caf014299 [2024-04-26 07:47:38] info: zh:ezsp:ezsp: <== 0x59: {"cls":"incomingRouteRecordHandler","id":89,"isRequest":false,"source":21161,"longId":{"type":"Buffer","data":[0,18,75,0,41,25,47,210]},"lastHopLqi":76,"lastHopRssi":-81,"relay":{"type":"Buffer","data":[66]}} [2024-04-26 07:47:38] info: zh:ezsp:driver: handleRouteRecord: nwk=21161, ieee=K)/�, lqi=76, rssi=-81, relays=B [2024-04-26 07:47:38] debug: zh:ezsp:uart: <-- [5566b1a90d2abce08bbb530caa1e8049] [2024-04-26 07:47:38] debug: zh:ezsp:uart: <-- [d0e126e9747ad87e] [2024-04-26 07:47:38] debug: zh:ezsp:uart: <-- DATA (5,5,0): 5566b1a90d2abce08bbb530caa1e8049d0e126e9747ad87e [2024-04-26 07:47:38] debug: zh:ezsp:uart: --> ACK (6) [2024-04-26 07:47:38] debug: zh:ezsp:uart: --> [8610be7e] [2024-04-26 07:47:38] debug: zh:ezsp:uart: <-- ACK (5): 5566b1a90d2abce08bbb530caa1e8049d0e126e9747ad87e [2024-04-26 07:47:38] info: zh:ezsp:ezsp: <== Frame: 2490015900a952d22f1929004b12004caf014299 [2024-04-26 07:47:38] info: zh:ezsp:ezsp: <== 0x59: {"cls":"incomingRouteRecordHandler","id":89,"isRequest":false,"source":21161,"longId":{"type":"Buffer","data":[0,18,75,0,41,25,47,210]},"lastHopLqi":76,"lastHopRssi":-81,"relay":{"type":"Buffer","data":[66]}} [2024-04-26 07:47:38] info: zh:ezsp:driver: handleRouteRecord: nwk=21161, ieee=K)/�, lqi=76, rssi=-81, relays=B [2024-04-26 07:47:38] debug: zh:ezsp:uart: <-- [6566b1a97d312a15b658954a24ab5593] [2024-04-26 07:47:38] debug: zh:ezsp:uart: <-- [499cc86b04449c9874fade5283dc7d5e] [2024-04-26 07:47:38] debug: zh:ezsp:uart: <-- [1fb9eff3157e] [2024-04-26 07:47:38] debug: zh:ezsp:uart: <-- DATA (6,5,0): 6566b1a9112a15b658954a24ab5593499cc86b04449c9874fade5283dc7e1fb9eff3157e [2024-04-26 07:47:38] debug: zh:ezsp:uart: --> ACK (7) [2024-04-26 07:47:38] debug: zh:ezsp:uart: --> [87009f7e] [2024-04-26 07:47:38] debug: zh:ezsp:uart: <-- ACK (5): 6566b1a9112a15b658954a24ab5593499cc86b04449c9874fade5283dc7e1fb9eff3157e [2024-04-26 07:47:38] info: zh:ezsp:ezsp: <== Frame: 24900145000004010100010100010000864cafa952ffff0718310a2000201e04 [2024-04-26 07:47:38] info: zh:ezsp:ezsp: <== 0x45: {"cls":"incomingMessageHandler","id":69,"isRequest":false,"type":0,"apsFrame":{"profileId":260,"sequence":134,"clusterId":1,"sourceEndpoint":1,"destinationEndpoint":1,"groupId":0,"options":256},"lastHopLqi":76,"lastHopRssi":-81,"sender":21161,"bindingIndex":255,"addressIndex":255,"message":{"type":"Buffer","data":[24,49,10,32,0,32,30]}} [2024-04-26 07:47:38] debug: zh:ezsp: processMessage: {"messageType":0,"apsFrame":{"profileId":260,"sequence":134,"clusterId":1,"sourceEndpoint":1,"destinationEndpoint":1,"groupId":0,"options":256},"lqi":76,"rssi":-81,"sender":21161,"bindingIndex":255,"addressIndex":255,"message":{"type":"Buffer","data":[24,49,10,32,0,32,30]}} [2024-04-26 07:47:38] debug: zh:controller: Received 'zcl' data '{"frame":{"Header":{"frameControl":{"frameType":0,"manufacturerSpecific":false,"direction":1,"disableDefaultResponse":true,"reservedBits":0},"transactionSequenceNumber":49,"manufacturerCode":null,"commandIdentifier":10},"Payload":[{"attrId":32,"dataType":32,"attrData":30}],"Command":{"ID":10,"name":"report","parameters":[{"name":"attrId","type":33},{"name":"dataType","type":32},{"name":"attrData","type":1000}]}},"address":21161,"endpoint":1,"linkquality":76,"groupID":0,"wasBroadcast":false,"destinationEndpoint":1}' [2024-04-26 07:47:38] debug: z2m: Received Zigbee message from 'Sonoff_Sensor_Galerie', type 'attributeReport', cluster 'genPowerCfg', data '{"batteryVoltage":30}' from endpoint 1 with groupID 0 [2024-04-26 07:47:38] debug: z2m: MQTT publish: topic 'zigbee2mqtt/Sonoff_Sensor_Galerie', payload '{"battery":100,"humidity":39.47,"linkquality":76,"temperature":22.21,"voltage":3000}' [2024-04-26 07:47:38] debug: zh:ezsp:uart: <-- [7566b1a97d312a15b658954a24ab5593499cc66b04449c9874fade5183dd7d5e1f6fefb3b17e] [2024-04-26 07:47:38] debug: zh:ezsp:uart: <-- DATA (7,5,0): 7566b1a9112a15b658954a24ab5593499cc66b04449c9874fade5183dd7e1f6fefb3b17e [2024-04-26 07:47:38] debug: zh:ezsp:uart: --> ACK (0) [2024-04-26 07:47:38] debug: zh:ezsp:uart: --> [8070787e] [2024-04-26 07:47:38] debug: zh:ezsp:uart: <-- ACK (5): 7566b1a9112a15b658954a24ab5593499cc66b04449c9874fade5183dd7e1f6fefb3b17e [2024-04-26 07:47:38] info: zh:ezsp:ezsp: <== Frame: 24900145000004010100010100010000884cafa952ffff0718320a210020c804 [2024-04-26 07:47:38] info: zh:ezsp:ezsp: <== 0x45: {"cls":"incomingMessageHandler","id":69,"isRequest":false,"type":0,"apsFrame":{"profileId":260,"sequence":136,"clusterId":1,"sourceEndpoint":1,"destinationEndpoint":1,"groupId":0,"options":256},"lastHopLqi":76,"lastHopRssi":-81,"sender":21161,"bindingIndex":255,"addressIndex":255,"message":{"type":"Buffer","data":[24,50,10,33,0,32,200]}} [2024-04-26 07:47:38] debug: zh:ezsp: processMessage: {"messageType":0,"apsFrame":{"profileId":260,"sequence":136,"clusterId":1,"sourceEndpoint":1,"destinationEndpoint":1,"groupId":0,"options":256},"lqi":76,"rssi":-81,"sender":21161,"bindingIndex":255,"addressIndex":255,"message":{"type":"Buffer","data":[24,50,10,33,0,32,200]}} [2024-04-26 07:47:38] debug: zh:controller: Received 'zcl' data '{"frame":{"Header":{"frameControl":{"frameType":0,"manufacturerSpecific":false,"direction":1,"disableDefaultResponse":true,"reservedBits":0},"transactionSequenceNumber":50,"manufacturerCode":null,"commandIdentifier":10},"Payload":[{"attrId":33,"dataType":32,"attrData":200}],"Command":{"ID":10,"name":"report","parameters":[{"name":"attrId","type":33},{"name":"dataType","type":32},{"name":"attrData","type":1000}]}},"address":21161,"endpoint":1,"linkquality":76,"groupID":0,"wasBroadcast":false,"destinationEndpoint":1}' [2024-04-26 07:47:38] debug: z2m: Received Zigbee message from 'Sonoff_Sensor_Galerie', type 'attributeReport', cluster 'genPowerCfg', data '{"batteryPercentageRemaining":200}' from endpoint 1 with groupID 0 [2024-04-26 07:47:38] debug: z2m: MQTT publish: topic 'zigbee2mqtt/Sonoff_Sensor_Galerie', payload '{"battery":100,"humidity":39.47,"linkquality":76,"temperature":22.21,"voltage":3000}' [2024-04-26 07:47:38] debug: z2m: MQTT publish: topic 'zigbee2mqtt/Tuya_Infrarotheizung', payload '{"child_lock":"UNLOCK","current":0,"energy":4.55,"linkquality":76,"power":0,"state":"OFF","update":{"installed_version":192,"latest_version":192,"state":"idle"},"update_available":false,"voltage":231}' [2024-04-26 07:47:38] debug: z2m: MQTT publish: topic 'zigbee2mqtt/Tuya_Infrarotheizung', payload '{"child_lock":"UNLOCK","current":0,"energy":4.55,"linkquality":76,"power":0,"state":"OFF","update":{"installed_version":192,"latest_version":192,"state":"idle"},"update_available":false,"voltage":231}' [2024-04-26 07:47:40] debug: zh:ezsp:uart: <-- [0566b1a97d312a15b6588d4a24ab1592] [2024-04-26 07:47:40] debug: zh:ezsp:uart: <-- [499ca3af1519c69874f3c71f88fdf72e] [2024-04-26 07:47:40] debug: zh:ezsp:uart: <-- [c0eb9dbb6a8dfdc7df87957e] [2024-04-26 07:47:40] debug: zh:ezsp:uart: <-- DATA (0,5,0): 0566b1a9112a15b6588d4a24ab1592499ca3af1519c69874f3c71f88fdf72ec0eb9dbb6a8dfdc7df87957e [2024-04-26 07:47:40] debug: zh:ezsp:uart: --> ACK (1) [2024-04-26 07:47:40] debug: zh:ezsp:uart: --> [8160597e] [2024-04-26 07:47:40] debug: zh:ezsp:uart: <-- ACK (5): 0566b1a9112a15b6588d4a24ab1592499ca3af1519c69874f3c71f88fdf72ec0eb9dbb6a8dfdc7df87957e [2024-04-26 07:47:40] info: zh:ezsp:ezsp: <== Frame: 24900145000004011900010140000000ed88bef408ffff0e017c01018911670050650502020004 [2024-04-26 07:47:40] info: zh:ezsp:ezsp: <== 0x45: {"cls":"incomingMessageHandler","id":69,"isRequest":false,"type":0,"apsFrame":{"profileId":260,"sequence":237,"clusterId":25,"sourceEndpoint":1,"destinationEndpoint":1,"groupId":0,"options":64},"lastHopLqi":136,"lastHopRssi":-66,"sender":2292,"bindingIndex":255,"addressIndex":255,"message":{"type":"Buffer","data":[1,124,1,1,137,17,103,0,80,101,5,2,2,0]}} [2024-04-26 07:47:40] debug: zh:ezsp: processMessage: {"messageType":0,"apsFrame":{"profileId":260,"sequence":237,"clusterId":25,"sourceEndpoint":1,"destinationEndpoint":1,"groupId":0,"options":64},"lqi":136,"rssi":-66,"sender":2292,"bindingIndex":255,"addressIndex":255,"message":{"type":"Buffer","data":[1,124,1,1,137,17,103,0,80,101,5,2,2,0]}} [2024-04-26 07:47:40] debug: zh:controller: Received 'zcl' data '{"frame":{"Header":{"frameControl":{"frameType":1,"manufacturerSpecific":false,"direction":0,"disableDefaultResponse":false,"reservedBits":0},"transactionSequenceNumber":124,"manufacturerCode":null,"commandIdentifier":1},"Payload":{"fieldControl":1,"manufacturerCode":4489,"imageType":103,"fileVersion":33908048},"Command":{"ID":1,"response":2,"parameters":[{"name":"fieldControl","type":32},{"name":"manufacturerCode","type":33},{"name":"imageType","type":33},{"name":"fileVersion","type":35}],"name":"queryNextImageRequest"}},"address":2292,"endpoint":1,"linkquality":136,"groupID":0,"wasBroadcast":false,"destinationEndpoint":1}' [2024-04-26 07:47:40] debug: z2m: Received Zigbee message from 'Ledvance_Garage', type 'commandQueryNextImageRequest', cluster 'genOta', data '{"fieldControl":1,"fileVersion":33908048,"imageType":103,"manufacturerCode":4489}' from endpoint 1 with groupID 0 [2024-04-26 07:47:40] debug: z2m: Device 'Ledvance_Garage' requested OTA [2024-04-26 07:47:43] debug: z2m: Saving state to file /app/data/state.json [2024-04-26 07:47:43] debug: zh:ezsp:uart: <-- [1566b1a90d2aa91f1c8dd40e7d386d53] [2024-04-26 07:47:43] debug: zh:ezsp:uart: <-- [ed5480270b7d387e] [2024-04-26 07:47:43] debug: zh:ezsp:uart: <-- DATA (1,5,0): 1566b1a90d2aa91f1c8dd40e186d53ed5480270b187e [2024-04-26 07:47:43] debug: zh:ezsp:uart: --> ACK (2) [2024-04-26 07:47:43] debug: zh:ezsp:uart: --> [82503a7e] [2024-04-26 07:47:43] debug: zh:ezsp:uart: <-- ACK (5): 1566b1a90d2aa91f1c8dd40e186d53ed5480270b187e [2024-04-26 07:47:43] info: zh:ezsp:ezsp: <== Frame: 2490015900bcad45199e2bb238c1a4c8ce00 [2024-04-26 07:47:43] info: zh:ezsp:ezsp: <== 0x59: {"cls":"incomingRouteRecordHandler","id":89,"isRequest":false,"source":44476,"longId":{"type":"Buffer","data":[164,193,56,178,43,158,25,69]},"lastHopLqi":200,"lastHopRssi":-50,"relay":{"type":"Buffer","data":[]}} [2024-04-26 07:47:43] info: zh:ezsp:driver: handleRouteRecord: nwk=44476, ieee=��8�+�E, lqi=200, rssi=-50, relays= [2024-04-26 07:47:43] debug: zh:ezsp:uart: <-- [2566b1a97d312a15b658944a24ab5593] [2024-04-26 07:47:43] debug: zh:ezsp:uart: <-- [499c6def6551639874f2cec183fd7d5e] [2024-04-26 07:47:43] debug: zh:ezsp:uart: <-- [1f670932fe596b00e7dbd7dd6b7e] [2024-04-26 07:47:43] debug: zh:ezsp:uart: <-- DATA (2,5,0): 2566b1a9112a15b658944a24ab5593499c6def6551639874f2cec183fd7e1f670932fe596b00e7dbd7dd6b7e [2024-04-26 07:47:43] debug: zh:ezsp:uart: --> ACK (3) [2024-04-26 07:47:43] debug: zh:ezsp:uart: --> [83401b7e] [2024-04-26 07:47:43] debug: zh:ezsp:uart: <-- ACK (5): 2566b1a9112a15b658944a24ab5593499c6def6551639874f2cec183fd7e1f670932fe596b00e7dbd7dd6b7e [2024-04-26 07:47:43] info: zh:ezsp:ezsp: <== Frame: 2490014500000401000001010001000023c8cebcadffff0f08a20a010020c0e2ff2036e4ff200002 [2024-04-26 07:47:43] info: zh:ezsp:ezsp: <== 0x45: {"cls":"incomingMessageHandler","id":69,"isRequest":false,"type":0,"apsFrame":{"profileId":260,"sequence":35,"clusterId":0,"sourceEndpoint":1,"destinationEndpoint":1,"groupId":0,"options":256},"lastHopLqi":200,"lastHopRssi":-50,"sender":44476,"bindingIndex":255,"addressIndex":255,"message":{"type":"Buffer","data":[8,162,10,1,0,32,192,226,255,32,54,228,255,32,0]}} [2024-04-26 07:47:43] debug: zh:ezsp: processMessage: {"messageType":0,"apsFrame":{"profileId":260,"sequence":35,"clusterId":0,"sourceEndpoint":1,"destinationEndpoint":1,"groupId":0,"options":256},"lqi":200,"rssi":-50,"sender":44476,"bindingIndex":255,"addressIndex":255,"message":{"type":"Buffer","data":[8,162,10,1,0,32,192,226,255,32,54,228,255,32,0]}} [2024-04-26 07:47:43] debug: zh:controller: Received 'zcl' data '{"frame":{"Header":{"frameControl":{"frameType":0,"manufacturerSpecific":false,"direction":1,"disableDefaultResponse":false,"reservedBits":0},"transactionSequenceNumber":162,"manufacturerCode":null,"commandIdentifier":10},"Payload":[{"attrId":1,"dataType":32,"attrData":192},{"attrId":65506,"dataType":32,"attrData":54},{"attrId":65508,"dataType":32,"attrData":0}],"Command":{"ID":10,"name":"report","parameters":[{"name":"attrId","type":33},{"name":"dataType","type":32},{"name":"attrData","type":1000}]}},"address":44476,"endpoint":1,"linkquality":200,"groupID":0,"wasBroadcast":false,"destinationEndpoint":1}' [2024-04-26 07:47:43] debug: zh:controller:endpoint: ZCL command 0xa4c138b22b9e1945/1 genBasic.defaultRsp({"cmdId":10,"statusCode":0}, {"timeout":10000,"disableResponse":false,"disableRecovery":false,"disableDefaultResponse":true,"direction":1,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":162,"writeUndiv":false}) [2024-04-26 07:47:43] debug: zh:ezsp: sendZclFrameToEndpointInternal 0xa4c138b22b9e1945:44476/1 (0,0,1), timeout=10000 [2024-04-26 07:47:43] debug: z2m: Received Zigbee message from 'Tuya_Trockner', type 'attributeReport', cluster 'genBasic', data '{"65506":54,"65508":0,"appVersion":192}' from endpoint 1 with groupID 0 [2024-04-26 07:47:43] info: zh:ezsp:ezsp: ==> sendUnicast: {"type":0,"indexOrDestination":44476,"apsFrame":{"profileId":260,"sequence":115,"clusterId":0,"sourceEndpoint":1,"destinationEndpoint":1,"groupId":0,"options":256},"messageTag":116,"message":{"type":"Buffer","data":[24,162,11,10,0]}} [2024-04-26 07:47:43] info: zh:ezsp:ezsp: ==> {"cls":"sendUnicast","id":52,"isRequest":true,"type":0,"indexOrDestination":44476,"apsFrame":{"profileId":260,"sequence":115,"clusterId":0,"sourceEndpoint":1,"destinationEndpoint":1,"groupId":0,"options":256},"messageTag":116,"message":{"type":"Buffer","data":[24,162,11,10,0]}} [2024-04-26 07:47:43] debug: zh:ezsp:uart: --> DATA (5,3,0): 250001340000bcad0401000001010001000073740518a20b0a00 [2024-04-26 07:47:43] debug: zh:ezsp:uart: --> [536721a9602a150ef4904b25aa5493499d4e27d899cb7f29f6cc634d6c7e] [2024-04-26 07:47:43] debug: zh:ezsp:uart: -?- waiting (6) [2024-04-26 07:47:43] debug: zh:ezsp:uart: <-- [3667a1a9602a15f8f1a37e] [2024-04-26 07:47:43] debug: zh:ezsp:uart: <-- DATA (3,6,0): 3667a1a9602a15f8f1a37e [2024-04-26 07:47:43] debug: zh:ezsp:uart: --> ACK (4) [2024-04-26 07:47:43] debug: zh:ezsp:uart: --> [8430fc7e] [2024-04-26 07:47:43] debug: zh:ezsp:uart: <-- ACK (6): 3667a1a9602a15f8f1a37e [2024-04-26 07:47:43] info: zh:ezsp:ezsp: <== Frame: 2580013400004a [2024-04-26 07:47:43] info: zh:ezsp:ezsp: <== 0x34: {"cls":"sendUnicast","id":52,"isRequest":false,"status":0,"sequence":74} [2024-04-26 07:47:43] debug: zh:ezsp:uart: -+- waiting (6) success [2024-04-26 07:47:43] debug: zh:ezsp:uart: <-- [4667b1a96b2a150ef4904b25aa549349] [2024-04-26 07:47:43] debug: zh:ezsp:uart: <-- [9d4e27e199ce670b847e] [2024-04-26 07:47:43] debug: zh:ezsp:uart: <-- DATA (4,6,0): 4667b1a96b2a150ef4904b25aa5493499d4e27e199ce670b847e [2024-04-26 07:47:43] debug: zh:ezsp:uart: --> ACK (5) [2024-04-26 07:47:43] debug: zh:ezsp:uart: --> [8520dd7e] [2024-04-26 07:47:43] debug: zh:ezsp:uart: <-- ACK (6): 4667b1a96b2a150ef4904b25aa5493499d4e27e199ce670b847e [2024-04-26 07:47:43] info: zh:ezsp:ezsp: <== Frame: 2590013f0000bcad040100000101000100004a740000 [2024-04-26 07:47:43] info: zh:ezsp:ezsp: <== 0x3f: {"cls":"messageSentHandler","id":63,"isRequest":false,"type":0,"indexOrDestination":44476,"apsFrame":{"profileId":260,"sequence":74,"clusterId":0,"sourceEndpoint":1,"destinationEndpoint":1,"groupId":0,"options":256},"messageTag":116,"status":0,"message":{"type":"Buffer","data":[]}} [2024-04-26 07:47:45] info: zh:ezsp:ezsp: Time to watchdog ... 0 [2024-04-26 07:47:45] info: zh:ezsp:ezsp: ==> nop: null [2024-04-26 07:47:45] info: zh:ezsp:ezsp: ==> {"cls":"nop","id":5,"isRequest":true} [2024-04-26 07:47:45] debug: zh:ezsp:uart: --> DATA (6,5,0): 2600010500 [2024-04-26 07:47:45] debug: zh:ezsp:uart: --> [656421a9512a58827e] [2024-04-26 07:47:45] debug: zh:ezsp:uart: -?- waiting (7) [2024-04-26 07:47:45] debug: zh:ezsp:uart: <-- [5764a1a9512a21767e] [2024-04-26 07:47:45] debug: zh:ezsp:uart: <-- DATA (5,7,0): 5764a1a9512a21767e [2024-04-26 07:47:45] debug: zh:ezsp:uart: --> ACK (6) [2024-04-26 07:47:45] debug: zh:ezsp:uart: --> [8610be7e] [2024-04-26 07:47:45] debug: zh:ezsp:uart: <-- ACK (7): 5764a1a9512a21767e [2024-04-26 07:47:45] info: zh:ezsp:ezsp: <== Frame: 2680010500 [2024-04-26 07:47:45] info: zh:ezsp:ezsp: <== 0x5: {"cls":"nop","id":5,"isRequest":false} [2024-04-26 07:47:45] debug: zh:ezsp:uart: -+- waiting (7) success [2024-04-26 07:47:48] debug: zh:controller:database: Writing database to '/app/data/database.db' [2024-04-26 07:47:48] debug: zh:controller:endpoint: ZCL command 0x7cb03eaa00b26f6f/3 genBasic.read(["zclVersion"], {"timeout":10000,"disableResponse":false,"disableRecovery":true,"disableDefaultResponse":true,"direction":0,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":null,"writeUndiv":false}) [2024-04-26 07:47:48] debug: zh:ezsp: sendZclFrameToEndpointInternal 0x7cb03eaa00b26f6f:13507/3 (0,0,1), timeout=10000 [2024-04-26 07:47:48] info: zh:ezsp:ezsp: ==> sendUnicast: {"type":0,"indexOrDestination":13507,"apsFrame":{"profileId":260,"sequence":116,"clusterId":0,"sourceEndpoint":1,"destinationEndpoint":3,"groupId":0,"options":256},"messageTag":117,"message":{"type":"Buffer","data":[16,81,0,0,0]}} [2024-04-26 07:47:48] info: zh:ezsp:ezsp: ==> {"cls":"sendUnicast","id":52,"isRequest":true,"type":0,"indexOrDestination":13507,"apsFrame":{"profileId":260,"sequence":116,"clusterId":0,"sourceEndpoint":1,"destinationEndpoint":3,"groupId":0,"options":256},"messageTag":117,"message":{"type":"Buffer","data":[16,81,0,0,0]}} [2024-04-26 07:47:48] debug: zh:ezsp:uart: --> DATA (7,6,0): 270001340000c334040100000103000100007475051051000000 [2024-04-26 07:47:48] debug: zh:ezsp:uart: --> [766521a9602a15716d904b25aa5491499d4e27df98cb77dafdc663fc477e] [2024-04-26 07:47:48] debug: zh:ezsp:uart: -?- waiting (0) [2024-04-26 07:47:48] debug: zh:ezsp:uart: <-- [6065a1a9602a15f9cace7e] [2024-04-26 07:47:48] debug: zh:ezsp:uart: <-- DATA (6,0,0): 6065a1a9602

[harryba]

45df7312_zigbee2mqtt_2024-05-02T10-26-23.784Z.log

Having the same issues after trying to add a door sensor

[fszalaj]

same here

45df7312_zigbee2mqtt_2024-05-02T10-26-23.784Z.log

Having the same issues after trying to add a door sensor

[Chris0588]

Hi all.

I have recognized the same Issue as I wanted to add some devices.

Got the Error "Received undefined command from '0'", but was able to add the devices. Then i saw i could not rename them, the blue button is missing in the App of the mobile phone. Using a laptop, the Button is available, but not all Options when i rename them.

[xsrplayerx]

Hi all.

I have recognized the same Issue as I wanted to add some devices.

Got the Error "Received undefined command from '0'", but was able to add the devices. Then i saw i could not rename them, the blue button is missing in the App of the mobile phone. Using a laptop, the Button is available, but not all Options when i rename them.

I have the exact same issue...

[Pel1can111]

Same issue here, getting tons of these errors. Everything seems to be working except for power usage data for my sockets.

AU-A1ZBDSS

tried re-adding the sockets and now I just see "null" where the power measurement should be.

[EnzovdWetering]

I think I have the same issue, however I'm not sure if this started since I upgraded or before since my installation of zigbee2mqtt keeps freezing and zigbee devices become unresponsive. After restarting zigbee2mqtt everything is fine again.. Anyway I also get similar logs: [2024-05-03 06:01:37] error: zh:ezsp:ezsp: Frame changeSourceRouteHandler parsing error: RangeError: Attempt to access memory outside buffer bounds at new NodeError (node:internal/errors:405:5) at boundsError (node:internal/buffer:86:11) at Buffer.readUInt16LE (node:internal/buffer:245:5) at Buffer.readUIntLE (node:internal/buffer:182:17) at Function.deserialize (/app/node_modules/zigbee-herdsman/src/adapter/ezsp/driver/types/basic.ts:19:67) at new EZSPFrameData (/app/node_modules/zigbee-herdsman/src/adapter/ezsp/driver/ezsp.ts:180:54) at /app/node_modules/zigbee-herdsman/src/adapter/ezsp/driver/ezsp.ts:154:23 at Array.every (<anonymous>) at Function.createFrame (/app/node_modules/zigbee-herdsman/src/adapter/ezsp/driver/ezsp.ts:148:15) at Ezsp.onFrameReceived (/app/node_modules/zigbee-herdsman/src/adapter/ezsp/driver/ezsp.ts:439:35) [2024-05-03 06:01:37] error: zh:ezsp:ezsp: Unparsed frame 0xc4. Skipped [2024-05-03 06:01:37] error: zh:ezsp:ezsp: Frame changeSourceRouteHandler parsing error: RangeError: Attempt to access memory outside buffer bounds at new NodeError (node:internal/errors:405:5) at boundsError (node:internal/buffer:86:11) at Buffer.readUInt16LE (node:internal/buffer:245:5) at Buffer.readUIntLE (node:internal/buffer:182:17) at Function.deserialize (/app/node_modules/zigbee-herdsman/src/adapter/ezsp/driver/types/basic.ts:19:67) at new EZSPFrameData (/app/node_modules/zigbee-herdsman/src/adapter/ezsp/driver/ezsp.ts:180:54) at /app/node_modules/zigbee-herdsman/src/adapter/ezsp/driver/ezsp.ts:154:23 at Array.every (<anonymous>) at Function.createFrame (/app/node_modules/zigbee-herdsman/src/adapter/ezsp/driver/ezsp.ts:148:15) at Ezsp.onFrameReceived (/app/node_modules/zigbee-herdsman/src/adapter/ezsp/driver/ezsp.ts:439:35) [2024-05-03 06:01:37] error: zh:ezsp:ezsp: Unparsed frame 0xc4. Skipped

Current version: 1.37.0-1 (Changelog)

[robvanoostenrijk]

Confirming that I'm seeing the same issues after update:

[2024-05-03 10:41:47] error:    zh:ezsp:ezsp: Frame changeSourceRouteHandler parsing error: RangeError: Attempt to access memory outside buffer bounds
    at boundsError (node:internal/buffer:86:11)
    at Buffer.readUInt16LE (node:internal/buffer:245:5)
    at Buffer.readUIntLE (node:internal/buffer:182:17)
    at Function.deserialize (/usr/local/share/zigbee2mqtt/node_modules/zigbee-herdsman/src/adapter/ezsp/driver/types/basic.ts:19:67)
    at new EZSPFrameData (/usr/local/share/zigbee2mqtt/node_modules/zigbee-herdsman/src/adapter/ezsp/driver/ezsp.ts:180:54)
    at /usr/local/share/zigbee2mqtt/node_modules/zigbee-herdsman/src/adapter/ezsp/driver/ezsp.ts:154:23
    at Array.every (<anonymous>)
    at Function.createFrame (/usr/local/share/zigbee2mqtt/node_modules/zigbee-herdsman/src/adapter/ezsp/driver/ezsp.ts:148:15)
    at Ezsp.onFrameReceived (/usr/local/share/zigbee2mqtt/node_modules/zigbee-herdsman/src/adapter/ezsp/driver/ezsp.ts:439:35)
    at SerialDriver.emit (node:events:519:28)

Frontend version:

• 0.6.165
• 19.32.0
• 0.45.0

Zigbee2MQTT version:

• 1.37.0 commit: ee5cf5a9

Coordinator type

• EZSP v8

Coordinator revision

• 6.7.10.0 build 423

[posul]

Confirming I see the same issue after update

[hhrocha000]

Same issue here, when i restart zigbee2mqtt fixes for a couple of hours but the issue returns randomly. Having issues with my devices since last 2 updates randomly they stop responding, couldn't find a fix yet

[DennisJohnsen]

I know, i know. Watchtower is usually bad practice on something you want stable. I see that now 😂

Disabled Watchtower for my Zigbee2MQTT container, pulled the previous image koenkk/zigbee2mqtt:1.36.1 and now my GreenPower devices work again.

I noticed something was wrong when 14 of my 17 switches suddenly stopped working.

[litecross91]

Same problem here. Is there any solution?

[EnzovdWetering]

I upgraded my Sonoff ZBDongle-E adapter to: 7.4.0.0 (newer versions did not flash) Since I've done this I don't have the issue anymore. My adapter was running version 6.10.3.0 build 297 before the upgrade.

To be specific, I've used this firmware: https://github.com/darkxst/silabs-firmware-builder/blob/main/firmware_builds/zbdonglee/ncp-uart-hw-v7.4.0.0-zbdonglee-115200.gbl

With this command: universal-silabs-flasher --device /dev/tty.usbserial-202302201603421 --bootloader-reset sonoff flash --firmware /Users/enzovandewetering/Downloads/ncp-uart-hw-v7.4.0.0-zbdonglee-115200.gbl

I used --bootloader-reset because a newer version that I flashed stopt the adapter from booting. Perhaps you don't need this.

Let me know if it works.

Best regards, Enzo

[litecross91]

Something went wrong :(

I changed in the configuration.yaml adapter: ember

[14:59:27] INFO: Preparing to start...
[14:59:27] INFO: Socat not enabled
[14:59:28] INFO: Starting Zigbee2MQTT...
[2024-05-03 14:59:29] info:     z2m: Logging to console, file (filename: log.log)
[2024-05-03 14:59:30] info:     z2m: Starting Zigbee2MQTT version 1.37.0 (commit #unknown)
[2024-05-03 14:59:30] info:     z2m: Starting zigbee-herdsman (0.45.0)
[2024-05-03 14:59:30] info:     zh:ember: ======== Ember Adapter Starting ========
[2024-05-03 14:59:30] info:     zh:ember:ezsp: ======== EZSP starting ========
[2024-05-03 14:59:30] info:     zh:ember:uart:ash: ======== ASH NCP reset ========
[2024-05-03 14:59:30] info:     zh:ember:uart:ash: RTS/CTS config is off, enabling software flow control.
[2024-05-03 14:59:30] info:     zh:ember:uart:ash: Serial port opened
[2024-05-03 14:59:30] info:     zh:ember:uart:ash: ======== ASH starting ========
[2024-05-03 14:59:31] info:     zh:ember:uart:ash: ======== ASH connected ========
[2024-05-03 14:59:31] info:     zh:ember:uart:ash: ======== ASH started ========
[2024-05-03 14:59:31] info:     zh:ember:ezsp: ======== EZSP started ========
[2024-05-03 14:59:31] info:     zh:ember: [STACK STATUS] Network up.
[2024-05-03 14:59:31] error:    z2m: Error while starting zigbee-herdsman
[2024-05-03 14:59:31] error:    z2m: Failed to start zigbee
[2024-05-03 14:59:31] error:    z2m: Check https://www.zigbee2mqtt.io/guide/installation/20_zigbee2mqtt-fails-to-start.html for possible solutions
[2024-05-03 14:59:31] error:    z2m: Exiting...
[2024-05-03 14:59:31] error:    z2m: Error: [BACKUP] Current backup file is from an unsupported EZSP version (min: 12).
    at EmberAdapter.getStoredBackup (/app/node_modules/zigbee-herdsman/src/adapter/ember/adapter/emberAdapter.ts:1340:23)
    at EmberAdapter.initTrustCenter (/app/node_modules/zigbee-herdsman/src/adapter/ember/adapter/emberAdapter.ts:1131:33)
    at EmberAdapter.initEzsp (/app/node_modules/zigbee-herdsman/src/adapter/ember/adapter/emberAdapter.ts:813:19)
    at EmberAdapter.start (/app/node_modules/zigbee-herdsman/src/adapter/ember/adapter/emberAdapter.ts:2660:24)
    at Controller.start (/app/node_modules/zigbee-herdsman/src/controller/controller.ts:124:29)
    at Zigbee.start (/app/lib/zigbee.ts:62:27)
    at Controller.start (/app/lib/controller.ts:108:27)
    at start (/app/index.js:107:5)
[15:02:17] INFO: Preparing to start...
[15:02:17] INFO: Socat not enabled

Solution: In the configuration folder renamed the "coordinator_backup.json" to "coordinator_backup.json.old" and the z2m started.

[hhrocha000]

im using this coordinator https://pt.aliexpress.com/item/1005005271016330.html?spm=a2g0o.productlist.main.89.6771bo3hbo3hjf&algo_pvid=b4a4e2e4-2201-4032-a882-92bd94fc27d7&algo_exp_id=b4a4e2e4-2201-4032-a882-92bd94fc27d7-44&pdp_npi=4%40dis%21EUR%218.38%217.78%21%21%218.79%218.16%21%402103146f17147401316211689eb723%2112000032433818442%21sea%21PT%211761271617%21&curPageLogUid=CeVxZYM7GWpw&utparam-url=scene%3Asearch%7Cquery_from%3A

i update from version 6.7.9.0 build 405 to 7.3.1.0 build 176 (EZSP updates from version 8 to 12 too) using this website: https://darkxst.github.io/silabs-firmware-builder/

Will see if this fix my problem and i'll give you my feedback later.

[xsrplayerx]

Will see if this fix my problem and i'll give you my feedback later.

Thanks! I also have that coordinator

[guidox]

I also have the same problem, I use the coordinator Sonoff v2 plus

[hhrocha000]

UPDATE: in my case update my coordinator solve the problem.

im using this coordinator https://pt.aliexpress.com/item/1005005271016330.html?spm=a2g0o.productlist.main.89.6771bo3hbo3hjf&algo_pvid=b4a4e2e4-2201-4032-a882-92bd94fc27d7&algo_exp_id=b4a4e2e4-2201-4032-a882-92bd94fc27d7-44&pdp_npi=4%40dis%21EUR%218.38%217.78%21%21%218.79%218.16%21%402103146f17147401316211689eb723%2112000032433818442%21sea%21PT%211761271617%21&curPageLogUid=CeVxZYM7GWpw&utparam-url=scene%3Asearch%7Cquery_from%3A

i update from version 6.7.9.0 build 405 to 7.3.1.0 build 176 (EZSP updates from version 8 to 12 too) using this website: https://darkxst.github.io/silabs-firmware-builder/

Will see if this fix my problem and i'll give you my feedback later.

[thombec]

sounds great :-)

my Sonoff ZB-Dongle-E has the firmware 6.10.3.0 - so I want to flash it too to solve this problem.

Short question: After flashing - do you have to re-pair all your Zigbee devices or Z2MQTT started again with all the devices?

[litecross91]

I did it and no, don't need repair. Worked all 22 devices as before.

[xsrplayerx]

UPDATE: in my case update my coordinator solve the problem.

im using this coordinator https://pt.aliexpress.com/item/1005005271016330.html?spm=a2g0o.productlist.main.89.6771bo3hbo3hjf&algo_pvid=b4a4e2e4-2201-4032-a882-92bd94fc27d7&algo_exp_id=b4a4e2e4-2201-4032-a882-92bd94fc27d7-44&pdp_npi=4%40dis%21EUR%218.38%217.78%21%21%218.79%218.16%21%402103146f17147401316211689eb723%2112000032433818442%21sea%21PT%211761271617%21&curPageLogUid=CeVxZYM7GWpw&utparam-url=scene%3Asearch%7Cquery_from%3A i update from version 6.7.9.0 build 405 to 7.3.1.0 build 176 (EZSP updates from version 8 to 12 too) using this website: https://darkxst.github.io/silabs-firmware-builder/ Will see if this fix my problem and i'll give you my feedback later.

Thanks!

[Ltek]

@Koenkk a few Debug Logs attached Only started getting this error after just updating from FW v6.7.9.0 to 7.3.1.0 and to Z2M 1.37

Now using Sonoff ZB-Dongle-E w/ FW 7.3.1.0

Z2M_DebugLogs.zip

[Catalin84]

[2024-05-08 06:31:31] warning: zh:ezsp: Deprecated driver 'ezsp' currently in use, 'ember' will become the officially supported EmberZNet driver in next release. If using Zigbee2MQTT see https://github.com/Koenkk/zigbee2mqtt/discussions/21462 [2024-05-08 06:32:07] error: zh:controller:greenpower: Received undefined command from '0' [2024-05-08 06:35:27] error: zh:controller:greenpower: Received undefined command from '0' [2024-05-08 06:38:47] error: zh:controller:greenpower: Received undefined command from '0' [2024-05-08 06:42:07] error: zh:controller:greenpower: Received undefined command from '0' [2024-05-08 06:45:27] error: zh:controller:greenpower: Received undefined command from '0' [2024-05-08 06:48:47] error: zh:controller:greenpower: Received undefined command from '0' [2024-05-08 06:52:07] error: zh:controller:greenpower: Received undefined command from '0' [2024-05-08 06:55:27] error: zh:controller:greenpower: Received undefined command from '0' [2024-05-08 06:58:47] error: zh:controller:greenpower: Received undefined command from '0' [2024-05-08 07:02:07] error: zh:controller:greenpower: Received undefined command from '0' [2024-05-08 07:05:27] error: zh:controller:greenpower: Received undefined command from '0' [2024-05-08 07:08:47] error: zh:controller:greenpower: Received undefined command from '0' [2024-05-08 07:12:07] error: zh:controller:greenpower: Received undefined command from '0'

Same issue after updateing Zigbee app and firmware!

[archont00]

@EnzovdWetering

I upgraded my Sonoff ZBDongle-E adapter to: 7.4.0.0 (newer versions did not flash) Since I've done this I don't have the issue anymore. My adapter was running version 6.10.3.0 build 297 before the upgrade.

Did the same, no more error in logs - and afterwards, I could run OTA update for IKEA E2001/2002.

I used --bootloader-reset because a newer version that I flashed stopt the adapter from booting. Perhaps you don't need this.

I have updated the dongle via web flasher (Google Chrome, Ubuntu Linux) with fw: ncp-uart-hw-v7.4.0.0-zbdonglee-115200.gbl. The web flasher does not allow user to set options.

All devices were connected after HAOS reboot.

[Ltek]

Did the same, no more error in logs - and afterwards, I could run OTA update for IKEA E2001/2002.

I have updated the dongle via web flasher (Google Chrome, Ubuntu Linux) with fw: ncp-uart-hw-v7.4.0.0-zbdonglee-115200.gbl. The web flasher does not allow user to set options.

All devices were connected after HAOS reboot.

updated to 7.4.3 and no more Z2M errors -but- many of the devices did not reconnect on their own.

Z2M also has serious problems re-pairing Bosch and Aqara Motion Sensors even with the sensor being 4 ft from the Dongle... so its really hard to blame the dongle. I have to restart Z2M (dongle stays plugged/powered the entire time) multiple times before it will initiate the pairing.

Pairing a brand new device (Bosch or Aqara - new out of box) works super quick. This leads me to thing Z2M has a problem with pairing devices after they have already been paired (Deconz or Z2M), then factory reset... even if they have never been in Z2M.

[Gazarob63]

Same issue, I haven't seen any definitive answer to this problem. The error repeats every few seconds, eventually (randomly) Zigbee2MQTT will stop leaving all devices unavailable until restarted.

Info:

Zigbee2MQTT Current version: 1.37.1-1

ID_MODEL: SONOFF_Zigbee_3.0_USB_Dongle_Plus_V2 ID_MODEL_ENC: SONOFF\x20Zigbee\x203.0\x20USB\x20Dongle\x20Plus\x20V2 ID_MODEL_ID: 55d4 ID_PATH: platform-fd500000.pcie-pci-0000:01:00.0-usb-0:1.3:1.0 ID_PATH_TAG: platform-fd500000_pcie-pci-0000_01_00_0-usb-0_1_3_1_0 ID_PATH_WITH_USB_REVISION: platform-fd500000.pcie-pci-0000:01:00.0-usbv2-0:1.3:1.0 ID_REVISION: '0442' ID_SERIAL: ITEAD_SONOFF_Zigbee_3.0_USB_Dongle_Plus_V2_20221201164229 ID_SERIAL_SHORT: '20221201164229' ID_TYPE: generic ID_USB_DRIVER: cdc_acm

Log Error: (Repeats) 2024-05-13 06:00:13] error: zh:ezsp:ezsp: Unparsed frame 0xc4. Skipped [2024-05-13 06:00:19] error: zh:ezsp:ezsp: Frame changeSourceRouteHandler parsing error: RangeError: Attempt to access memory outside buffer bounds at new NodeError (node:internal/errors:405:5) at boundsError (node:internal/buffer:86:11) at Buffer.readUInt16LE (node:internal/buffer:245:5) at Buffer.readUIntLE (node:internal/buffer:182:17) at Function.deserialize (/app/node_modules/zigbee-herdsman/src/adapter/ezsp/driver/types/basic.ts:19:67) at new EZSPFrameData (/app/node_modules/zigbee-herdsman/src/adapter/ezsp/driver/ezsp.ts:180:54) at /app/node_modules/zigbee-herdsman/src/adapter/ezsp/driver/ezsp.ts:154:23 at Array.every () at Function.createFrame (/app/node_modules/zigbee-herdsman/src/adapter/ezsp/driver/ezsp.ts:148:15) at Ezsp.onFrameReceived (/app/node_modules/zigbee-herdsman/src/adapter/ezsp/driver/ezsp.ts:439:35)