Koenkk / zigbee2mqtt

Zigbee 🐝 to MQTT bridge 🌉, get rid of your proprietary Zigbee bridges 🔨
https://www.zigbee2mqtt.io
GNU General Public License v3.0
12.14k stars 1.68k forks source link

Sonoff Zigbee 3.0 USB Dongle Plus fails with SPM02 and SPM01 after a view hours #22489

Open matlab22 opened 6 months ago

matlab22 commented 6 months ago

What happened?

I have about 80 devices and recently the network is getting unstable. First it crashed after a few days and now it survives only hours. In the log I can not find any clue. I think it is a traffic related issue. I suspect it started after adding SPM01 and SPM02 power meter and got worse when I added more SPM02V2. Those report new data every other 2s. Has anyone similar issues or any tip to further investigate my problems?

What did you expect to happen?

No response

How to reproduce it (minimal and precise)

No response

Zigbee2MQTT version

1.36.0

Adapter firmware version

20230507

Adapter

SONOFF ZBDongle-E

Setup

Add-on on Rpi4 2GB RAM external USB SSD DietPi ( Debian - 11 Kernel 6.1.21-v8+)

Debug log

zigbee2mqtt.log

Pieter12345678 commented 6 months ago

I might have the same issue, any luck?

matlab22 commented 6 months ago

So far not. I thought the problem is that the noisy SPM02 power meter have to pass the xiaomi bulb to get to the coordinator. Then I added a zigbee 3.0 socked to provide an alternative route. Same trouble, no I removed the xiaomi bulb, but the network is still failing. Only restart is helping. Would be nice to have a watchdog implemented, to automate the restart.

What is in your log, when it crashes?

matlab22 commented 6 months ago

Now I moved the coordinator close to the energie meters. It looked good and there are a lots of topics published, but suddenly no new messages. The log is empty. then I changed the log level and got this:

info 2024-05-07 20:34:59Successfully changed options
info 2024-05-07 20:34:59MQTT publish: topic 'zigbee2mqtt/bridge/response/options', payload '{"data":{"restart_required":false},"status":"ok","transaction":"3bw9p-1"}'
debug 2024-05-07 20:35:16Received MQTT message on 'zigbee2mqtt/bridge/request/permit_join' with data '{"device":null,"time":254,"transaction":"3bw9p-2","value":true}'
info 2024-05-07 20:35:16Zigbee: allowing new devices to join.
error 2024-05-07 20:36:14Publish 'set' 'state' to 'X1.A5' failed: 'Error: Command 0x00158d00032ca3c7/1 genOnOff.off({}, {"timeout":10000,"disableResponse":false,"disableRecovery":false,"disableDefaultResponse":false,"direction":0,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":null,"writeUndiv":false}) failed (SRSP - AF - dataRequest after 6000ms)'
debug 2024-05-07 20:36:14Error: Command 0x00158d00032ca3c7/1 genOnOff.off({}, {"timeout":10000,"disableResponse":false,"disableRecovery":false,"disableDefaultResponse":false,"direction":0,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":null,"writeUndiv":false}) failed (SRSP - AF - dataRequest after 6000ms) at Object.start (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/src/utils/waitress.ts:63:23) at /opt/zigbee2mqtt/node_modules/zigbee-herdsman/src/adapter/z-stack/znp/znp.ts:312:45 at Queue.execute (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/src/utils/queue.ts:35:26) at ZStackAdapter.dataRequest (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/src/adapter/z-stack/adapter/zStackAdapter.ts:965:9) at ZStackAdapter.sendZclFrameToEndpointInternal (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/src/adapter/z-stack/adapter/zStackAdapter.ts:387:35) at Queue.execute (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/src/utils/queue.ts:35:20) at Request.send (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/src/controller/helpers/request.ts:79:20) at Endpoint.command (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/src/controller/model/endpoint.ts:746:28) at Object.convertSet (/opt/zigbee2mqtt/node_modules/zigbee-herdsman-converters/src/converters/toZigbee.ts:46:17) at Object.convertSet (/opt/zigbee2mqtt/node_modules/zigbee-herdsman-converters/src/converters/toZigbee.ts:1119:32)
debug 2024-05-07 20:36:23Saving state to file /opt/zigbee2mqtt/data/state.json
debug 2024-05-07 20:36:31Received MQTT message on 'zigbee2mqtt/X1.A5/set' with data '{"state":"off"}'
debug 2024-05-07 20:36:31Publishing 'set' 'state' to 'X1.A5'
error 2024-05-07 20:36:38Request 'zigbee2mqtt/bridge/request/permit_join' failed with error: 'SRSP - ZDO - mgmtPermitJoinReq after 6000ms'
debug 2024-05-07 20:36:38Error: SRSP - ZDO - mgmtPermitJoinReq after 6000ms at Object.start (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/src/utils/waitress.ts:63:23) at /opt/zigbee2mqtt/node_modules/zigbee-herdsman/src/adapter/z-stack/znp/znp.ts:312:45 at Queue.execute (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/src/utils/queue.ts:35:26) at /opt/zigbee2mqtt/node_modules/zigbee-herdsman/src/adapter/z-stack/adapter/zStackAdapter.ts:206:13 at Queue.execute (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/src/utils/queue.ts:35:20) at ZStackAdapter.permitJoin (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/src/adapter/z-stack/adapter/zStackAdapter.ts:203:9) at Controller.permitJoinInternal (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/src/controller/controller.ts:246:13) at Controller.permitJoin (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/src/controller/controller.ts:234:9) at Zigbee.permitJoin (/opt/zigbee2mqtt/lib/zigbee.ts:244:13) at Bridge.permitJoin (/opt/zigbee2mqtt/lib/extension/bridge.ts:275:9)
info 2024-05-07 20:36:38MQTT publish: topic 'zigbee2mqtt/bridge/response/permit_join', payload '{"data":{},"error":"SRSP - ZDO - mgmtPermitJoinReq after 6000ms","status":"error","transaction":"3bw9p-2"}'
error 2024-05-07 20:37:38Failed to execute LQI for 'X3.C2'
debug 2024-05-07 20:37:38Error: SRSP - ZDO - mgmtLqiReq after 6000ms at Object.start (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/src/utils/waitress.ts:63:23) at /opt/zigbee2mqtt/node_modules/zigbee-herdsman/src/adapter/z-stack/znp/znp.ts:312:45 at Queue.execute (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/src/utils/queue.ts:35:26) at request (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/src/adapter/z-stack/adapter/zStackAdapter.ts:579:17) at /opt/zigbee2mqtt/node_modules/zigbee-herdsman/src/adapter/z-stack/adapter/zStackAdapter.ts:604:28 at Queue.execute (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/src/utils/queue.ts:35:20) at doRequest (/opt/zigbee2mqtt/lib/extension/networkMap.ts:218:28) at NetworkMap.networkScan (/opt/zigbee2mqtt/lib/extension/networkMap.ts:231:32) at NetworkMap.onMQTTMessage (/opt/zigbee2mqtt/lib/extension/networkMap.ts:63:34) at EventEmitter.wrappedCallback (/opt/zigbee2mqtt/lib/eventBus.ts:174:17)
error 2024-05-07 20:37:50Publish 'set' 'state' to 'X1.A5' failed: 'Error: Command 0x00158d00032ca3c7/1 genOnOff.off({}, {"timeout":10000,"disableResponse":false,"disableRecovery":false,"disableDefaultResponse":false,"direction":0,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":null,"writeUndiv":false}) failed (SRSP - AF - dataRequest after 6000ms)'
debug 2024-05-07 20:37:50Error: Command 0x00158d00032ca3c7/1 genOnOff.off({}, {"timeout":10000,"disableResponse":false,"disableRecovery":false,"disableDefaultResponse":false,"direction":0,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":null,"writeUndiv":false}) failed (SRSP - AF - dataRequest after 6000ms) at Object.start (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/src/utils/waitress.ts:63:23) at /opt/zigbee2mqtt/node_modules/zigbee-herdsman/src/adapter/z-stack/znp/znp.ts:312:45 at Queue.execute (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/src/utils/queue.ts:35:26) at ZStackAdapter.dataRequest (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/src/adapter/z-stack/adapter/zStackAdapter.ts:965:9) at ZStackAdapter.sendZclFrameToEndpointInternal (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/src/adapter/z-stack/adapter/zStackAdapter.ts:387:35) at Queue.execute (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/src/utils/queue.ts:35:20) at Request.send (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/src/controller/helpers/request.ts:79:20) at Endpoint.command (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/src/controller/model/endpoint.ts:746:28) at Object.convertSet (/opt/zigbee2mqtt/node_modules/zigbee-herdsman-converters/src/converters/toZigbee.ts:46:17) at Object.convertSet (/opt/zigbee2mqtt/node_modules/zigbee-herdsman-converters/src/converters/toZigbee.ts:1119:32)
debug 2024-05-07 20:38:06Received MQTT message on 'zigbee2mqtt/X1.A5/set' with data '{"state":"off"}'
debug 2024-05-07 20:38:06Publishing 'set' 'state' to 'X1.A5'
error 2024-05-07 20:39:14Publish 'set' 'state' to 'X1.A5' failed: 'Error: Command 0x00158d00032ca3c7/1 genOnOff.off({}, {"timeout":10000,"disableResponse":false,"disableRecovery":false,"disableDefaultResponse":false,"direction":0,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":null,"writeUndiv":false}) failed (SRSP - AF - dataRequest after 6000ms)'
debug 2024-05-07 20:39:14Error: Command 0x00158d00032ca3c7/1 genOnOff.off({}, {"timeout":10000,"disableResponse":false,"disableRecovery":false,"disableDefaultResponse":false,"direction":0,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":null,"writeUndiv":false}) failed (SRSP - AF - dataRequest after 6000ms) at Object.start (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/src/utils/waitress.ts:63:23) at /opt/zigbee2mqtt/node_modules/zigbee-herdsman/src/adapter/z-stack/znp/znp.ts:312:45 at Queue.execute (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/src/utils/queue.ts:35:26) at ZStackAdapter.dataRequest (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/src/adapter/z-stack/adapter/zStackAdapter.ts:965:9) at ZStackAdapter.sendZclFrameToEndpointInternal (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/src/adapter/z-stack/adapter/zStackAdapter.ts:387:35) at Queue.execute (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/src/utils/queue.ts:35:20) at Request.send (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/src/controller/helpers/request.ts:79:20) at Endpoint.command (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/src/controller/model/endpoint.ts:746:28) at Object.convertSet (/opt/zigbee2mqtt/node_modules/zigbee-herdsman-converters/src/converters/toZigbee.ts:46:17) at Object.convertSet (/opt/zigbee2mqtt/node_modules/zigbee-herdsman-converters/src/converters/toZigbee.ts:1119:32)
debug 2024-05-07 20:39:41Received MQTT message on 'zigbee2mqtt/X1.A5/set' with data '{"state":"off"}'
debug 2024-05-07 20:39:41Publishing 'set' 'state' to 'X1.A5'

the network is still not working :(

matlab22 commented 6 months ago

I made a new setup with a new raspberry Pi 4 and a zigbee new network. It has a coordinator Sonoff Zigbee 3.0 USB Dongle Plus and 10 of those power meters SPM02 or SPM01. This is working fine, but after a while it stops working without any error. In this case 2h ago: image when I try to generate a map it fails:

info 2024-05-16 20:26:56Successfully changed options
info 2024-05-16 20:27:15Starting network scan (includeRoutes 'false')
error 2024-05-16 20:27:33Failed to execute LQI for 'Coordinator'
error 2024-05-16 20:27:51Failed to execute LQI for 'W3.FILS.HV26'
error 2024-05-16 20:28:09Failed to execute LQI for 'W0.FILS.HV10'
error 2024-05-16 20:28:27Failed to execute LQI for 'W0.FILS.HV12'
error 2024-05-16 20:28:45Failed to execute LQI for 'W0.FILS.HV13'
error 2024-05-16 20:29:03Failed to execute LQI for 'W0.FILS.HV11'
error 2024-05-16 20:29:21Failed to execute LQI for 'W0.FILS.HV1'
error 2024-05-16 20:29:39Failed to execute LQI for 'W0.FILS.HV2'
error 2024-05-16 20:29:57Failed to execute LQI for 'W0.FILS.HV5'
error 2024-05-16 20:30:15Failed to execute LQI for 'W0.FILS.HV6'
error 2024-05-16 20:30:33Failed to execute LQI for 'W0.FILS.HV16'
info 2024-05-16 20:30:33Network scan finished

I guess the firmware on the stick crashes. Anybody has an idea to fix this? It is zStack3x0 20230507 coordinator. And I am running z2m 1.37.1

Koenkk commented 5 months ago

20230507 is not stable, try with https://github.com/Koenkk/Z-Stack-firmware/discussions/496