Koenkk / zigbee2mqtt

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

Zigbee2mqtt Home Assistant add-on doesn't start anymore #24829

Open pazzotranquillo opened 6 days ago

pazzotranquillo commented 6 days ago

What happened?

I have Home Assistant running on RPi 4 with both ZHA (USB coordinator) and Zigbee2mqtt add-on (network adapter based on SonoffZBPro with Esphome).

Since a few days SonoffZBPro doesn't start anymore. I can't say exactly when the issue started, if it was after updating HA, Zigbee2mqtt or both.

What did you expect to happen?

No response

How to reproduce it (minimal and precise)

No response

Zigbee2MQTT version

1.41.0-1 and Edge

Adapter firmware version

SonoffZBPro_coord_20240710.hex

Adapter

SonoffZBPro with Esphome

Setup

Add-on on Home Assistant on RPi 4

Debug log

[15:08:37] INFO: Preparing to start... [15:08:37] INFO: Socat not enabled [15:08:37] INFO: Starting Zigbee2MQTT... Starting Zigbee2MQTT without watchdog. [2024-11-19 15:08:43] info: z2m: Logging to console, file (filename: log.log) [2024-11-19 15:08:43] debug: z2m: Loaded state from file /config/zigbee2mqtt/state.json [2024-11-19 15:08:43] info: z2m: Starting Zigbee2MQTT version 1.41.0-dev (commit #b1508ae) [2024-11-19 15:08:43] debug: z2m: sd-notify loaded [2024-11-19 15:08:43] info: z2m: Starting zigbee-herdsman (2.1.9) [2024-11-19 15:08:43] debug: z2m: Using zigbee-herdsman with settings: '"{\"network\":{\"panID\":15348,\"extendedPanID\":[208,61,240,98,43,108,195,55],\"channelList\":[11],\"networkKey\":\"HIDDEN\"},\"databasePath\":\"/config/zigbee2mqtt/database.db\",\"databaseBackupPath\":\"/config/zigbee2mqtt/database.db.backup\",\"backupPath\":\"/config/zigbee2mqtt/coordinator_backup.json\",\"serialPort\":{\"path\":\"tcp://192.168.4.28:8888\"},\"adapter\":{\"disableLED\":false}}"' [2024-11-19 15:08:43] debug: zh:controller: Starting with options '{"network":{"networkKeyDistribute":false,"networkKey":"HIDDEN","panID":15348,"extendedPanID":[208,61,240,98,43,108,195,55],"channelList":[11]},"serialPort":{"path":"tcp://192.168.4.28:8888"},"adapter":{"disableLED":false},"databasePath":"/config/zigbee2mqtt/database.db","databaseBackupPath":"/config/zigbee2mqtt/database.db.backup","backupPath":"/config/zigbee2mqtt/coordinator_backup.json"}' [2024-11-19 15:08:43] info: zh:zstack:znp: Opening TCP socket with 192.168.4.28:8888 [2024-11-19 15:08:43] info: zh:zstack:znp: Socket connected [2024-11-19 15:08:43] info: zh:zstack:znp: Socket ready [2024-11-19 15:08:43] info: zh:zstack:znp: Writing CC2530/CC2531 skip bootloader payload [2024-11-19 15:08:43] debug: zh:zstack:unpi:writer: --> buffer [239] [2024-11-19 15:08:45] info: zh:zstack:znp: Skip bootloader for CC2652/CC1352 [2024-11-19 15:08:45] debug: zh:zstack:znp: --> SREQ: SYS - ping - {"capabilities":1} [2024-11-19 15:08:45] debug: zh:zstack:unpi:writer: --> frame [254,0,33,1,32] [2024-11-19 15:08:51] debug: zh:zstack:znp: --> SREQ: SYS - ping - {"capabilities":1} [2024-11-19 15:08:51] debug: zh:zstack:unpi:writer: --> frame [254,0,33,1,32] [2024-11-19 15:08:57] debug: zh:zstack:znp: --> SREQ: SYS - ping - {"capabilities":1} [2024-11-19 15:08:57] debug: zh:zstack:unpi:writer: --> frame [254,0,33,1,32] [2024-11-19 15:09:03] error: z2m: Error while starting zigbee-herdsman [2024-11-19 15:09:03] error: z2m: Failed to start zigbee [2024-11-19 15:09:03] error: z2m: Check https://www.zigbee2mqtt.io/guide/installation/20_zigbee2mqtt-fails-to-start.html for possible solutions [2024-11-19 15:09:03] error: z2m: Exiting... [2024-11-19 15:09:03] error: z2m: Error: Failed to connect to the adapter (Error: SRSP - SYS - ping after 6000ms) at ZStackAdapter.start (/app/node_modules/zigbee-herdsman/src/adapter/z-stack/adapter/zStackAdapter.ts:113:27) at Controller.start (/app/node_modules/zigbee-herdsman/src/controller/controller.ts:137:29) at Zigbee.start (/app/lib/zigbee.ts:69:27) at Controller.start (/app/lib/controller.ts:161:27) at start (/app/index.js:154:5)

pazzotranquillo commented 6 days ago

Here is the debug log after changing the adapter to ember

[16:02:42] INFO: Preparing to start... [16:02:42] INFO: Socat not enabled [16:02:43] INFO: Starting Zigbee2MQTT... Starting Zigbee2MQTT without watchdog. [2024-11-19 16:02:48] info: z2m: Logging to console, file (filename: log.log) [2024-11-19 16:02:48] debug: z2m: Loaded state from file /config/zigbee2mqtt/state.json [2024-11-19 16:02:48] info: z2m: Starting Zigbee2MQTT version 1.41.0-dev (commit #b1508ae) [2024-11-19 16:02:48] debug: z2m: sd-notify loaded [2024-11-19 16:02:48] info: z2m: Starting zigbee-herdsman (2.1.9) [2024-11-19 16:02:48] debug: z2m: Using zigbee-herdsman with settings: '"{\"network\":{\"panID\":15348,\"extendedPanID\":[208,61,240,98,43,108,195,55],\"channelList\":[11],\"networkKey\":\"HIDDEN\"},\"databasePath\":\"/config/zigbee2mqtt/database.db\",\"databaseBackupPath\":\"/config/zigbee2mqtt/database.db.backup\",\"backupPath\":\"/config/zigbee2mqtt/coordinator_backup.json\",\"serialPort\":{\"path\":\"tcp://192.168.4.28:8888\",\"adapter\":\"ember\"},\"adapter\":{\"disableLED\":false}}"' [2024-11-19 16:02:49] info: zh:ember: Using default stack config. [2024-11-19 16:02:49] debug: zh:controller: Starting with options '{"network":{"networkKeyDistribute":false,"networkKey":"HIDDEN","panID":15348,"extendedPanID":[208,61,240,98,43,108,195,55],"channelList":[11]},"serialPort":{"path":"tcp://192.168.4.28:8888","adapter":"ember"},"adapter":{"disableLED":false},"databasePath":"/config/zigbee2mqtt/database.db","databaseBackupPath":"/config/zigbee2mqtt/database.db.backup","backupPath":"/config/zigbee2mqtt/coordinator_backup.json"}' [2024-11-19 16:02:49] info: zh:ember: ======== Ember Adapter Starting ======== [2024-11-19 16:02:49] info: zh:ember:ezsp: ======== EZSP starting ======== [2024-11-19 16:02:49] info: zh:ember:uart:ash: ======== ASH Adapter reset ======== [2024-11-19 16:02:49] debug: zh:ember:uart:ash: Opening TCP socket with 192.168.4.28:8888 [2024-11-19 16:02:49] debug: zh:ember:uart:ash: Socket connected [2024-11-19 16:02:49] info: zh:ember:uart:ash: Socket ready [2024-11-19 16:02:49] info: zh:ember:uart:ash: ======== ASH starting ======== [2024-11-19 16:02:49] debug: zh:ember:uart:ash: ---> [FRAME type=RST] [2024-11-19 16:02:49] debug: zh:ember:uart:ash: Waiting for RSTACK... 0/2500 [2024-11-19 16:02:49] debug: zh:ember:uart:ash: Waiting for RSTACK... 100/2500 [2024-11-19 16:02:49] debug: zh:ember:uart:ash: Waiting for RSTACK... 200/2500 [2024-11-19 16:02:49] debug: zh:ember:uart:ash: Waiting for RSTACK... 300/2500 [2024-11-19 16:02:50] debug: zh:ember:uart:ash: Waiting for RSTACK... 400/2500 [2024-11-19 16:02:50] debug: zh:ember:uart:ash: Waiting for RSTACK... 500/2500 [2024-11-19 16:02:50] debug: zh:ember:uart:ash: Waiting for RSTACK... 600/2500 [2024-11-19 16:02:50] debug: zh:ember:uart:ash: Waiting for RSTACK... 700/2500 [2024-11-19 16:02:50] debug: zh:ember:uart:ash: Waiting for RSTACK... 800/2500 [2024-11-19 16:02:50] debug: zh:ember:uart:ash: Waiting for RSTACK... 900/2500 [2024-11-19 16:02:50] debug: zh:ember:uart:ash: Waiting for RSTACK... 1000/2500 [2024-11-19 16:02:50] debug: zh:ember:uart:ash: Waiting for RSTACK... 1100/2500 [2024-11-19 16:02:50] debug: zh:ember:uart:ash: Waiting for RSTACK... 1200/2500 [2024-11-19 16:02:50] debug: zh:ember:uart:ash: Waiting for RSTACK... 1300/2500 [2024-11-19 16:02:51] debug: zh:ember:uart:ash: Waiting for RSTACK... 1400/2500 [2024-11-19 16:02:51] debug: zh:ember:uart:ash: Waiting for RSTACK... 1500/2500 [2024-11-19 16:02:51] debug: zh:ember:uart:ash: Waiting for RSTACK... 1600/2500 [2024-11-19 16:02:51] debug: zh:ember:uart:ash: Waiting for RSTACK... 1700/2500 [2024-11-19 16:02:51] debug: zh:ember:uart:ash: Waiting for RSTACK... 1800/2500 [2024-11-19 16:02:51] debug: zh:ember:uart:ash: Waiting for RSTACK... 1900/2500 [2024-11-19 16:02:51] debug: zh:ember:uart:ash: Waiting for RSTACK... 2000/2500 [2024-11-19 16:02:51] debug: zh:ember:uart:ash: Waiting for RSTACK... 2100/2500 [2024-11-19 16:02:51] debug: zh:ember:uart:ash: Waiting for RSTACK... 2200/2500 [2024-11-19 16:02:51] debug: zh:ember:uart:ash: Waiting for RSTACK... 2300/2500 [2024-11-19 16:02:52] debug: zh:ember:uart:ash: Waiting for RSTACK... 2400/2500 [2024-11-19 16:02:52] info: zh:ember:uart:ash: ======== ASH Adapter reset ======== [2024-11-19 16:02:52] info: zh:ember:uart:ash: ======== ASH starting ======== [2024-11-19 16:02:52] debug: zh:ember:uart:ash: ---> [FRAME type=RST] [2024-11-19 16:02:52] debug: zh:ember:uart:ash: Waiting for RSTACK... 0/2500 [2024-11-19 16:02:52] debug: zh:ember:uart:ash: Waiting for RSTACK... 100/2500 [2024-11-19 16:02:52] debug: zh:ember:uart:ash: Waiting for RSTACK... 200/2500 [2024-11-19 16:02:52] debug: zh:ember:uart:ash: Waiting for RSTACK... 300/2500 [2024-11-19 16:02:52] debug: zh:ember:uart:ash: Waiting for RSTACK... 400/2500 [2024-11-19 16:02:52] debug: zh:ember:uart:ash: Waiting for RSTACK... 500/2500 [2024-11-19 16:02:52] debug: zh:ember:uart:ash: Waiting for RSTACK... 600/2500 [2024-11-19 16:02:52] debug: zh:ember:uart:ash: Waiting for RSTACK... 700/2500 [2024-11-19 16:02:53] debug: zh:ember:uart:ash: Waiting for RSTACK... 800/2500 [2024-11-19 16:02:53] debug: zh:ember:uart:ash: Waiting for RSTACK... 900/2500 [2024-11-19 16:02:53] debug: zh:ember:uart:ash: Waiting for RSTACK... 1000/2500 [2024-11-19 16:02:53] debug: zh:ember:uart:ash: Waiting for RSTACK... 1100/2500 [2024-11-19 16:02:53] debug: zh:ember:uart:ash: Waiting for RSTACK... 1200/2500 [2024-11-19 16:02:53] debug: zh:ember:uart:ash: Waiting for RSTACK... 1300/2500 [2024-11-19 16:02:53] debug: zh:ember:uart:ash: Waiting for RSTACK... 1400/2500 [2024-11-19 16:02:53] debug: zh:ember:uart:ash: Waiting for RSTACK... 1500/2500 [2024-11-19 16:02:53] debug: zh:ember:uart:ash: Waiting for RSTACK... 1600/2500 [2024-11-19 16:02:53] debug: zh:ember:uart:ash: Waiting for RSTACK... 1700/2500 [2024-11-19 16:02:54] debug: zh:ember:uart:ash: Waiting for RSTACK... 1800/2500 [2024-11-19 16:02:54] debug: zh:ember:uart:ash: Waiting for RSTACK... 1900/2500 [2024-11-19 16:02:54] debug: zh:ember:uart:ash: Waiting for RSTACK... 2000/2500 [2024-11-19 16:02:54] debug: zh:ember:uart:ash: Waiting for RSTACK... 2100/2500 [2024-11-19 16:02:54] debug: zh:ember:uart:ash: Waiting for RSTACK... 2200/2500 [2024-11-19 16:02:54] debug: zh:ember:uart:ash: Waiting for RSTACK... 2300/2500 [2024-11-19 16:02:54] debug: zh:ember:uart:ash: Waiting for RSTACK... 2400/2500 [2024-11-19 16:02:54] info: zh:ember:uart:ash: ======== ASH Adapter reset ======== [2024-11-19 16:02:54] info: zh:ember:uart:ash: ======== ASH starting ======== [2024-11-19 16:02:54] debug: zh:ember:uart:ash: ---> [FRAME type=RST] [2024-11-19 16:02:54] debug: zh:ember:uart:ash: Waiting for RSTACK... 0/2500 [2024-11-19 16:02:54] debug: zh:ember:uart:ash: Waiting for RSTACK... 100/2500 [2024-11-19 16:02:54] debug: zh:ember:uart:ash: Waiting for RSTACK... 200/2500 [2024-11-19 16:02:55] debug: zh:ember:uart:ash: Waiting for RSTACK... 300/2500 [2024-11-19 16:02:55] debug: zh:ember:uart:ash: Waiting for RSTACK... 400/2500 [2024-11-19 16:02:55] debug: zh:ember:uart:ash: Waiting for RSTACK... 500/2500 [2024-11-19 16:02:55] debug: zh:ember:uart:ash: Waiting for RSTACK... 600/2500 [2024-11-19 16:02:55] debug: zh:ember:uart:ash: Waiting for RSTACK... 700/2500 [2024-11-19 16:02:55] debug: zh:ember:uart:ash: Waiting for RSTACK... 800/2500 [2024-11-19 16:02:55] debug: zh:ember:uart:ash: Waiting for RSTACK... 900/2500 [2024-11-19 16:02:55] debug: zh:ember:uart:ash: Waiting for RSTACK... 1000/2500 [2024-11-19 16:02:55] debug: zh:ember:uart:ash: Waiting for RSTACK... 1100/2500 [2024-11-19 16:02:55] debug: zh:ember:uart:ash: Waiting for RSTACK... 1200/2500 [2024-11-19 16:02:56] debug: zh:ember:uart:ash: Waiting for RSTACK... 1300/2500 [2024-11-19 16:02:56] debug: zh:ember:uart:ash: Waiting for RSTACK... 1400/2500 [2024-11-19 16:02:56] debug: zh:ember:uart:ash: Waiting for RSTACK... 1500/2500 [2024-11-19 16:02:56] debug: zh:ember:uart:ash: Waiting for RSTACK... 1600/2500 [2024-11-19 16:02:56] debug: zh:ember:uart:ash: Waiting for RSTACK... 1700/2500 [2024-11-19 16:02:56] debug: zh:ember:uart:ash: Waiting for RSTACK... 1800/2500 [2024-11-19 16:02:56] debug: zh:ember:uart:ash: Waiting for RSTACK... 1900/2500 [2024-11-19 16:02:56] debug: zh:ember:uart:ash: Waiting for RSTACK... 2000/2500 [2024-11-19 16:02:56] debug: zh:ember:uart:ash: Waiting for RSTACK... 2100/2500 [2024-11-19 16:02:56] debug: zh:ember:uart:ash: Waiting for RSTACK... 2200/2500 [2024-11-19 16:02:57] debug: zh:ember:uart:ash: Waiting for RSTACK... 2300/2500 [2024-11-19 16:02:57] debug: zh:ember:uart:ash: Waiting for RSTACK... 2400/2500 [2024-11-19 16:02:57] info: zh:ember:uart:ash: ======== ASH Adapter reset ======== [2024-11-19 16:02:57] info: zh:ember:uart:ash: ======== ASH starting ======== [2024-11-19 16:02:57] debug: zh:ember:uart:ash: ---> [FRAME type=RST] [2024-11-19 16:02:57] debug: zh:ember:uart:ash: Waiting for RSTACK... 0/2500 [2024-11-19 16:02:57] debug: zh:ember:uart:ash: Waiting for RSTACK... 100/2500 [2024-11-19 16:02:57] debug: zh:ember:uart:ash: Waiting for RSTACK... 200/2500 [2024-11-19 16:02:57] debug: zh:ember:uart:ash: Waiting for RSTACK... 300/2500 [2024-11-19 16:02:57] debug: zh:ember:uart:ash: Waiting for RSTACK... 400/2500 [2024-11-19 16:02:57] debug: zh:ember:uart:ash: Waiting for RSTACK... 500/2500 [2024-11-19 16:02:57] debug: zh:ember:uart:ash: Waiting for RSTACK... 600/2500 [2024-11-19 16:02:58] debug: zh:ember:uart:ash: Waiting for RSTACK... 700/2500 [2024-11-19 16:02:58] debug: zh:ember:uart:ash: Waiting for RSTACK... 800/2500 [2024-11-19 16:02:58] debug: zh:ember:uart:ash: Waiting for RSTACK... 900/2500 [2024-11-19 16:02:58] debug: zh:ember:uart:ash: Waiting for RSTACK... 1000/2500 [2024-11-19 16:02:58] debug: zh:ember:uart:ash: Waiting for RSTACK... 1100/2500 [2024-11-19 16:02:58] debug: zh:ember:uart:ash: Waiting for RSTACK... 1200/2500 [2024-11-19 16:02:58] debug: zh:ember:uart:ash: Waiting for RSTACK... 1300/2500 [2024-11-19 16:02:58] debug: zh:ember:uart:ash: Waiting for RSTACK... 1400/2500 [2024-11-19 16:02:58] debug: zh:ember:uart:ash: Waiting for RSTACK... 1500/2500 [2024-11-19 16:02:58] debug: zh:ember:uart:ash: Waiting for RSTACK... 1600/2500 [2024-11-19 16:02:59] debug: zh:ember:uart:ash: Waiting for RSTACK... 1700/2500 [2024-11-19 16:02:59] debug: zh:ember:uart:ash: Waiting for RSTACK... 1800/2500 [2024-11-19 16:02:59] debug: zh:ember:uart:ash: Waiting for RSTACK... 1900/2500 [2024-11-19 16:02:59] debug: zh:ember:uart:ash: Waiting for RSTACK... 2000/2500 [2024-11-19 16:02:59] debug: zh:ember:uart:ash: Waiting for RSTACK... 2100/2500 [2024-11-19 16:02:59] debug: zh:ember:uart:ash: Waiting for RSTACK... 2200/2500 [2024-11-19 16:02:59] debug: zh:ember:uart:ash: Waiting for RSTACK... 2300/2500 [2024-11-19 16:02:59] debug: zh:ember:uart:ash: Waiting for RSTACK... 2400/2500 [2024-11-19 16:02:59] info: zh:ember:uart:ash: ======== ASH Adapter reset ======== [2024-11-19 16:02:59] info: zh:ember:uart:ash: ======== ASH starting ======== [2024-11-19 16:02:59] debug: zh:ember:uart:ash: ---> [FRAME type=RST] [2024-11-19 16:02:59] debug: zh:ember:uart:ash: Waiting for RSTACK... 0/2500 [2024-11-19 16:02:59] debug: zh:ember:uart:ash: Waiting for RSTACK... 100/2500 [2024-11-19 16:03:00] debug: zh:ember:uart:ash: Waiting for RSTACK... 200/2500 [2024-11-19 16:03:00] debug: zh:ember:uart:ash: Waiting for RSTACK... 300/2500 [2024-11-19 16:03:00] debug: zh:ember:uart:ash: Waiting for RSTACK... 400/2500 [2024-11-19 16:03:00] debug: zh:ember:uart:ash: Waiting for RSTACK... 500/2500 [2024-11-19 16:03:00] debug: zh:ember:uart:ash: Waiting for RSTACK... 600/2500 [2024-11-19 16:03:00] debug: zh:ember:uart:ash: Waiting for RSTACK... 700/2500 [2024-11-19 16:03:00] debug: zh:ember:uart:ash: Waiting for RSTACK... 800/2500 [2024-11-19 16:03:00] debug: zh:ember:uart:ash: Waiting for RSTACK... 900/2500 [2024-11-19 16:03:00] debug: zh:ember:uart:ash: Waiting for RSTACK... 1000/2500 [2024-11-19 16:03:00] debug: zh:ember:uart:ash: Waiting for RSTACK... 1100/2500 [2024-11-19 16:03:01] debug: zh:ember:uart:ash: Waiting for RSTACK... 1200/2500 [2024-11-19 16:03:01] debug: zh:ember:uart:ash: Waiting for RSTACK... 1300/2500 [2024-11-19 16:03:01] debug: zh:ember:uart:ash: Waiting for RSTACK... 1400/2500 [2024-11-19 16:03:01] debug: zh:ember:uart:ash: Waiting for RSTACK... 1500/2500 [2024-11-19 16:03:01] debug: zh:ember:uart:ash: Waiting for RSTACK... 1600/2500 [2024-11-19 16:03:01] debug: zh:ember:uart:ash: Waiting for RSTACK... 1700/2500 [2024-11-19 16:03:01] debug: zh:ember:uart:ash: Waiting for RSTACK... 1800/2500 [2024-11-19 16:03:01] debug: zh:ember:uart:ash: Waiting for RSTACK... 1900/2500 [2024-11-19 16:03:01] debug: zh:ember:uart:ash: Waiting for RSTACK... 2000/2500 [2024-11-19 16:03:01] debug: zh:ember:uart:ash: Waiting for RSTACK... 2100/2500 [2024-11-19 16:03:02] debug: zh:ember:uart:ash: Waiting for RSTACK... 2200/2500 [2024-11-19 16:03:02] debug: zh:ember:uart:ash: Waiting for RSTACK... 2300/2500 [2024-11-19 16:03:02] debug: zh:ember:uart:ash: Waiting for RSTACK... 2400/2500 [2024-11-19 16:03:02] error: z2m: Error while starting zigbee-herdsman [2024-11-19 16:03:02] error: z2m: Failed to start zigbee [2024-11-19 16:03:02] error: z2m: Check https://www.zigbee2mqtt.io/guide/installation/20_zigbee2mqtt-fails-to-start.html for possible solutions [2024-11-19 16:03:02] error: z2m: Exiting... [2024-11-19 16:03:02] error: z2m: Error: Failed to start EZSP layer with status=HOST_FATAL_ERROR. at EmberAdapter.initEzsp (/app/node_modules/zigbee-herdsman/src/adapter/ember/adapter/emberAdapter.ts:684:19) at EmberAdapter.start (/app/node_modules/zigbee-herdsman/src/adapter/ember/adapter/emberAdapter.ts:1598:24) at Controller.start (/app/node_modules/zigbee-herdsman/src/controller/controller.ts:137:29) at Zigbee.start (/app/lib/zigbee.ts:69:27) at Controller.start (/app/lib/controller.ts:161:27) at start (/app/index.js:154:5)