Koenkk / zigbee2mqtt

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

All devices unreachable after ~48 hours #24391

Open mg180 opened 4 weeks ago

mg180 commented 4 weeks ago

What happened?

Approximately every 48 hours, all devices on the network become unreachable. Zigbe2mqtt itself doesn't crash, but will not re-establish contact with devices without manually restarting. This has happened about 9 or 10 times now over the past few weeks.

There is nothing obvious at default log settings, but there are some stack traces when enabling debug logging.

What did you expect to happen?

No response

How to reproduce it (minimal and precise)

Happens by itself every couple of days.

Zigbee2MQTT version

1.40.2-1

Adapter firmware version

20220219

Adapter

Sonoff ZB Dongle-P

Setup

Pi4

Debug log

[2024-10-18 10:31:33] debug: zh:zstack:unpi:writer: --> frame [254,15,36,1,184,71,11,1,0,0,7,0,30,5,16,141,0,0,0,94] [2024-10-18 10:31:39] debug: zh:controller:endpoint: Error: ZCL command 0x00178801026ff389/11 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 (/app/node_modules/zigbee-herdsman/src/utils/waitress.ts:59:23) at /app/node_modules/zigbee-herdsman/src/adapter/z-stack/znp/znp.ts:285:45 at Queue.execute (/app/node_modules/zigbee-herdsman/src/utils/queue.ts:36:26) at Znp.request (/app/node_modules/zigbee-herdsman/src/adapter/z-stack/znp/znp.ts:278:27) at ZStackAdapter.dataRequest (/app/node_modules/zigbee-herdsman/src/adapter/z-stack/adapter/zStackAdapter.ts:1034:24) at ZStackAdapter.sendZclFrameToEndpointInternal (/app/node_modules/zigbee-herdsman/src/adapter/z-stack/adapter/zStackAdapter.ts:488:46) at /app/node_modules/zigbee-herdsman/src/adapter/z-stack/adapter/zStackAdapter.ts:422:31 at Queue.execute (/app/node_modules/zigbee-herdsman/src/utils/queue.ts:36:26) at ZStackAdapter.sendZclFrameToEndpoint (/app/node_modules/zigbee-herdsman/src/adapter/z-stack/adapter/zStackAdapter.ts:420:33) at Request.func (/app/node_modules/zigbee-herdsman/src/controller/model/endpoint.ts:299:36) [2024-10-18 10:31:39] warning: z2m: Failed to ping 'Hall Inner' (attempt 1/1, ZCL command 0x00178801026ff389/11 genBasic.read(["zclVersion"], {"timeout":10000,"disableResponse":false,"disableRecovery":true,"disableDefaultResponse":true,"direction":0,"reservedBits":0,"writeUndiv":false}) failed (SRSP - AF - dataRequest after 6000ms)) [2024-10-18 10:31:39] debug: z2m: Active device 'Hall Inner' was last seen '506.73' minutes ago. [2024-10-18 10:31:49] debug: z2m: Saving state to file /config/zigbee2mqtt/state.json [2024-10-18 10:31:50] debug: zh:controller:endpoint: ZCL command 0xdc8e95fffe19bbae/1 genBasic.read(["zclVersion"], {"timeout":10000,"disableResponse":false,"disableRecovery":true,"disableDefaultResponse":true,"direction":0,"reservedBits":0,"writeUndiv":false}) [2024-10-18 10:31:50] debug: zh:zstack: sendZclFrameToEndpointInternal 0xdc8e95fffe19bbae:52231/1 (0,0,1) [2024-10-18 10:31:50] debug: zh:zstack:znp: --> SREQ: AF - dataRequest - {"dstaddr":52231,"destendpoint":1,"srcendpoint":1,"clusterid":0,"transid":8,"options":0,"radius":30,"len":5,"data":{"type":"Buffer","data":[16,142,0,0,0]}} [2024-10-18 10:31:50] debug: zh:zstack:unpi:writer: --> frame [254,15,36,1,7,204,1,1,0,0,8,0,30,5,16,142,0,0,0,108] [2024-10-18 10:31:56] debug: zh:controller:endpoint: Error: ZCL command 0xdc8e95fffe19bbae/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 (/app/node_modules/zigbee-herdsman/src/utils/waitress.ts:59:23) at /app/node_modules/zigbee-herdsman/src/adapter/z-stack/znp/znp.ts:285:45 at Queue.execute (/app/node_modules/zigbee-herdsman/src/utils/queue.ts:36:26) at Znp.request (/app/node_modules/zigbee-herdsman/src/adapter/z-stack/znp/znp.ts:278:27) at ZStackAdapter.dataRequest (/app/node_modules/zigbee-herdsman/src/adapter/z-stack/adapter/zStackAdapter.ts:1034:24) at ZStackAdapter.sendZclFrameToEndpointInternal (/app/node_modules/zigbee-herdsman/src/adapter/z-stack/adapter/zStackAdapter.ts:488:46) at /app/node_modules/zigbee-herdsman/src/adapter/z-stack/adapter/zStackAdapter.ts:422:31 at Queue.execute (/app/node_modules/zigbee-herdsman/src/utils/queue.ts:36:26) at ZStackAdapter.sendZclFrameToEndpoint (/app/node_modules/zigbee-herdsman/src/adapter/z-stack/adapter/zStackAdapter.ts:420:33) at Request.func (/app/node_modules/zigbee-herdsman/src/controller/model/endpoint.ts:299:36) [2024-10-18 10:31:56] warning: z2m: Failed to ping 'R_Light_Outside_Side' (attempt 1/1, ZCL command 0xdc8e95fffe19bbae/1 genBasic.read(["zclVersion"], {"timeout":10000,"disableResponse":false,"disableRecovery":true,"disableDefaultResponse":true,"direction":0,"reservedBits":0,"writeUndiv":false}) failed (SRSP - AF - dataRequest after 6000ms)) [2024-10-18 10:31:56] debug: z2m: Active device 'R_Light_Outside_Side' was last seen '506.90' minutes ago. [2024-10-18 10:32:07] debug: zh:controller:endpoint: ZCL command 0xdc8e95fffe11b971/1 genBasic.read(["zclVersion"], {"timeout":10000,"disableResponse":false,"disableRecovery":true,"disableDefaultResponse":true,"direction":0,"reservedBits":0,"writeUndiv":false}) [2024-10-18 10:32:07] debug: zh:zstack: sendZclFrameToEndpointInternal 0xdc8e95fffe11b971:16077/1 (0,0,1) [2024-10-18 10:32:07] debug: zh:zstack:znp: --> SREQ: AF - dataRequest - {"dstaddr":16077,"destendpoint":1,"srcendpoint":1,"clusterid":0,"transid":9,"options":0,"radius":30,"len":5,"data":{"type":"Buffer","data":[16,143,0,0,0]}} [2024-10-18 10:32:07] debug: zh:zstack:unpi:writer: --> frame [254,15,36,1,205,62,1,1,0,0,9,0,30,5,16,143,0,0,0,84] [2024-10-18 10:32:13] debug: zh:controller:endpoint: Error: ZCL command 0xdc8e95fffe11b971/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 (/app/node_modules/zigbee-herdsman/src/utils/waitress.ts:59:23) at /app/node_modules/zigbee-herdsman/src/adapter/z-stack/znp/znp.ts:285:45 at Queue.execute (/app/node_modules/zigbee-herdsman/src/utils/queue.ts:36:26) at Znp.request (/app/node_modules/zigbee-herdsman/src/adapter/z-stack/znp/znp.ts:278:27) at ZStackAdapter.dataRequest (/app/node_modules/zigbee-herdsman/src/adapter/z-stack/adapter/zStackAdapter.ts:1034:24) at ZStackAdapter.sendZclFrameToEndpointInternal (/app/node_modules/zigbee-herdsman/src/adapter/z-stack/adapter/zStackAdapter.ts:488:46) at /app/node_modules/zigbee-herdsman/src/adapter/z-stack/adapter/zStackAdapter.ts:422:31 at Queue.execute (/app/node_modules/zigbee-herdsman/src/utils/queue.ts:36:26) at ZStackAdapter.sendZclFrameToEndpoint (/app/node_modules/zigbee-herdsman/src/adapter/z-stack/adapter/zStackAdapter.ts:420:33) at Request.func (/app/node_modules/zigbee-herdsman/src/controller/model/endpoint.ts:299:36) [2024-10-18 10:32:13] warning: z2m: Failed to ping 'R_Light_Outside_Rear' (attempt 1/1, ZCL command 0xdc8e95fffe11b971/1 genBasic.read(["zclVersion"], {"timeout":10000,"disableResponse":false,"disableRecovery":true,"disableDefaultResponse":true,"direction":0,"reservedBits":0,"writeUndiv":false}) failed (SRSP - AF - dataRequest after 6000ms)) [2024-10-18 10:32:13] debug: z2m: Active device 'R_Light_Outside_Rear' was last seen '506.87' minutes ago. [2024-10-18 10:32:24] debug: zh:controller:endpoint: ZCL command 0xccccccfffedbc168/1 genBasic.read(["zclVersion"], {"timeout":10000,"disableResponse":false,"disableRecovery":true,"disableDefaultResponse":true,"direction":0,"reservedBits":0,"writeUndiv":false}) [2024-10-18 10:32:24] debug: zh:zstack: sendZclFrameToEndpointInternal 0xccccccfffedbc168:25890/1 (0,0,1) [2024-10-18 10:32:24] debug: zh:zstack:znp: --> SREQ: AF - dataRequest - {"dstaddr":25890,"destendpoint":1,"srcendpoint":1,"clusterid":0,"transid":10,"options":0,"radius":30,"len":5,"data":{"type":"Buffer","data":[16,144,0,0,0]}} [2024-10-18 10:32:24] debug: zh:zstack:unpi:writer: --> frame [254,15,36,1,34,101,1,1,0,0,10,0,30,5,16,144,0,0,0,252] [2024-10-18 10:32:30] debug: zh:controller:endpoint: Error: ZCL command 0xccccccfffedbc168/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 (/app/node_modules/zigbee-herdsman/src/utils/waitress.ts:59:23) at /app/node_modules/zigbee-herdsman/src/adapter/z-stack/znp/znp.ts:285:45 at Queue.execute (/app/node_modules/zigbee-herdsman/src/utils/queue.ts:36:26) at Znp.request (/app/node_modules/zigbee-herdsman/src/adapter/z-stack/znp/znp.ts:278:27) at ZStackAdapter.dataRequest (/app/node_modules/zigbee-herdsman/src/adapter/z-stack/adapter/zStackAdapter.ts:1034:24) at ZStackAdapter.sendZclFrameToEndpointInternal (/app/node_modules/zigbee-herdsman/src/adapter/z-stack/adapter/zStackAdapter.ts:488:46) at /app/node_modules/zigbee-herdsman/src/adapter/z-stack/adapter/zStackAdapter.ts:422:31 at Queue.execute (/app/node_modules/zigbee-herdsman/src/utils/queue.ts:36:26) at ZStackAdapter.sendZclFrameToEndpoint (/app/node_modules/zigbee-herdsman/src/adapter/z-stack/adapter/zStackAdapter.ts:420:33) at Request.func (/app/node_modules/zigbee-herdsman/src/controller/model/endpoint.ts:299:36) [2024-10-18 10:32:30] warning: z2m: Failed to ping 'O_Eufy_Dock' (attempt 1/1, ZCL command 0xccccccfffedbc168/1 genBasic.read(["zclVersion"], {"timeout":10000,"disableResponse":false,"disableRecovery":true,"disableDefaultResponse":true,"direction":0,"reservedBits":0,"writeUndiv":false}) failed (SRSP - AF - dataRequest after 6000ms)) [2024-10-18 10:32:30] debug: z2m: Active device 'O_Eufy_Dock' was last seen '506.12' minutes ago. [2024-10-18 10:33:12] debug: zh:controller:endpoint: ZCL command 0x001788010424c57e/11 genBasic.read(["zclVersion"], {"timeout":10000,"disableResponse":false,"disableRecovery":true,"disableDefaultResponse":true,"direction":0,"reservedBits":0,"writeUndiv":false}) [2024-10-18 10:33:12] debug: zh:zstack: sendZclFrameToEndpointInternal 0x001788010424c57e:20287/11 (0,0,1) [2024-10-18 10:33:12] debug: zh:zstack:znp: --> SREQ: AF - dataRequest - {"dstaddr":20287,"destendpoint":11,"srcendpoint":1,"clusterid":0,"transid":11,"options":0,"radius":30,"len":5,"data":{"type":"Buffer","data":[16,145,0,0,0]}} [2024-10-18 10:33:12] debug: zh:zstack:unpi:writer: --> frame [254,15,36,1,63,79,11,1,0,0,11,0,30,5,16,145,0,0,0,193] [2024-10-18 10:33:18] debug: zh:controller:endpoint: Error: ZCL command 0x001788010424c57e/11 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 (/app/node_modules/zigbee-herdsman/src/utils/waitress.ts:59:23) at /app/node_modules/zigbee-herdsman/src/adapter/z-stack/znp/znp.ts:285:45 at Queue.execute (/app/node_modules/zigbee-herdsman/src/utils/queue.ts:36:26) at Znp.request (/app/node_modules/zigbee-herdsman/src/adapter/z-stack/znp/znp.ts:278:27) at ZStackAdapter.dataRequest (/app/node_modules/zigbee-herdsman/src/adapter/z-stack/adapter/zStackAdapter.ts:1034:24) at ZStackAdapter.sendZclFrameToEndpointInternal (/app/node_modules/zigbee-herdsman/src/adapter/z-stack/adapter/zStackAdapter.ts:488:46) at /app/node_modules/zigbee-herdsman/src/adapter/z-stack/adapter/zStackAdapter.ts:422:31 at Queue.execute (/app/node_modules/zigbee-herdsman/src/utils/queue.ts:36:26) at ZStackAdapter.sendZclFrameToEndpoint (/app/node_modules/zigbee-herdsman/src/adapter/z-stack/adapter/zStackAdapter.ts:420:33) at Request.func (/app/node_modules/zigbee-herdsman/src/controller/model/endpoint.ts:299:36) [2024-10-18 10:33:18] warning: z2m: Failed to ping 'Living Room Lamp 1' (attempt 1/1, ZCL command 0x001788010424c57e/11 genBasic.read(["zclVersion"],

mrmaximas commented 4 weeks ago

how about update dongle fw to latest release?

mg180 commented 4 weeks ago

Crash happened 3 times today.

I have now updated the coordinator firmware to 20240710 and will report back soon.