z2m crashes after some time

[okastl]

What happened?

After some time of use, z2m crashes. It may be related to polled haElectricalMeasurement.read from Tuya plugs. No idea, if this is related to a recent z2m or firmware update. Debug log is attached.
I will disable polling for now and hope, there will be no more crashes.

[2024-09-24 05:27:52] debug: 	zh:controller:endpoint: ZCL command 0x540f57fffe08d3cf/1 haElectricalMeasurement.read(["rmsVoltage","rmsCurrent","activePower"], {"timeout":10000,"disableResponse":false,"disableRecovery":false,"disableDefaultResponse":true,"direction":0,"reservedBits":0,"writeUndiv":false})
[2024-09-24 05:27:52] debug: 	zh:zstack: sendZclFrameToEndpointInternal 0x540f57fffe08d3cf:23647/1 (0,0,1)
[2024-09-24 05:27:52] debug: 	zh:zstack:znp: SREQ: --> AF - dataRequest - {"dstaddr":23647,"destendpoint":1,"srcendpoint":1,"clusterid":2820,"transid":244,"options":0,"radius":30,"len":9,"data":{"type":"Buffer","data":[16,99,0,5,5,8,5,11,5]}}
[2024-09-24 05:27:52] debug: 	zh:zstack:unpi:writer: --> frame [254,19,36,1,95,92,1,1,4,11,244,0,30,9,16,99,0,5,5,8,5,11,5,169]
[2024-09-24 05:27:58] debug: 	zh:controller:endpoint: Error: ZCL command 0x540f57fffe08d3cf/1 haElectricalMeasurement.read(["rmsVoltage","rmsCurrent","activePower"], {"timeout":10000,"disableResponse":false,"disableRecovery":false,"disableDefaultResponse":true,"direction":0,"reservedBits":0,"writeUndiv":false}) failed (SRSP - AF - dataRequest after 6000ms)
    at Object.start (/opt/storen2mqtt/node_modules/zigbee-herdsman/src/utils/waitress.ts:59:23)
    at /opt/storen2mqtt/node_modules/zigbee-herdsman/src/adapter/z-stack/znp/znp.ts:300:45
    at Queue.execute (/opt/storen2mqtt/node_modules/zigbee-herdsman/src/utils/queue.ts:36:26)
    at Znp.request (/opt/storen2mqtt/node_modules/zigbee-herdsman/src/adapter/z-stack/znp/znp.ts:291:27)
    at ZStackAdapter.dataRequest (/opt/storen2mqtt/node_modules/zigbee-herdsman/src/adapter/z-stack/adapter/zStackAdapter.ts:1201:24)
    at ZStackAdapter.sendZclFrameToEndpointInternal (/opt/storen2mqtt/node_modules/zigbee-herdsman/src/adapter/z-stack/adapter/zStackAdapter.ts:446:46)
    at /opt/storen2mqtt/node_modules/zigbee-herdsman/src/adapter/z-stack/adapter/zStackAdapter.ts:380:25
    at Queue.execute (/opt/storen2mqtt/node_modules/zigbee-herdsman/src/utils/queue.ts:36:26)
    at ZStackAdapter.sendZclFrameToEndpoint (/opt/storen2mqtt/node_modules/zigbee-herdsman/src/adapter/z-stack/adapter/zStackAdapter.ts:378:27)
    at Request.func (/opt/storen2mqtt/node_modules/zigbee-herdsman/src/controller/model/endpoint.ts:296:36)

What did you expect to happen?

No crash.

How to reproduce it (minimal and precise)

Use my setup and wait long enough... ;)

Zigbee2MQTT version

1.40.1-dev commit: 48d77e4

Adapter firmware version

20240710

Adapter

Sonoff P

Setup

plain

Debug log

log.zip

[Koenkk]

Does it still happen with the firmwares from #23869 (comment)

[okastl]

Does it still happen with the firmwares from #23869 (comment)

I am trying it right now with SONOFF_DONGLE_P_99240914.hex.
As a stress test, I have enabled polling on all Tuya plugs (5 or 6) and reduced polling time to 30 seconds.
I'll let you know, how long it works.

[okastl]

Does it still happen with the firmwares from #23869 (comment)

No crash after 5 days stress testing, SONOFF_DONGLE_P_99240914.hex seems to have fixed the problem.
How to proceed? What is the difference to 20240710? Based on same the TI SDK? Are the changes Sonoff specific?

[Koenkk]

Try the other firmwares in that zip, continue updating until it fails again

[Great-Chart]

Does it still happen with the firmwares from #23869 (comment)

No crash after 5 days stress testing, SONOFF_DONGLE_P_99240914.hex seems to have fixed the problem. How to proceed? What is the difference to 20240710? Based on same the TI SDK? Are the changes Sonoff specific?

I too have been struggling with Sonoff Dongle P; originally BEFORE updating firmware and found reverting back to 20221226 still hasn't resolved things fully - inference is that these variants for this coordinator might be the answer.

Can I ask if it's still OK for you and if you worked your way through them sequentially?

I'm monitoring logs closely going forwards but suffer from periods of relative stability among periods of chaos; but not finding it easy to know what to be looking for in the logs!

[okastl]

Try the other firmwares in that zip, continue updating until it fails again

I am still on SONOFF_DONGLE_P_99240914.hex as I didn't dare to update. After a long time of operation, yesterday it crashed again. So SONOFF_DONGLE_P_99240914.hex did not fix it, it just makes the crash much less frequent. Again, havoc starts with polling power of a Tuya plug haElectricalMeasurement.read:

[2024-11-17 03:05:57] debug: zh:controller:endpoint: ZCL command 0xcc86ecfffeeac21c/1 haElectricalMeasurement.read(["rmsVoltage","rmsCurrent","activePower"], {"timeout":10000,"disableResponse":false,"disableRecovery":false,"disableDefaultResponse":true,"direction":0,"reservedBits":0,"writeUndiv":false}) [2024-11-17 03:05:57] debug: zh:zstack: sendZclFrameToEndpointInternal 0xcc86ecfffeeac21c:32972/1 (0,0,1) [2024-11-17 03:05:57] debug: zh:zstack:znp: --> SREQ: AF - dataRequest - {"dstaddr":32972,"destendpoint":1,"srcendpoint":1,"clusterid":2820,"transid":211,"options":0,"radius":30,"len":9,"data":{"type":"Buffer","data":[16,158,0,5,5,8,5,11,5]}} [2024-11-17 03:05:57] debug: zh:zstack:unpi:writer: --> frame [254,19,36,1,204,128,1,1,4,11,211,0,30,9,16,158,0,5,5,8,5,11,5,60] [2024-11-17 03:06:03] debug: zh:controller:endpoint: Error: ZCL command 0xcc86ecfffeeac21c/1 haElectricalMeasurement.read(["rmsVoltage","rmsCurrent","activePower"], {"timeout":10000,"disableResponse":false,"disableRecovery":false,"disableDefaultResponse":true,"direction":0,"reservedBits":0,"writeUndiv":false}) failed (SRSP - AF - dataRequest after 6000ms) at Object.start (/opt/storen2mqtt/node_modules/zigbee-herdsman/src/utils/waitress.ts:59:23) at /opt/storen2mqtt/node_modules/zigbee-herdsman/src/adapter/z-stack/znp/znp.ts:285:45 at Queue.execute (/opt/storen2mqtt/node_modules/zigbee-herdsman/src/utils/queue.ts:36:26) at Znp.request (/opt/storen2mqtt/node_modules/zigbee-herdsman/src/adapter/z-stack/znp/znp.ts:278:27) at ZStackAdapter.dataRequest (/opt/storen2mqtt/node_modules/zigbee-herdsman/src/adapter/z-stack/adapter/zStackAdapter.ts:1034:24) at ZStackAdapter.sendZclFrameToEndpointInternal (/opt/storen2mqtt/node_modules/zigbee-herdsman/src/adapter/z-stack/adapter/zStackAdapter.ts:488:46) at /opt/storen2mqtt/node_modules/zigbee-herdsman/src/adapter/z-stack/adapter/zStackAdapter.ts:422:31 at Queue.execute (/opt/storen2mqtt/node_modules/zigbee-herdsman/src/utils/queue.ts:36:26) at ZStackAdapter.sendZclFrameToEndpoint (/opt/storen2mqtt/node_modules/zigbee-herdsman/src/adapter/z-stack/adapter/zStackAdapter.ts:420:33) at Request.func (/opt/storen2mqtt/node_modules/zigbee-herdsman/src/controller/model/endpoint.ts:299:36) [2024-11-17 03:06:10] debug: zh:controller:endpoint: ZCL command 0xa4c1380a32e70c5d/1 genBasic.read(["zclVersion"], {"timeout":10000,"disableResponse":false,"disableRecovery":true,"disableDefaultResponse":true,"direction":0,"reservedBits":0,"writeUndiv":false}) [2024-11-17 03:06:10] debug: zh:zstack: sendZclFrameToEndpointInternal 0xa4c1380a32e70c5d:10545/1 (0,0,1) [2024-11-17 03:06:10] debug: zh:zstack:znp: --> SREQ: AF - dataRequest - {"dstaddr":10545,"destendpoint":1,"srcendpoint":1,"clusterid":0,"transid":212,"options":0,"radius":30,"len":5,"data":{"type":"Buffer","data":[16,159,0,0,0]}} [2024-11-17 03:06:10] debug: zh:zstack:unpi:writer: --> frame [254,15,36,1,49,41,1,1,0,0,212,0,30,5,16,159,0,0,0,114] [2024-11-17 03:06:16] debug: zh:controller:endpoint: Error: ZCL command 0xa4c1380a32e70c5d/1 genBasic.read(["zclVersion"], {"timeout":10000,"disableResponse":false,"disableRecovery":true,"disableDefaultResponse":true,"direction":0,"reservedBits":0,"writeUndiv":false}) failed (SRSP - AF - dataRequest after 6000ms) at Object.start (/opt/storen2mqtt/node_modules/zigbee-herdsman/src/utils/waitress.ts:59:23) at /opt/storen2mqtt/node_modules/zigbee-herdsman/src/adapter/z-stack/znp/znp.ts:285:45 at Queue.execute (/opt/storen2mqtt/node_modules/zigbee-herdsman/src/utils/queue.ts:36:26) at Znp.request (/opt/storen2mqtt/node_modules/zigbee-herdsman/src/adapter/z-stack/znp/znp.ts:278:27) at ZStackAdapter.dataRequest (/opt/storen2mqtt/node_modules/zigbee-herdsman/src/adapter/z-stack/adapter/zStackAdapter.ts:1034:24) at ZStackAdapter.sendZclFrameToEndpointInternal (/opt/storen2mqtt/node_modules/zigbee-herdsman/src/adapter/z-stack/adapter/zStackAdapter.ts:488:46) at /opt/storen2mqtt/node_modules/zigbee-herdsman/src/adapter/z-stack/adapter/zStackAdapter.ts:422:31 at Queue.execute (/opt/storen2mqtt/node_modules/zigbee-herdsman/src/utils/queue.ts:36:26) at ZStackAdapter.sendZclFrameToEndpoint (/opt/storen2mqtt/node_modules/zigbee-herdsman/src/adapter/z-stack/adapter/zStackAdapter.ts:420:33) at Request.func (/opt/storen2mqtt/node_modules/zigbee-herdsman/src/controller/model/endpoint.ts:299:36)