Zigbee2mqtt 1.21.0-1 Error while starting zigbee-herdsman

[SmartM-ui]

Hi, after updating the addon to version 1.21.0-1, I noticed that to display the cc2530 key I have to stop the addon, remove the key from the USB port, wait a few seconds, reconnect the USB key, start the addon.

I have to repeat this procedure every time I stop and start the component or simply restart it.

Returning to the previous version of the addon 1.20.0-1, however, I can restart the component and the key is seen immediately, without having to disconnect the USB key and carry out the procedure described above.

What can it be?

This is the log:

[12:57:46] INFO: Handing over control to Zigbee2mqtt Core ...

zigbee2mqtt@1.21.0 start node index.js Zigbee2MQTT:error 2021-08-04 12:58:08: Error while starting zigbee-herdsman Zigbee2MQTT:error 2021-08-04 12:58:08: Failed to start zigbee Zigbee2MQTT:error 2021-08-04 12:58:08: Check https://www.zigbee2mqtt.io/information/FAQ.html#help-zigbee2mqtt-fails-to-start for possible solutions Zigbee2MQTT:error 2021-08-04 12:58:08: Exiting... Zigbee2MQTT:error 2021-08-04 12:58:08: 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:102:27) at Controller.start (/app/node_modules/zigbee-herdsman/src/controller/controller.ts:123:29) at Zigbee.start (/app/lib/zigbee.js:67:27) at Controller.start (/app/lib/controller.js:106:27) at start (/app/index.js:94:5)

My system: HassOS: 6.2 Core: 2021.8.3 SuperVisor: 2021.06.08

Thanks

[epicurean70]

I have the exact same problem. Running zigbee2mqtt as a docker

[FimaiTech]

I also have this problem.when it running at docker.

[Koenkk]

Could you post the herdsman debug log when starting with both 1.20.0 (working situation) and 1.21.0 (non working situation)?

See https://www.zigbee2mqtt.io/information/debug.html#zigbee-herdsman-debug-logging on how to enable the herdsman debug logging. Note that this is only logged to STDOUT and not to log files.

[SmartM-ui]

Could you post the herdsman debug log when starting with both 1.20.0 (working situation) and 1.21.0 (non working situation)?

See https://www.zigbee2mqtt.io/information/debug.html#zigbee-herdsman-debug-logging on how to enable the herdsman debug logging. Note that this is only logged to STDOUT and not to log files.

Hi @Koenkk , thanks for the prompt reply. This is the code that is reported immediately after starting the addon in the working version 1.20.0-1:

[s6-init] making user provided files available at /var/run/s6/etc...exited 0. [s6-init] ensuring user provided files have correct perms...exited 0. [fix-attrs.d] applying ownership & permissions fixes... [fix-attrs.d] done. [cont-init.d] executing container initialization scripts... [cont-init.d] socat.sh: executing... [00:41:47] INFO: Socat not enabled, marking service as down [cont-init.d] socat.sh: exited 0. [cont-init.d] zigbee2mqtt.sh: executing... [00:41:47] INFO: MQTT available, fetching server detail ... [00:41:47] INFO: Previous config file found, checking backup [00:41:47] INFO: Creating backup config in '/share/zigbee2mqtt/.configuration.yaml.bk' [00:41:47] INFO: Adjusting Zigbee2mqtt core yaml config with add-on quirks ... [cont-init.d] zigbee2mqtt.sh: exited 0. [cont-init.d] done. [services.d] starting services [services.d] done. [00:41:48] INFO: Zigbee Herdsman debug logging enabled [00:41:48] INFO: Handing over control to Zigbee2mqtt Core ...

zigbee2mqtt@1.20.0 start /app node index.js 2021-08-07T22:41:50.547Z zigbee-herdsman:adapter Failed to validate path: 'Error: spawn udevadm ENOENT' 2021-08-07T22:41:50.550Z zigbee-herdsman:controller:log Starting with options '{"network":{"networkKeyDistribute":false,"networkKey":[1,3,5,7,9,11,13,15,0,2,4,6,8,10,12,13],"panID":6754,"extendedPanID":[221,221,221,221,221,221,221,221],"channelList":[11]},"serialPort":{"rtscts":false,"path":"/dev/ttyUSB0"},"databasePath":"/share/zigbee2mqtt/database.db","databaseBackupPath":"/share/zigbee2mqtt/database.db.backup","backupPath":"/share/zigbee2mqtt/coordinator_backup.json","adapter":{"disableLED":false,"concurrent":null,"delay":null}}' 2021-08-07T22:41:50.551Z zigbee-herdsman:adapter:zStack:znp:log Opening SerialPort with /dev/ttyUSB0 and {"baudRate":115200,"rtscts":false,"autoOpen":false} 2021-08-07T22:41:50.566Z zigbee-herdsman:adapter:zStack:znp:log Serialport opened 2021-08-07T22:41:51.044Z zigbee-herdsman:adapter:zStack:znp:log Writing skip bootloader payload 2021-08-07T22:41:51.045Z zigbee-herdsman:adapter:zStack:unpi:writer --> buffer [239]

2021-08-07T22:41:52.592Z zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [] 2021-08-07T22:41:52.598Z zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,14,69,132,0,0,0,0,0,8,6,9,1,5,0,0,0,0,204] 2021-08-07T22:41:52.598Z zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,14,69,132,0,0,0,0,0,8,6,9,1,5,0,0,0,0,204] 2021-08-07T22:41:52.598Z zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 14 - 2 - 5 - 132 - [0,0,0,0,0,8,6,9,1,5,0,0,0,0] - 204 2021-08-07T22:41:52.598Z zigbee-herdsman:adapter:zStack:znp:AREQ <-- ZDO - simpleDescRsp - {"srcaddr":0,"status":0,"nwkaddr":0,"len":8,"endpoint":6,"profileid":265,"deviceid":5,"deviceversion":0,"numinclusters":0,"inclusterlist":[],"numoutclusters":0,"outclusterlist":[]} 2021-08-07T22:41:52.598Z zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [] 2021-08-07T22:41:52.599Z zigbee-herdsman:adapter:zStack:znp:SREQ --> ZDO - simpleDescReq - {"dstaddr":0,"nwkaddrofinterest":0,"endpoint":5} 2021-08-07T22:41:52.599Z zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,5,37,4,0,0,0,0,5,33] 2021-08-07T22:41:52.609Z zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,1,101,4,0,96] 2021-08-07T22:41:52.609Z zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,1,101,4,0,96] 2021-08-07T22:41:52.609Z zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 1 - 3 - 5 - 4 - [0] - 96 2021-08-07T22:41:52.609Z zigbee-herdsman:adapter:zStack:znp:SRSP <-- ZDO - simpleDescReq - {"status":0} 2021-08-07T22:41:52.610Z zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [] ... ...

This is the code that is reported in the working version 1.21.0, by removing the key and putting it back: [s6-init] making user provided files available at /var/run/s6/etc...exited 0. [s6-init] ensuring user provided files have correct perms...exited 0. [fix-attrs.d] applying ownership & permissions fixes... [fix-attrs.d] done. [cont-init.d] executing container initialization scripts... [cont-init.d] socat.sh: executing... [00:59:26] INFO: Socat not enabled, marking service as down [cont-init.d] socat.sh: exited 0. [cont-init.d] zigbee2mqtt.sh: executing... [00:59:26] INFO: MQTT available, fetching server detail ... [00:59:26] INFO: Previous config file found, checking backup [00:59:26] INFO: Creating backup config in '/share/zigbee2mqtt/.configuration.yaml.bk' [00:59:27] INFO: Adjusting Zigbee2mqtt core yaml config with add-on quirks ... [cont-init.d] zigbee2mqtt.sh: exited 0. [cont-init.d] done. [services.d] starting services [services.d] done. [00:59:27] INFO: Zigbee Herdsman debug logging enabled [00:59:27] INFO: Handing over control to Zigbee2mqtt Core ...

zigbee2mqtt@1.21.0 start node index.js 2021-08-07T22:59:30.375Z zigbee-herdsman:adapter Failed to validate path: 'Error: spawn udevadm ENOENT' 2021-08-07T22:59:30.378Z zigbee-herdsman:controller:log Starting with options '{"network":{"networkKeyDistribute":false,"networkKey":[1,3,5,7,9,11,13,15,0,2,4,6,8,10,12,13],"panID":6754,"extendedPanID":[221,221,221,221,221,221,221,221],"channelList":[11]},"serialPort":{"rtscts":false,"path":"/dev/ttyUSB0"},"databasePath":"/share/zigbee2mqtt/database.db","databaseBackupPath":"/share/zigbee2mqtt/database.db.backup","backupPath":"/share/zigbee2mqtt/coordinator_backup.json","adapter":{"disableLED":false,"concurrent":null,"delay":null}}' 2021-08-07T22:59:30.379Z zigbee-herdsman:adapter:zStack:znp:log Opening SerialPort with /dev/ttyUSB0 and {"baudRate":115200,"rtscts":false,"autoOpen":false} 2021-08-07T22:59:30.405Z zigbee-herdsman:adapter:zStack:znp:log Serialport opened 2021-08-07T22:59:30.407Z zigbee-herdsman:adapter:zStack:unpi:parser <-- [236] 2021-08-07T22:59:30.408Z zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [236] 2021-08-07T22:59:30.878Z zigbee-herdsman:adapter:zStack:znp:log Writing skip bootloader payload 2021-08-07T22:59:30.879Z zigbee-herdsman:adapter:zStack:unpi:writer --> buffer [239] 2021-08-07T22:59:33.320Z zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 14 - 2 - 5 - 132 - [0,0,0,0,0,8,6,9,1,5,0,0,0,0] - 204 2021-08-07T22:59:33.320Z zigbee-herdsman:adapter:zStack:znp:AREQ <-- ZDO - simpleDescRsp - {"srcaddr":0,"status":0,"nwkaddr":0,"len":8,"endpoint":6,"profileid":265,"deviceid":5,"deviceversion":0,"numinclusters":0,"inclusterlist":[],"numoutclusters":0,"outclusterlist":[]} 2021-08-07T22:59:33.320Z zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [] ... ...

This is the code that is reported when the addon is restarted with version 1.21 and the key is no longer recognized correctly and the device sensors are no longer detected: [s6-init] making user provided files available at /var/run/s6/etc...exited 0. [s6-init] ensuring user provided files have correct perms...exited 0. [fix-attrs.d] applying ownership & permissions fixes... [fix-attrs.d] done. [cont-init.d] executing container initialization scripts... [cont-init.d] socat.sh: executing... [01:01:34] INFO: Socat not enabled, marking service as down [cont-init.d] socat.sh: exited 0. [cont-init.d] zigbee2mqtt.sh: executing... [01:01:34] INFO: MQTT available, fetching server detail ... [01:01:34] INFO: Previous config file found, checking backup [01:01:34] INFO: Creating backup config in '/share/zigbee2mqtt/.configuration.yaml.bk' [01:01:35] INFO: Adjusting Zigbee2mqtt core yaml config with add-on quirks ... [cont-init.d] zigbee2mqtt.sh: exited 0. [cont-init.d] done. [services.d] starting services [services.d] done. [01:01:35] INFO: Zigbee Herdsman debug logging enabled [01:01:35] INFO: Handing over control to Zigbee2mqtt Core ...

zigbee2mqtt@1.21.0 start node index.js 2021-08-07T23:01:38.070Z zigbee-herdsman:adapter Failed to validate path: 'Error: spawn udevadm ENOENT' 2021-08-07T23:01:38.073Z zigbee-herdsman:controller:log Starting with options '{"network":{"networkKeyDistribute":false,"networkKey":[1,3,5,7,9,11,13,15,0,2,4,6,8,10,12,13],"panID":6754,"extendedPanID":[221,221,221,221,221,221,221,221],"channelList":[11]},"serialPort":{"rtscts":false,"path":"/dev/ttyUSB0"},"databasePath":"/share/zigbee2mqtt/database.db","databaseBackupPath":"/share/zigbee2mqtt/database.db.backup","backupPath":"/share/zigbee2mqtt/coordinator_backup.json","adapter":{"disableLED":false,"concurrent":null,"delay":null}}' 2021-08-07T23:01:38.073Z zigbee-herdsman:adapter:zStack:znp:log Opening SerialPort with /dev/ttyUSB0 and {"baudRate":115200,"rtscts":false,"autoOpen":false} 2021-08-07T23:01:38.090Z zigbee-herdsman:adapter:zStack:znp:log Serialport opened 2021-08-07T23:01:38.567Z zigbee-herdsman:adapter:zStack:znp:log Writing skip bootloader payload 2021-08-07T23:01:38.567Z zigbee-herdsman:adapter:zStack:unpi:writer --> buffer [239] 2021-08-07T23:01:39.572Z zigbee-herdsman:adapter:zStack:znp:SREQ --> SYS - ping - {"capabilities":1} 2021-08-07T23:01:39.573Z zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,0,33,1,32] 2021-08-07T23:01:45.575Z zigbee-herdsman:adapter:zStack:znp:SREQ --> SYS - ping - {"capabilities":1} 2021-08-07T23:01:45.575Z zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,0,33,1,32] 2021-08-07T23:01:51.585Z zigbee-herdsman:adapter:zStack:znp:SREQ --> SYS - ping - {"capabilities":1} 2021-08-07T23:01:51.586Z zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,0,33,1,32] Zigbee2MQTT:error 2021-08-08 01:01:57: Error while starting zigbee-herdsman Zigbee2MQTT:error 2021-08-08 01:01:57: Failed to start zigbee Zigbee2MQTT:error 2021-08-08 01:01:57: Check https://www.zigbee2mqtt.io/information/FAQ.html#help-zigbee2mqtt-fails-to-start for possible solutions Zigbee2MQTT:error 2021-08-08 01:01:57: Exiting... Zigbee2MQTT:error 2021-08-08 01:01:57: 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:102:27) at Controller.start (/app/node_modules/zigbee-herdsman/src/controller/controller.ts:123:29) at Zigbee.start (/app/lib/zigbee.js:67:27) at Controller.start (/app/lib/controller.js:106:27) at start (/app/index.js:94:5) [01:01:57] INFO: Zigbee Herdsman debug logging enabled [01:01:57] INFO: Handing over control to Zigbee2mqtt Core ... zigbee2mqtt@1.21.0 start node index.js 2021-08-07T23:02:00.247Z zigbee-herdsman:adapter Failed to validate path: 'Error: spawn udevadm ENOENT' 2021-08-07T23:02:00.250Z zigbee-herdsman:controller:log Starting with options '{"network":{"networkKeyDistribute":false,"networkKey":[1,3,5,7,9,11,13,15,0,2,4,6,8,10,12,13],"panID":6754,"extendedPanID":[221,221,221,221,221,221,221,221],"channelList":[11]},"serialPort":{"rtscts":false,"path":"/dev/ttyUSB0"},"databasePath":"/share/zigbee2mqtt/database.db","databaseBackupPath":"/share/zigbee2mqtt/database.db.backup","backupPath":"/share/zigbee2mqtt/coordinator_backup.json","adapter":{"disableLED":false,"concurrent":null,"delay":null}}' 2021-08-07T23:02:00.251Z zigbee-herdsman:adapter:zStack:znp:log Opening SerialPort with /dev/ttyUSB0 and {"baudRate":115200,"rtscts":false,"autoOpen":false} 2021-08-07T23:02:00.268Z zigbee-herdsman:adapter:zStack:znp:log Serialport opened 2021-08-07T23:02:00.744Z zigbee-herdsman:adapter:zStack:znp:log Writing skip bootloader payload 2021-08-07T23:02:00.745Z zigbee-herdsman:adapter:zStack:unpi:writer --> buffer [239] 2021-08-07T23:02:01.748Z zigbee-herdsman:adapter:zStack:znp:SREQ --> SYS - ping - {"capabilities":1} 2021-08-07T23:02:01.750Z zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,0,33,1,32] 2021-08-07T23:02:07.752Z zigbee-herdsman:adapter:zStack:znp:SREQ --> SYS - ping - {"capabilities":1} 2021-08-07T23:02:07.753Z zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,0,33,1,32] 2021-08-07T23:02:13.760Z zigbee-herdsman:adapter:zStack:znp:SREQ --> SYS - ping - {"capabilities":1} 2021-08-07T23:02:13.761Z zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,0,33,1,32]

Thanks again for this amazing add-on!

[liuk4friends]

same problem here…. you can find my log below:

Zigbee2MQTT:error 2021-08-02 01:09:42: Error while starting zigbee-herdsman
Zigbee2MQTT:error 2021-08-02 01:09:42: Failed to start zigbee
Zigbee2MQTT:error 2021-08-02 01:09:42: Check https://www.zigbee2mqtt.io/information/FAQ.html#help-zigbee2mqtt-fails-to-start for possible solutions
Zigbee2MQTT:error 2021-08-02 01:09:42: Exiting...
Zigbee2MQTT:error 2021-08-02 01:09:42: 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:102:27)
    at Controller.start (/app/node_modules/zigbee-herdsman/src/controller/controller.ts:123:29)
    at Zigbee.start (/app/lib/zigbee.js:67:27)
    at Controller.start (/app/lib/controller.js:106:27)
    at start (/app/index.js:94:5))

thank you @Koenkk for your precious work

[robyevolution]

same problem here…. you can find my log below:

Zigbee2MQTT:error 2021-08-02 01:09:42: Error while starting zigbee-herdsman
Zigbee2MQTT:error 2021-08-02 01:09:42: Failed to start zigbee
Zigbee2MQTT:error 2021-08-02 01:09:42: Check https://www.zigbee2mqtt.io/information/FAQ.html#help-zigbee2mqtt-fails-to-start for possible solutions
Zigbee2MQTT:error 2021-08-02 01:09:42: Exiting...
Zigbee2MQTT:error 2021-08-02 01:09:42: 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:102:27)
    at Controller.start (/app/node_modules/zigbee-herdsman/src/controller/controller.ts:123:29)
    at Zigbee.start (/app/lib/zigbee.js:67:27)
    at Controller.start (/app/lib/controller.js:106:27)
    at start (/app/index.js:94:5))

thank you @Koenkk for your precious work

same error for me, i tried reflashing the adapter, and using a new adapter but it still has the same problem since i upgraded to 1.21, i also tried with 1.21dev but it doesn't solve the problem.

[umairyounus]

I started facing the same issue 2 days ago. I got two different adapters (LAUNCHXL-CC26X2R1 and CC2592) and getting the same issue. Below are the logs from herdsman:

  zigbee-herdsman:adapter:zStack:znp:log Serialport opened +8ms
  zigbee-herdsman:adapter:zStack:znp:log Writing skip bootloader payload +460ms
  zigbee-herdsman:adapter:zStack:unpi:writer --> buffer [239] +0ms
  zigbee-herdsman:adapter:zStack:znp:SREQ --> SYS - ping - {"capabilities":1} +0ms
  zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,0,33,1,32] +1s
  zigbee-herdsman:adapter:zStack:znp:SREQ --> SYS - ping - {"capabilities":1} +6s
  zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,0,33,1,32] +6s
  zigbee-herdsman:adapter:zStack:znp:SREQ --> SYS - ping - {"capabilities":1} +6s
  zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,0,33,1,32] +6s
Zigbee2MQTT:error 2021-08-10 12:47:49: Error while starting zigbee-herdsman
Zigbee2MQTT:error 2021-08-10 12:47:49: Failed to start zigbee```

[fabioxp7980]

Hi all, I add my experince about the same problem, using HA Supervised on a Proxmox VM, latest zigbee2mqtt edge addon (I can try with standard version but I read the problem is with the 2 addons version so I think is the same, because nothing works after a restart of the addons). Below my log, if this can help to solve the problem:

`[s6-init] making user provided files available at /var/run/s6/etc...exited 0. [s6-init] ensuring user provided files have correct perms...exited 0. [fix-attrs.d] applying ownership & permissions fixes... [fix-attrs.d] done. [cont-init.d] executing container initialization scripts... [cont-init.d] socat.sh: executing... [18:24:24] INFO: Socat not enabled, marking service as down [cont-init.d] socat.sh: exited 0. [cont-init.d] zigbee2mqtt.sh: executing... [18:24:24] INFO: MQTT available, fetching server detail ... [18:24:24] INFO: Previous config file found, checking backup [18:24:24] INFO: Creating backup config in '/share/zigbee2mqtt/.configuration.yaml.bk' [18:24:24] INFO: Adjusting Zigbee2mqtt core yaml config with add-on quirks ... [cont-init.d] zigbee2mqtt.sh: exited 0. [cont-init.d] done. [services.d] starting services [services.d] done. [18:24:25] INFO: Zigbee Herdsman debug logging enabled [18:24:25] INFO: Handing over control to Zigbee2mqtt Core ...

zigbee2mqtt@1.21.0-dev start node index.js Zigbee2MQTT:debug 2021-08-10 18:24:28: Loaded state from file /share/zigbee2mqtt/state.json Zigbee2MQTT:info 2021-08-10 18:24:28: Logging to console and directory: '/share/zigbee2mqtt/log/2021-08-10.18-24-27' filename: log.txt Zigbee2MQTT:debug 2021-08-10 18:24:28: Removing old log directory '/share/zigbee2mqtt/log/2021-08-09.21-25-19' Zigbee2MQTT:info 2021-08-10 18:24:28: Starting Zigbee2MQTT version 1.21.0-dev (commit #911c3d2) Zigbee2MQTT:info 2021-08-10 18:24:28: Starting zigbee-herdsman (0.13.127) Zigbee2MQTT:debug 2021-08-10 18:24:28: Using zigbee-herdsman with settings: '{"adapter":{"concurrent":null,"delay":null,"disableLED":false},"backupPath":"/share/zigbee2mqtt/coordinator_backup.json","databaseBackupPath":"/share/zigbee2mqtt/database.db.backup","databasePath":"/share/zigbee2mqtt/database.db","network":{"channelList":[11],"extendedPanID":[221,221,221,221,221,221,221,221],"networkKey":"HIDDEN","panID":6754},"serialPort":{"path":"/dev/ttyUSB0"}}' 2021-08-10T16:24:28.732Z zigbee-herdsman:adapter Failed to validate path: 'Error: spawn udevadm ENOENT' 2021-08-10T16:24:28.735Z zigbee-herdsman:controller:log Starting with options '{"network":{"networkKeyDistribute":false,"networkKey":[1,3,5,7,9,11,13,15,0,2,4,6,8,10,12,13],"panID":6754,"extendedPanID":[221,221,221,221,221,221,221,221],"channelList":[11]},"serialPort":{"path":"/dev/ttyUSB0"},"databasePath":"/share/zigbee2mqtt/database.db","databaseBackupPath":"/share/zigbee2mqtt/database.db.backup","backupPath":"/share/zigbee2mqtt/coordinator_backup.json","adapter":{"disableLED":false,"concurrent":null,"delay":null}}' 2021-08-10T16:24:28.736Z zigbee-herdsman:adapter:zStack:znp:log Opening SerialPort with /dev/ttyUSB0 and {"baudRate":115200,"rtscts":false,"autoOpen":false} 2021-08-10T16:24:28.745Z zigbee-herdsman:adapter:zStack:znp:log Serialport opened 2021-08-10T16:24:29.204Z zigbee-herdsman:adapter:zStack:znp:log Writing skip bootloader payload 2021-08-10T16:24:29.205Z zigbee-herdsman:adapter:zStack:unpi:writer --> buffer [239] 2021-08-10T16:24:30.209Z zigbee-herdsman:adapter:zStack:znp:SREQ --> SYS - ping - {"capabilities":1} 2021-08-10T16:24:30.211Z zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,0,33,1,32] 2021-08-10T16:24:36.214Z zigbee-herdsman:adapter:zStack:znp:SREQ --> SYS - ping - {"capabilities":1} 2021-08-10T16:24:36.215Z zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,0,33,1,32] 2021-08-10T16:24:42.220Z zigbee-herdsman:adapter:zStack:znp:SREQ --> SYS - ping - {"capabilities":1} 2021-08-10T16:24:42.221Z zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,0,33,1,32] Zigbee2MQTT:error 2021-08-10 18:24:48: Error while starting zigbee-herdsman Zigbee2MQTT:error 2021-08-10 18:24:48: Failed to start zigbee Zigbee2MQTT:error 2021-08-10 18:24:48: Check https://www.zigbee2mqtt.io/information/FAQ.html#help-zigbee2mqtt-fails-to-start for possible solutions Zigbee2MQTT:error 2021-08-10 18:24:48: Exiting... Zigbee2MQTT:error 2021-08-10 18:24:48: 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:102:27) at Controller.start (/app/node_modules/zigbee-herdsman/src/controller/controller.ts:123:29) at Zigbee.start (/app/lib/zigbee.js:67:27) at Controller.start (/app/lib/controller.js:106:27) at start (/app/index.js:94:5) [18:24:48] INFO: Zigbee Herdsman debug logging enabled [18:24:48] INFO: Handing over control to Zigbee2mqtt Core ... zigbee2mqtt@1.21.0-dev start node index.js`

My zigbee key are not flashable so I expect such a big project to continue being compatible with all kinds of zigbee keys, otherwise I don't see advantages to use zigbee over other connections, but we are all here to help solve problems.

[jcastro]

Hello, Having the same problem as well. It's been working flawlessly for months before this happening. I also upgraded the usb stick (Zzh! CC2652R) to the latest version.

Is there a way to make this work back again? Is it possible to maybe install previous 1.20 version? Thanks!

[s6-init] making user provided files available at /var/run/s6/etc...exited 0.
[s6-init] ensuring user provided files have correct perms...exited 0.
[fix-attrs.d] applying ownership & permissions fixes...
[fix-attrs.d] done.
[cont-init.d] executing container initialization scripts...
[cont-init.d] socat.sh: executing... 
[00:25:46] INFO: Socat not enabled, marking service as down
[cont-init.d] socat.sh: exited 0.
[cont-init.d] zigbee2mqtt.sh: executing... 
[00:25:47] INFO: MQTT available, fetching server detail ...
[00:25:47] INFO: MQTT server settings not configured, trying to auto-discovering ...
[00:25:47] INFO: Configuring 'mqtt://core-mosquitto:1883' mqtt server
[00:25:47] INFO: MQTT credentials not configured, trying to auto-discovering ...
[00:25:47] INFO: Configuring'addons' mqtt user
[00:25:47] INFO: Previous config file found, checking backup
[00:25:47] INFO: Creating backup config in '/config/zigbee2mqtt/.configuration.yaml.bk'
[00:25:47] INFO: Adjusting Zigbee2mqtt core yaml config with add-on quirks ...
[cont-init.d] zigbee2mqtt.sh: exited 0.
[cont-init.d] done.
[services.d] starting services
[services.d] done.
[00:25:48] INFO: Zigbee Herdsman debug logging enabled
[00:25:48] INFO: Handing over control to Zigbee2mqtt Core ...
> zigbee2mqtt@1.21.0 start
> node index.js
2021-08-10T22:25:51.388Z zigbee-herdsman:adapter Failed to validate path: 'Error: spawn udevadm ENOENT'
2021-08-10T22:25:51.400Z zigbee-herdsman:controller:log Starting with options '{"network":{"networkKeyDistribute":false,"networkKey":[1,3,5,7,9,11,13,15,0,2,4,6,8,10,12,13],"panID":6754,"extendedPanID":[221,221,221,221,221,221,221,221],"channelList":[11]},"serialPort":{"path":"/dev/serial/by-id/usb-1a86_USB_Serial-if00-port0"},"databasePath":"/config/zigbee2mqtt/database.db","databaseBackupPath":"/config/zigbee2mqtt/database.db.backup","backupPath":"/config/zigbee2mqtt/coordinator_backup.json","adapter":{"disableLED":false,"concurrent":null,"delay":null}}'
2021-08-10T22:25:51.401Z zigbee-herdsman:adapter:zStack:znp:log Opening SerialPort with /dev/serial/by-id/usb-1a86_USB_Serial-if00-port0 and {"baudRate":115200,"rtscts":false,"autoOpen":false}
2021-08-10T22:25:51.408Z zigbee-herdsman:adapter:zStack:znp:log Serialport opened

EDIT: Not entirely sure what happened or what I did, but without changing any configuration other than setting log_level: debug now it seems to be working

[ykiv63]

Same error for me with CC2530

[maxcanna]

Same error for me with CC2530

Please guys, please, avoid "me too" posts

[jcastro]

Oh I realised what I've changed, I switch the USB stick to another port and restarted the whole computer

[SmartM-ui]

Oh I realised what I've changed, I switch the USB stick to another port and restarted the whole computer

If I restart the computer, even without changing the USB port, the addon restarts, but the problem recurs if you restart the addon without restarting the computer

[jcastro]

Oh I realised what I've changed, I switch the USB stick to another port and restarted the whole computer

If I restart the computer, even without changing the USB port, the addon restarts, but the problem recurs if you restart the addon without restarting the computer

That's true! it seems only a temporary solution

[michelebossa]

Hi, I have the same issue there is a way to came back to previous version with addon?

Thanks

[epicurean70]

I found that if I unplug the zigbee stick from the usb port and replug it again, and then restart the zigbee2mqtt container, it would be ok. But its only temporary. my log is exactly the same as @robyevolution

[maxcanna]

Hi, I have the same issue there is a way to came back to previous version with addon?

Thanks

Avoid this kind of messages. They don't add anything useful but spam everyone. Furthermore you're off topic

[YassineBenayad]

Hello,

have the same issue since I migrated to z2m 1.21. I'm using a CC2530+CC2591, the same setup works perfectly well if I down grade to version 1.18-1 or 1.17.0-1 (Home Assistant Add-on). this issue seems to be directly related to #8376 and @#8452

Regards

[SmartM-ui]

Hi @Koenkk I have not read directions on resolving this problem in your latest version of the addon (1.21.1-1) Not being very present in the home and not being able to allow me to do tests, could you tell me if you managed to solve this problem and if you need further information to deal with it? Thanks again!

[Koenkk]

Please provide the herdsman debug logging.

See https://www.zigbee2mqtt.io/information/debug.html#zigbee-herdsman-debug-logging on how to enable the herdsman debug logging. Note that this is only logged to STDOUT and not to log files.

for the addon you can grab the logs by executing: docker logs ZIGBEE2MQTT_CONTAINER_ID > log.txt 2>&1

[SmartM-ui]

Please provide the herdsman debug logging.

See https://www.zigbee2mqtt.io/information/debug.html#zigbee-herdsman-debug-logging on how to enable the herdsman debug logging. Note that this is only logged to STDOUT and not to log files.

for the addon you can grab the logs by executing: docker logs ZIGBEE2MQTT_CONTAINER_ID > log.txt 2>&1

Hi @Koenkk Thank you for answering.

Having HassOS, I had enabled Zigbee-herdsman debug logging with the procedure described in the paragraph for Home Assistant OS / Supervised addon and had reported the log here:

https://github.com/Koenkk/zigbee2mqtt/issues/8282#issuecomment-894716998

Can it fit?

Thanks again

[Koenkk]

@SmartM-ui if you see Failed to connect to the adapter (Error: SRSP - SYS - ping after 6000ms) it means zigbee2mqtt cannot contact the adapter.

Try reflashing the fw of your adapter and verify the path:

• https://www.zigbee2mqtt.io/information/FAQ.html#error-srsp---sys---ping-after-6000ms
• https://www.zigbee2mqtt.io/getting_started/running_zigbee2mqtt.html#1-determine-location-of-the-adapter-and-checking-user-permissions

[SmartM-ui]

@SmartM-ui if you see Failed to connect to the adapter (Error: SRSP - SYS - ping after 6000ms) it means zigbee2mqtt cannot contact the adapter.

Try reflashing the fw of your adapter and verify the path:

* https://www.zigbee2mqtt.io/information/FAQ.html#error-srsp---sys---ping-after-6000ms

* https://www.zigbee2mqtt.io/getting_started/running_zigbee2mqtt.html#1-determine-location-of-the-adapter-and-checking-user-permissions

But has anything changed in terms of the course from 1.20.0-1 to 1.21.x? Because with 1.20.0-1 it works perfectly. Many friends who have the same dongle as mine (CC2530 + CC2590) complain about the same problem since version 1.21. The strange thing is that if I unplug the key, restart the host, and reconnect the key, it is seen until the addon is restarted. However, I try to verify the correctness of the path. Thanks

[Koenkk]

So after downgrading back to 1.20.0 it works again?

[SmartM-ui]

So after downgrading back to 1.20.0 it works again?

YES! The problem only occurs from 1.21.x.

[robyevolution]

I had this problem going from 1.90 to 1.20 and it persists even with 1.21, I tried with another adapter flashed, the permissions are OK, I solve by disconnecting and reconnecting the adapter but it is not a comfortable solution

[snakuzzo]

Hi @Koenkk I tried my CC2530 (Z-Stack 3.0) on zigbee2mqtt 1.21 (Docker container) ... there is strange behavior

• Connect CC2530 via USB
• Start Zigbee2mqtt 1.21
• Everything works fine...

Attaching to zigbee2mqtt-dev
Using '/app/data' as data directory
Zigbee2MQTT:debug 2021-09-02 21:40:45: Loaded state from file /app/data/state.json
Zigbee2MQTT:info  2021-09-02 21:40:45: Logging to console and directory: '/var/log/zigbee2mqtt' filename: log.txt
Zigbee2MQTT:info  2021-09-02 21:40:45: Starting Zigbee2MQTT version 1.21.1 (commit #eb5750d
)
Zigbee2MQTT:info  2021-09-02 21:40:45: Starting zigbee-herdsman (0.13.138)
Zigbee2MQTT:debug 2021-09-02 21:40:45: Using zigbee-herdsman with settings: '{"adapter":{"concurrent":null,"delay":null,"disableLED":false},"backupPath":"/app/data/coordinator_backup.json","databaseBackupPath":"/app/data/database.db.backup","databasePath":"/app/data/database.db","network":{"channelList":[11],"extendedPanID":[221,221,221,221,221,221,221,221],"networkKey":"HIDDEN","panID":6754},"serialPort":{"path":"/dev/ttyUSB0"}}'
2021-09-02T19:40:45.269Z zigbee-herdsman:controller:log Starting with options '{"network":{"networkKeyDistribute":false,"networkKey":[1,3,5,7,9,11,13,15,0,2,4,6,8,10,12,13],"panID":6754,"extendedPanID":[221,221,221,221,221,221,221,221],"channelList":[11]},"serialPort":{"path":"/dev/ttyUSB0"},"databasePath":"/app/data/database.db","databaseBackupPath":"/app/data/database.db.backup","backupPath":"/app/data/coordinator_backup.json","adapter":{"disableLED":false,"concurrent":null,"delay":null}}'
2021-09-02T19:40:45.269Z zigbee-herdsman:adapter:zStack:znp:log Opening SerialPort with /dev/ttyUSB0 and {"baudRate":115200,"rtscts":false,"autoOpen":false}
2021-09-02T19:40:45.272Z zigbee-herdsman:adapter:zStack:znp:log Serialport opened
2021-09-02T19:40:45.729Z zigbee-herdsman:adapter:zStack:znp:log Writing skip bootloader payload
2021-09-02T19:40:45.730Z zigbee-herdsman:adapter:zStack:unpi:writer --> buffer [239]
2021-09-02T19:40:46.735Z zigbee-herdsman:adapter:zStack:znp:SREQ --> SYS - ping - {"capabilities":1}
2021-09-02T19:40:46.737Z zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,0,33,1,32]
2021-09-02T19:40:46.744Z zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,2,97,1,121,7,28]
2021-09-02T19:40:46.744Z zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,2,97,1,121,7,28]
2021-09-02T19:40:46.745Z zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 2 - 3 - 1 - 1 - [121,7] - 28
2021-09-02T19:40:46.745Z zigbee-herdsman:adapter:zStack:znp:SRSP <-- SYS - ping - {"capabilities":1913}
2021-09-02T19:40:46.746Z zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext []
2021-09-02T19:40:46.746Z zigbee-herdsman:adapter:zStack:znp:SREQ --> SYS - version - {}
2021-09-02T19:40:46.746Z zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,0,33,2,35]
2021-09-02T19:40:46.754Z zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,14,97,2,2,2,2,7,2,59,21,52,1,2,0,0,0,0,115]
2021-09-02T19:40:46.754Z zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,14,97,2,2,2,2,7,2,59,21,52,1,2,0,0,0,0,115]
2021-09-02T19:40:46.754Z zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 14 - 3 - 1 - 2 - [2,2,2,7,2,59,21,52,1,2,0,0,0,0] - 115
2021-09-02T19:40:46.755Z zigbee-herdsman:adapter:zStack:znp:SRSP <-- SYS - version - {"transportrev":2,"product":2,"majorrel":2,"minorrel":7,"maintrel":2,"revision":20190523}
2021-09-02T19:40:46.755Z zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext []
2021-09-02T19:40:46.755Z zigbee-herdsman:adapter:zStack:adapter Adapter concurrent: 2
2021-09-02T19:40:46.755Z zigbee-herdsman:adapter:zStack:adapter Detected znp version 'zStack30x' ({"transportrev":2,"product":2,"majorrel":2,"minorrel":7,"maintrel":2,"revision":20190523})
...
...

• Stop Zigbee2mqtt
• Start Zigbee2mqtt and... it doesn't work...

Zigbee2MQTT:debug 2021-09-02 21:43:00: Loaded state from file /app/data/state.json
Zigbee2MQTT:info  2021-09-02 21:43:00: Logging to console and directory: '/var/log/zigbee2mqtt' filename: log.txt
Zigbee2MQTT:info  2021-09-02 21:43:00: Starting Zigbee2MQTT version 1.21.1 (commit #eb5750d
)
Zigbee2MQTT:info  2021-09-02 21:43:00: Starting zigbee-herdsman (0.13.138)
Zigbee2MQTT:debug 2021-09-02 21:43:00: Using zigbee-herdsman with settings: '{"adapter":{"concurrent":null,"delay":null,"disableLED":false},"backupPath":"/app/data/coordinator_backup.json","databaseBackupPath":"/app/data/database.db.backup","databasePath":"/app/data/database.db","network":{"channelList":[11],"extendedPanID":[221,221,221,221,221,221,221,221],"networkKey":"HIDDEN","panID":6754},"serialPort":{"path":"/dev/ttyUSB0"}}'
2021-09-02T19:43:00.362Z zigbee-herdsman:controller:log Starting with options '{"network":{"networkKeyDistribute":false,"networkKey":[1,3,5,7,9,11,13,15,0,2,4,6,8,10,12,13],"panID":6754,"extendedPanID":[221,221,221,221,221,221,221,221],"channelList":[11]},"serialPort":{"path":"/dev/ttyUSB0"},"databasePath":"/app/data/database.db","databaseBackupPath":"/app/data/database.db.backup","backupPath":"/app/data/coordinator_backup.json","adapter":{"disableLED":false,"concurrent":null,"delay":null}}'
2021-09-02T19:43:00.362Z zigbee-herdsman:adapter:zStack:znp:log Opening SerialPort with /dev/ttyUSB0 and {"baudRate":115200,"rtscts":false,"autoOpen":false}
2021-09-02T19:43:00.365Z zigbee-herdsman:adapter:zStack:znp:log Serialport opened
2021-09-02T19:43:00.822Z zigbee-herdsman:adapter:zStack:znp:log Writing skip bootloader payload
2021-09-02T19:43:00.823Z zigbee-herdsman:adapter:zStack:unpi:writer --> buffer [239]
2021-09-02T19:43:01.829Z zigbee-herdsman:adapter:zStack:znp:SREQ --> SYS - ping - {"capabilities":1}
2021-09-02T19:43:01.831Z zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,0,33,1,32]
2021-09-02T19:43:07.832Z zigbee-herdsman:adapter:zStack:znp:SREQ --> SYS - ping - {"capabilities":1}
2021-09-02T19:43:07.833Z zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,0,33,1,32]
2021-09-02T19:43:13.839Z zigbee-herdsman:adapter:zStack:znp:SREQ --> SYS - ping - {"capabilities":1}
2021-09-02T19:43:13.840Z zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,0,33,1,32]
Zigbee2MQTT:error 2021-09-02 21:43:19: Error while starting zigbee-herdsman
Zigbee2MQTT:error 2021-09-02 21:43:19: Failed to start zigbee
Zigbee2MQTT:error 2021-09-02 21:43:19: Check https://www.zigbee2mqtt.io/information/FAQ.html#help-zigbee2mqtt-fails-to-start for possible solutions
Zigbee2MQTT:error 2021-09-02 21:43:19: Exiting...
Zigbee2MQTT:error 2021-09-02 21:43:19: 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:102:27)
    at Controller.start (/app/node_modules/zigbee-herdsman/src/controller/controller.ts:123:29)
    at Zigbee.start (/app/lib/zigbee.js:66:27)
    at Controller.start (/app/lib/controller.js:110:27)
    at start (/app/index.js:95:5)

If I remove and reconnect CC2530... It starts fine again.

I've tried at least 10 times and the behavior is always the same... If I remove and reconnect CC250 it works. if I restart without reconnecting CC2530 it doesn't work

[andreasbrett]

Agree. Updated to 1.21.x today and had to restart due to some issues. Doesn't come up and shows

error 2021-09-02 23:56:50: Error while starting zigbee-herdsman

Works when removing the CC2531 before starting z2m.

[SmartM-ui]

Hi @Koenkk I tried my CC2530 (Z-Stack 3.0) on zigbee2mqtt 1.21 (Docker container) ... there is strange behavior

* Connect CC2530 via USB

* Start Zigbee2mqtt 1.21

* Everything works fine...

Attaching to zigbee2mqtt-dev
Using '/app/data' as data directory
Zigbee2MQTT:debug 2021-09-02 21:40:45: Loaded state from file /app/data/state.json
Zigbee2MQTT:info  2021-09-02 21:40:45: Logging to console and directory: '/var/log/zigbee2mqtt' filename: log.txt
Zigbee2MQTT:info  2021-09-02 21:40:45: Starting Zigbee2MQTT version 1.21.1 (commit #eb5750d
)
Zigbee2MQTT:info  2021-09-02 21:40:45: Starting zigbee-herdsman (0.13.138)
Zigbee2MQTT:debug 2021-09-02 21:40:45: Using zigbee-herdsman with settings: '{"adapter":{"concurrent":null,"delay":null,"disableLED":false},"backupPath":"/app/data/coordinator_backup.json","databaseBackupPath":"/app/data/database.db.backup","databasePath":"/app/data/database.db","network":{"channelList":[11],"extendedPanID":[221,221,221,221,221,221,221,221],"networkKey":"HIDDEN","panID":6754},"serialPort":{"path":"/dev/ttyUSB0"}}'
2021-09-02T19:40:45.269Z zigbee-herdsman:controller:log Starting with options '{"network":{"networkKeyDistribute":false,"networkKey":[1,3,5,7,9,11,13,15,0,2,4,6,8,10,12,13],"panID":6754,"extendedPanID":[221,221,221,221,221,221,221,221],"channelList":[11]},"serialPort":{"path":"/dev/ttyUSB0"},"databasePath":"/app/data/database.db","databaseBackupPath":"/app/data/database.db.backup","backupPath":"/app/data/coordinator_backup.json","adapter":{"disableLED":false,"concurrent":null,"delay":null}}'
2021-09-02T19:40:45.269Z zigbee-herdsman:adapter:zStack:znp:log Opening SerialPort with /dev/ttyUSB0 and {"baudRate":115200,"rtscts":false,"autoOpen":false}
2021-09-02T19:40:45.272Z zigbee-herdsman:adapter:zStack:znp:log Serialport opened
2021-09-02T19:40:45.729Z zigbee-herdsman:adapter:zStack:znp:log Writing skip bootloader payload
2021-09-02T19:40:45.730Z zigbee-herdsman:adapter:zStack:unpi:writer --> buffer [239]
2021-09-02T19:40:46.735Z zigbee-herdsman:adapter:zStack:znp:SREQ --> SYS - ping - {"capabilities":1}
2021-09-02T19:40:46.737Z zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,0,33,1,32]
2021-09-02T19:40:46.744Z zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,2,97,1,121,7,28]
2021-09-02T19:40:46.744Z zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,2,97,1,121,7,28]
2021-09-02T19:40:46.745Z zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 2 - 3 - 1 - 1 - [121,7] - 28
2021-09-02T19:40:46.745Z zigbee-herdsman:adapter:zStack:znp:SRSP <-- SYS - ping - {"capabilities":1913}
2021-09-02T19:40:46.746Z zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext []
2021-09-02T19:40:46.746Z zigbee-herdsman:adapter:zStack:znp:SREQ --> SYS - version - {}
2021-09-02T19:40:46.746Z zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,0,33,2,35]
2021-09-02T19:40:46.754Z zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,14,97,2,2,2,2,7,2,59,21,52,1,2,0,0,0,0,115]
2021-09-02T19:40:46.754Z zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,14,97,2,2,2,2,7,2,59,21,52,1,2,0,0,0,0,115]
2021-09-02T19:40:46.754Z zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 14 - 3 - 1 - 2 - [2,2,2,7,2,59,21,52,1,2,0,0,0,0] - 115
2021-09-02T19:40:46.755Z zigbee-herdsman:adapter:zStack:znp:SRSP <-- SYS - version - {"transportrev":2,"product":2,"majorrel":2,"minorrel":7,"maintrel":2,"revision":20190523}
2021-09-02T19:40:46.755Z zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext []
2021-09-02T19:40:46.755Z zigbee-herdsman:adapter:zStack:adapter Adapter concurrent: 2
2021-09-02T19:40:46.755Z zigbee-herdsman:adapter:zStack:adapter Detected znp version 'zStack30x' ({"transportrev":2,"product":2,"majorrel":2,"minorrel":7,"maintrel":2,"revision":20190523})
...
...

* Stop Zigbee2mqtt

* Start Zigbee2mqtt and... it doesn't work...

Zigbee2MQTT:debug 2021-09-02 21:43:00: Loaded state from file /app/data/state.json
Zigbee2MQTT:info  2021-09-02 21:43:00: Logging to console and directory: '/var/log/zigbee2mqtt' filename: log.txt
Zigbee2MQTT:info  2021-09-02 21:43:00: Starting Zigbee2MQTT version 1.21.1 (commit #eb5750d
)
Zigbee2MQTT:info  2021-09-02 21:43:00: Starting zigbee-herdsman (0.13.138)
Zigbee2MQTT:debug 2021-09-02 21:43:00: Using zigbee-herdsman with settings: '{"adapter":{"concurrent":null,"delay":null,"disableLED":false},"backupPath":"/app/data/coordinator_backup.json","databaseBackupPath":"/app/data/database.db.backup","databasePath":"/app/data/database.db","network":{"channelList":[11],"extendedPanID":[221,221,221,221,221,221,221,221],"networkKey":"HIDDEN","panID":6754},"serialPort":{"path":"/dev/ttyUSB0"}}'
2021-09-02T19:43:00.362Z zigbee-herdsman:controller:log Starting with options '{"network":{"networkKeyDistribute":false,"networkKey":[1,3,5,7,9,11,13,15,0,2,4,6,8,10,12,13],"panID":6754,"extendedPanID":[221,221,221,221,221,221,221,221],"channelList":[11]},"serialPort":{"path":"/dev/ttyUSB0"},"databasePath":"/app/data/database.db","databaseBackupPath":"/app/data/database.db.backup","backupPath":"/app/data/coordinator_backup.json","adapter":{"disableLED":false,"concurrent":null,"delay":null}}'
2021-09-02T19:43:00.362Z zigbee-herdsman:adapter:zStack:znp:log Opening SerialPort with /dev/ttyUSB0 and {"baudRate":115200,"rtscts":false,"autoOpen":false}
2021-09-02T19:43:00.365Z zigbee-herdsman:adapter:zStack:znp:log Serialport opened
2021-09-02T19:43:00.822Z zigbee-herdsman:adapter:zStack:znp:log Writing skip bootloader payload
2021-09-02T19:43:00.823Z zigbee-herdsman:adapter:zStack:unpi:writer --> buffer [239]
2021-09-02T19:43:01.829Z zigbee-herdsman:adapter:zStack:znp:SREQ --> SYS - ping - {"capabilities":1}
2021-09-02T19:43:01.831Z zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,0,33,1,32]
2021-09-02T19:43:07.832Z zigbee-herdsman:adapter:zStack:znp:SREQ --> SYS - ping - {"capabilities":1}
2021-09-02T19:43:07.833Z zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,0,33,1,32]
2021-09-02T19:43:13.839Z zigbee-herdsman:adapter:zStack:znp:SREQ --> SYS - ping - {"capabilities":1}
2021-09-02T19:43:13.840Z zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,0,33,1,32]
Zigbee2MQTT:error 2021-09-02 21:43:19: Error while starting zigbee-herdsman
Zigbee2MQTT:error 2021-09-02 21:43:19: Failed to start zigbee
Zigbee2MQTT:error 2021-09-02 21:43:19: Check https://www.zigbee2mqtt.io/information/FAQ.html#help-zigbee2mqtt-fails-to-start for possible solutions
Zigbee2MQTT:error 2021-09-02 21:43:19: Exiting...
Zigbee2MQTT:error 2021-09-02 21:43:19: 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:102:27)
    at Controller.start (/app/node_modules/zigbee-herdsman/src/controller/controller.ts:123:29)
    at Zigbee.start (/app/lib/zigbee.js:66:27)
    at Controller.start (/app/lib/controller.js:110:27)
    at start (/app/index.js:95:5)

If I remove and reconnect CC2530... It starts fine again.

I've tried at least 10 times and the behavior is always the same... If I remove and reconnect CC250 it works. if I restart without reconnecting CC2530 it doesn't work

Thanks Diego for testing by enabling the herdsman debug logging

We look forward to a response from @Koenkk

[Koenkk]

Could you check the latest-dev (edge for hass) version? (https://www.zigbee2mqtt.io/how_tos/how-to-switch-to-dev-branch.html)

[snakuzzo]

Done. Same resault...

HERE the full log

• Connected CC2530
• Started Z2M dev ... OK
• Stopped Z2M dev
• Started Z2M dev ... KO

[hassiomanuel90]

Even myself problem. solve please Thank you!

[Koenkk]

@snakuzzo thanks for the good logging, I cannot find the root cause of this yet in your log. Could you provide the logging when running with DEBUG=* npm start? (instead of DEBUG=zigbee-herdsman* npm start)

[snakuzzo]

Hi @Koenkk ... This is the log with DEBUG=*

Using '/app/data' as data directory
winston:create-logger: Define prototype method for "error"
winston:create-logger: Define prototype method for "warn"
winston:create-logger: Define prototype method for "info"
winston:create-logger: Define prototype method for "http"
winston:create-logger: Define prototype method for "verbose"
winston:create-logger: Define prototype method for "debug"
winston:create-logger: Define prototype method for "silly"
winston:create-logger: Define prototype method for "emerg"
winston:create-logger: Define prototype method for "alert"
winston:create-logger: Define prototype method for "crit"
winston:create-logger: Define prototype method for "error"
winston:create-logger: Define prototype method for "warning"
winston:create-logger: Define prototype method for "notice"
winston:create-logger: Define prototype method for "info"
winston:create-logger: Define prototype method for "debug"
Zigbee2MQTT:debug 2021-09-11 17:30:34: Loaded state from file /app/data/state.json
winston:file: written true false
Zigbee2MQTT:info  2021-09-11 17:30:34: Logging to console and directory: '/var/log/zigbee2mqtt' filename: log.txt
winston:file: written true false
winston:file: logged 71 debug 2021-09-11 17:30:34: Loaded state from file /app/data/state.json

winston:file: logged 173 info  2021-09-11 17:30:34: Logging to console and directory: '/var/log/zigbee2mqtt' filename: log.txt

winston:file: stat done: log.txt { size: 4746810 }
winston:file: create stream start /var/log/zigbee2mqtt/log.txt { flags: 'a' }
winston:file: create stream ok /var/log/zigbee2mqtt/log.txt
Zigbee2MQTT:info  2021-09-11 17:30:34: Starting Zigbee2MQTT version 1.21.1-dev (commit #cf01919
)
winston:file: written true false
Zigbee2MQTT:info  2021-09-11 17:30:34: Starting zigbee-herdsman (0.13.139)
winston:file: written true false
Zigbee2MQTT:debug 2021-09-11 17:30:34: Using zigbee-herdsman with settings: '{"adapter":{"concurrent":null,"delay":null,"disableLED":false},"backupPath":"/app/data/coordinator_backup.json","databaseBackupPath":"/app/data/database.db.backup","databasePath":"/app/data/database.db","network":{"channelList":[11],"extendedPanID":[221,221,221,221,221,221,221,221],"networkKey":"HIDDEN","panID":6754},"serialPort":{"path":"/dev/ttyUSB0"}}'
winston:file: written true false
2021-09-11T15:30:34.879Z serialport/bindings loading LinuxBinding
2021-09-11T15:30:34.928Z serialport/stream .list
winston:file: logged 4746896 info  2021-09-11 17:30:34: Starting Zigbee2MQTT version 1.21.1-dev (commit #cf01919
)

winston:file: logged 4746959 info  2021-09-11 17:30:34: Starting zigbee-herdsman (0.13.139)

winston:file: logged 4747382 debug 2021-09-11 17:30:34: Using zigbee-herdsman with settings: '{"adapter":{"concurrent":null,"delay":null,"disableLED":false},"backupPath":"/app/data/coordinator_backup.json","databaseBackupPath":"/app/data/database.db.backup","databasePath":"/app/data/database.db","network":{"channelList":[11],"extendedPanID":[221,221,221,221,221,221,221,221],"networkKey":"HIDDEN","panID":6754},"serialPort":{"path":"/dev/ttyUSB0"}}'

winston:file: file open ok /var/log/zigbee2mqtt/log.txt
2021-09-11T15:30:34.991Z serialport/stream .list
2021-09-11T15:30:35.033Z serialport/stream .list
2021-09-11T15:30:35.074Z zigbee-herdsman:controller:log Starting with options '{"network":{"networkKeyDistribute":false,"networkKey":[1,3,5,7,9,11,13,15,0,2,4,6,8,10,12,13],"panID":6754,"extendedPanID":[221,221,221,221,221,221,221,221],"channelList":[11]},"serialPort":{"path":"/dev/ttyUSB0"},"databasePath":"/app/data/database.db","databaseBackupPath":"/app/data/database.db.backup","backupPath":"/app/data/coordinator_backup.json","adapter":{"disableLED":false,"concurrent":null,"delay":null}}'
2021-09-11T15:30:35.074Z zigbee-herdsman:adapter:zStack:znp:log Opening SerialPort with /dev/ttyUSB0 and {"baudRate":115200,"rtscts":false,"autoOpen":false}
2021-09-11T15:30:35.075Z serialport/stream opening path: /dev/ttyUSB0
2021-09-11T15:30:35.075Z serialport/binding-abstract open
2021-09-11T15:30:35.076Z serialport/stream _read queueing _read for after open
2021-09-11T15:30:35.076Z serialport/bindings/poller Creating poller
2021-09-11T15:30:35.076Z serialport/stream opened path: /dev/ttyUSB0
2021-09-11T15:30:35.077Z serialport/stream _read reading { start: 0, toRead: 65536 }
2021-09-11T15:30:35.077Z serialport/binding-abstract read
2021-09-11T15:30:35.077Z zigbee-herdsman:adapter:zStack:znp:log Serialport opened
2021-09-11T15:30:35.077Z serialport/stream #set { brk: false, cts: false, dtr: false, dts: false, rts: false }
2021-09-11T15:30:35.077Z serialport/binding-abstract set
2021-09-11T15:30:35.077Z serialport/bindings/unixRead Starting read
2021-09-11T15:30:35.078Z serialport/bindings/unixRead read error [Error: EAGAIN: resource temporarily unavailable, read] {
  errno: -11,
  code: 'EAGAIN',
  syscall: 'read'
}
2021-09-11T15:30:35.078Z serialport/bindings/unixRead waiting for readable because of code: EAGAIN
2021-09-11T15:30:35.078Z serialport/bindings/poller Polling for "readable"
2021-09-11T15:30:35.078Z serialport/stream binding.set had an error [Error: Error: Not a tty, cannot get low latency]
2021-09-11T15:30:35.231Z serialport/stream #set { brk: false, cts: false, dtr: false, dts: false, rts: true }
2021-09-11T15:30:35.231Z serialport/binding-abstract set
2021-09-11T15:30:35.233Z serialport/stream binding.set had an error [Error: Error: Not a tty, cannot get low latency]
2021-09-11T15:30:35.384Z serialport/stream #set { brk: false, cts: false, dtr: false, dts: false, rts: false }
2021-09-11T15:30:35.384Z serialport/binding-abstract set
2021-09-11T15:30:35.385Z serialport/stream binding.set had an error [Error: Error: Not a tty, cannot get low latency]
2021-09-11T15:30:35.535Z zigbee-herdsman:adapter:zStack:znp:log Writing skip bootloader payload
2021-09-11T15:30:35.536Z zigbee-herdsman:adapter:zStack:unpi:writer --> buffer [239]
2021-09-11T15:30:35.537Z serialport/stream _write 1 bytes of data
2021-09-11T15:30:35.537Z serialport/binding-abstract write 1 bytes
2021-09-11T15:30:35.538Z serialport/bindings/unixWrite Starting write 1 bytes offset 0 bytesToWrite 1
2021-09-11T15:30:35.539Z serialport/bindings/unixWrite write returned: wrote 1 bytes
2021-09-11T15:30:35.539Z serialport/bindings/unixWrite Finished writing 1 bytes
2021-09-11T15:30:35.539Z serialport/stream binding.write write finished
2021-09-11T15:30:36.542Z zigbee-herdsman:adapter:zStack:znp:SREQ --> SYS - ping - {"capabilities":1}
2021-09-11T15:30:36.543Z zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,0,33,1,32]
2021-09-11T15:30:36.544Z serialport/stream _write 5 bytes of data
2021-09-11T15:30:36.544Z serialport/binding-abstract write 5 bytes
2021-09-11T15:30:36.544Z serialport/bindings/unixWrite Starting write 5 bytes offset 0 bytesToWrite 5
2021-09-11T15:30:36.544Z serialport/bindings/unixWrite write returned: wrote 5 bytes
2021-09-11T15:30:36.544Z serialport/bindings/unixWrite Finished writing 5 bytes
2021-09-11T15:30:36.544Z serialport/stream binding.write write finished
2021-09-11T15:30:42.545Z zigbee-herdsman:adapter:zStack:znp:SREQ --> SYS - ping - {"capabilities":1}
2021-09-11T15:30:42.546Z zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,0,33,1,32]
2021-09-11T15:30:42.546Z serialport/stream _write 5 bytes of data
2021-09-11T15:30:42.546Z serialport/binding-abstract write 5 bytes
2021-09-11T15:30:42.547Z serialport/bindings/unixWrite Starting write 5 bytes offset 0 bytesToWrite 5
2021-09-11T15:30:42.547Z serialport/bindings/unixWrite write returned: wrote 5 bytes
2021-09-11T15:30:42.547Z serialport/bindings/unixWrite Finished writing 5 bytes
2021-09-11T15:30:42.548Z serialport/stream binding.write write finished
2021-09-11T15:30:48.553Z zigbee-herdsman:adapter:zStack:znp:SREQ --> SYS - ping - {"capabilities":1}
2021-09-11T15:30:48.554Z zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,0,33,1,32]
2021-09-11T15:30:48.554Z serialport/stream _write 5 bytes of data
2021-09-11T15:30:48.554Z serialport/binding-abstract write 5 bytes
2021-09-11T15:30:48.555Z serialport/bindings/unixWrite Starting write 5 bytes offset 0 bytesToWrite 5
2021-09-11T15:30:48.555Z serialport/bindings/unixWrite write returned: wrote 5 bytes
2021-09-11T15:30:48.555Z serialport/bindings/unixWrite Finished writing 5 bytes
2021-09-11T15:30:48.555Z serialport/stream binding.write write finished
Zigbee2MQTT:error 2021-09-11 17:30:54: Error while starting zigbee-herdsman
winston:file: written true false
Zigbee2MQTT:error 2021-09-11 17:30:54: Failed to start zigbee
winston:file: written true false
Zigbee2MQTT:error 2021-09-11 17:30:54: Check https://www.zigbee2mqtt.io/information/FAQ.html#help-zigbee2mqtt-fails-to-start for possible solutions
winston:file: written true false
Zigbee2MQTT:error 2021-09-11 17:30:54: Exiting...
winston:file: written true false
Zigbee2MQTT:error 2021-09-11 17:30:54: 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:102:27)
    at Controller.start (/app/node_modules/zigbee-herdsman/src/controller/controller.ts:123:29)
    at Zigbee.start (/app/lib/zigbee.ts:62:27)
    at Controller.start (/app/lib/controller.js:113:27)
    at start (/app/index.js:95:5)
winston:file: written true false

[Koenkk]

@snakuzzo what kernel/os are you using? (uname -r)

[snakuzzo]

I'm on Ubuntu 20.04 (focal) and kernel version is 5.4.0-84-generic

[maxcanna]

Same happens on raspbian

maxcanna@maspberry:~ $ uname -r
5.10.17-v7l+
maxcanna@maspberry:~ $ cat /etc/os-release
PRETTY_NAME="Raspbian GNU/Linux 10 (buster)"
NAME="Raspbian GNU/Linux"
VERSION_ID="10"
VERSION="10 (buster)"
VERSION_CODENAME=buster
ID=raspbian
ID_LIKE=debian
HOME_URL="http://www.raspbian.org/"
SUPPORT_URL="http://www.raspbian.org/RaspbianForums"
BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs"
maxcanna@maspberry:~ $

[Koenkk]

@snakuzzo @maxcanna when downgrading zigbee2mqtt, what is the first version where this issue does not appear anymore?

[hassiomanuel90]

@snakuzzo @maxcanna durante il downgrade di zigbee2mqtt, qual è la prima versione in cui questo problema non compare più?

1.20.0 it worked fine! :)

[SmartM-ui]

@snakuzzo @maxcanna when downgrading zigbee2mqtt, what is the first version where this issue does not appear anymore?

Hi @Koenkk Work to: HassOS 6.2 Core 2021.9.5 Supervisor 2021.09 Zigbee2MQTT 1.20.0-1

[maxcanna]

@snakuzzo @maxcanna when downgrading zigbee2mqtt, what is the first version where this issue does not appear anymore?

1.20.0

[snakuzzo]

Guys...I was trying using a CC2530 with Z-Stack 3.0 but on github repo there is no fw 3.0 for CC2530 anymore. So I flashed again using Z-Stack 1.2. Now I noticed that...

Using 1.21.x (zigbee-herdsman 0.13.138) CC2530 doesn't work...even if I disconnect and reconnect the adapter Using 1.20.x (zigbee-herdsman 0.13.117) CC2530 works fine...without disconnect and reconnect the adapter

[snakuzzo]

Just another detail....

I used same CC2530 on a nodemcu with esp-link firmware to connect via ser2net.

Same issue...so I don't think it's a USB/kernel problem. So...configuring z2m to connect via TCP to the adapter...

Using 1.21.x (zigbee-herdsman 0.13.138) CC2530 doesn't work...even if I disconnect and reconnect the adapter Using 1.20.x (zigbee-herdsman 0.13.117) CC2530 works fine...without disconnect and reconnect the adapter

NOTE: If I try using 1.21.x -> KO If I retry using 1.20.x without turn off/on the adapter before ... it doesn't work but if I turn off/on the adapter on 1.20.x it works again

It seems 1.21 make "something" that breaks CC2530 that needs a restart

[Koenkk]

Can you check with the latest dev branch? (edge for hassio)

Changes will be available in the dev branch in a few hours from now. (https://www.zigbee2mqtt.io/how_tos/how-to-switch-to-dev-branch.html)

[snakuzzo]

Hi...Tested right now with latest-dev image using a fresh CC2530 with Z-Stack 1.2 firmware

First start -> OK Container stopped Container started -> KO

Here the log

Using '/app/data' as data directory
Zigbee2MQTT:debug 2021-09-13 10:31:41: Loaded state from file /app/data/state.json
Zigbee2MQTT:info  2021-09-13 10:31:41: Logging to console and directory: '/var/log/zigbee2mqtt' filename: log.txt
Zigbee2MQTT:info  2021-09-13 10:31:41: Starting Zigbee2MQTT version 1.21.1-dev (commit #ac44a50
)
Zigbee2MQTT:info  2021-09-13 10:31:41: Starting zigbee-herdsman (0.13.144)
Zigbee2MQTT:debug 2021-09-13 10:31:41: Using zigbee-herdsman with settings: '{"adapter":{"concurrent":null,"delay":null,"disableLED":false},"backupPath":"/app/data/coordinator_backup.json","databaseBackupPath":"/app/data/database.db.backup","databasePath":"/app/data/database.db","network":{"channelList":[25],"extendedPanID":[221,221,221,221,221,221,221,221],"networkKey":"HIDDEN","panID":6754},"serialPort":{"path":"/dev/ttyUSB0"}}'
2021-09-13T08:31:41.380Z zigbee-herdsman:controller:log Starting with options '{"network":{"networkKeyDistribute":false,"networkKey":[1,3,5,7,9,11,13,15,0,2,4,6,8,10,12,13],"panID":6754,"extendedPanID":[221,221,221,221,221,221,221,221],"channelList":[25]},"serialPort":{"path":"/dev/ttyUSB0"},"databasePath":"/app/data/database.db","databaseBackupPath":"/app/data/database.db.backup","backupPath":"/app/data/coordinator_backup.json","adapter":{"disableLED":false,"concurrent":null,"delay":null}}'
2021-09-13T08:31:41.381Z zigbee-herdsman:adapter:zStack:znp:log Opening SerialPort with /dev/ttyUSB0 and {"baudRate":115200,"rtscts":false,"autoOpen":false}
2021-09-13T08:31:41.384Z zigbee-herdsman:adapter:zStack:znp:log Serialport opened
2021-09-13T08:31:41.844Z zigbee-herdsman:adapter:zStack:znp:log Writing skip bootloader payload
2021-09-13T08:31:41.844Z zigbee-herdsman:adapter:zStack:unpi:writer --> buffer [239]
2021-09-13T08:31:42.850Z zigbee-herdsman:adapter:zStack:znp:SREQ --> SYS - ping - {"capabilities":1}
2021-09-13T08:31:42.850Z zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,0,33,1,32]
2021-09-13T08:31:48.852Z zigbee-herdsman:adapter:zStack:znp:SREQ --> SYS - ping - {"capabilities":1}
2021-09-13T08:31:48.853Z zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,0,33,1,32]
2021-09-13T08:31:54.859Z zigbee-herdsman:adapter:zStack:znp:SREQ --> SYS - ping - {"capabilities":1}
2021-09-13T08:31:54.860Z zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,0,33,1,32]
Zigbee2MQTT:error 2021-09-13 10:32:00: Error while starting zigbee-herdsman
Zigbee2MQTT:error 2021-09-13 10:32:00: Failed to start zigbee
Zigbee2MQTT:error 2021-09-13 10:32:00: Check https://www.zigbee2mqtt.io/information/FAQ.html#help-zigbee2mqtt-fails-to-start for possible solutions
Zigbee2MQTT:error 2021-09-13 10:32:00: Exiting...
Zigbee2MQTT:error 2021-09-13 10:32:00: 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:102:27)
    at Controller.start (/app/node_modules/zigbee-herdsman/src/controller/controller.ts:123:29)
    at Zigbee.start (/app/lib/zigbee.ts:63:27)
    at Controller.start (/app/lib/controller.js:113:27)
    at start (/app/index.js:95:5)

Adapter disconnected Adapter reconnected Container started -> OK Container stopped Container restarted -> KO

HERE full log with test OK/KO

[fabioxp7980]

Tried in my proxmox supervised with latest edge addon, here is the log, same behaviour descripted by other users, first start works, restart DON'T work.

[s6-init] making user provided files available at /var/run/s6/etc...exited 0.
[s6-init] ensuring user provided files have correct perms...exited 0.
[fix-attrs.d] applying ownership & permissions fixes...
[fix-attrs.d] done.
[cont-init.d] executing container initialization scripts...
[cont-init.d] socat.sh: executing... 
[10:40:05] INFO: Socat not enabled, marking service as down
[cont-init.d] socat.sh: exited 0.
[cont-init.d] zigbee2mqtt.sh: executing... 
[10:40:05] INFO: MQTT available, fetching server detail ...
[10:40:05] INFO: Previous config file found, checking backup
[10:40:05] INFO: Creating backup config in '/config/zigbee2mqtt/.configuration.yaml.bk'
[10:40:05] INFO: Adjusting Zigbee2mqtt core yaml config with add-on quirks ...
[cont-init.d] zigbee2mqtt.sh: exited 0.
[cont-init.d] done.
[services.d] starting services
[services.d] done.
[10:40:06] INFO: Zigbee Herdsman debug logging enabled
[10:40:06] INFO: Handing over control to Zigbee2mqtt Core ...
> zigbee2mqtt@1.21.1-dev start
> node index.js
Zigbee2MQTT:debug 2021-09-13 10:40:09: Loaded state from file /config/zigbee2mqtt/state.json
Zigbee2MQTT:info  2021-09-13 10:40:09: Logging to console and directory: '/config/zigbee2mqtt/log/2021-09-13.10-40-08' filename: log.txt
Zigbee2MQTT:debug 2021-09-13 10:40:09: Removing old log directory '/config/zigbee2mqtt/log/2021-09-13.10-25-57'
Zigbee2MQTT:info  2021-09-13 10:40:09: Starting Zigbee2MQTT version 1.21.1-dev (commit #ac44a50)
Zigbee2MQTT:info  2021-09-13 10:40:09: Starting zigbee-herdsman (0.13.144)
Zigbee2MQTT:debug 2021-09-13 10:40:09: Using zigbee-herdsman with settings: '{"adapter":{"concurrent":null,"delay":null,"disableLED":false},"backupPath":"/config/zigbee2mqtt/coordinator_backup.json","databaseBackupPath":"/config/zigbee2mqtt/database.db.backup","databasePath":"/config/zigbee2mqtt/database.db","network":{"channelList":[11],"extendedPanID":[221,221,221,221,221,221,221,221],"networkKey":"HIDDEN","panID":6754},"serialPort":{"path":"/dev/ttyUSB0"}}'
2021-09-13T08:40:09.735Z zigbee-herdsman:adapter Failed to validate path: 'Error: spawn udevadm ENOENT'
2021-09-13T08:40:09.738Z zigbee-herdsman:controller:log Starting with options '{"network":{"networkKeyDistribute":false,"networkKey":[1,3,5,7,9,11,13,15,0,2,4,6,8,10,12,13],"panID":6754,"extendedPanID":[221,221,221,221,221,221,221,221],"channelList":[11]},"serialPort":{"path":"/dev/ttyUSB0"},"databasePath":"/config/zigbee2mqtt/database.db","databaseBackupPath":"/config/zigbee2mqtt/database.db.backup","backupPath":"/config/zigbee2mqtt/coordinator_backup.json","adapter":{"disableLED":false,"concurrent":null,"delay":null}}'
2021-09-13T08:40:09.739Z zigbee-herdsman:adapter:zStack:znp:log Opening SerialPort with /dev/ttyUSB0 and {"baudRate":115200,"rtscts":false,"autoOpen":false}
2021-09-13T08:40:09.750Z zigbee-herdsman:adapter:zStack:znp:log Serialport opened
2021-09-13T08:40:10.209Z zigbee-herdsman:adapter:zStack:znp:log Writing skip bootloader payload
2021-09-13T08:40:10.211Z zigbee-herdsman:adapter:zStack:unpi:writer --> buffer [239]
2021-09-13T08:40:11.215Z zigbee-herdsman:adapter:zStack:znp:SREQ --> SYS - ping - {"capabilities":1}
2021-09-13T08:40:11.217Z zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,0,33,1,32]
2021-09-13T08:40:17.221Z zigbee-herdsman:adapter:zStack:znp:SREQ --> SYS - ping - {"capabilities":1}
2021-09-13T08:40:17.222Z zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,0,33,1,32]
2021-09-13T08:40:23.229Z zigbee-herdsman:adapter:zStack:znp:SREQ --> SYS - ping - {"capabilities":1}
2021-09-13T08:40:23.231Z zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,0,33,1,32]
Zigbee2MQTT:error 2021-09-13 10:40:29: Error while starting zigbee-herdsman
Zigbee2MQTT:error 2021-09-13 10:40:29: Failed to start zigbee
Zigbee2MQTT:error 2021-09-13 10:40:29: Check https://www.zigbee2mqtt.io/information/FAQ.html#help-zigbee2mqtt-fails-to-start for possible solutions
Zigbee2MQTT:error 2021-09-13 10:40:29: Exiting...
Zigbee2MQTT:error 2021-09-13 10:40:29: 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:102:27)
    at Controller.start (/app/node_modules/zigbee-herdsman/src/controller/controller.ts:123:29)
    at Zigbee.start (/app/lib/zigbee.ts:63:27)
    at Controller.start (/app/lib/controller.js:113:27)
    at start (/app/index.js:95:5)
[10:40:29] INFO: Zigbee Herdsman debug logging enabled
[10:40:29] INFO: Handing over control to Zigbee2mqtt Core ...
> zigbee2mqtt@1.21.1-dev start
> node index.js
Zigbee2MQTT:debug 2021-09-13 10:40:32: Loaded state from file /config/zigbee2mqtt/state.json
Zigbee2MQTT:info  2021-09-13 10:40:32: Logging to console and directory: '/config/zigbee2mqtt/log/2021-09-13.10-40-31' filename: log.txt
Zigbee2MQTT:debug 2021-09-13 10:40:32: Removing old log directory '/config/zigbee2mqtt/log/2021-09-13.10-26-20'
Zigbee2MQTT:info  2021-09-13 10:40:32: Starting Zigbee2MQTT version 1.21.1-dev (commit #ac44a50)
Zigbee2MQTT:info  2021-09-13 10:40:32: Starting zigbee-herdsman (0.13.144)
Zigbee2MQTT:debug 2021-09-13 10:40:32: Using zigbee-herdsman with settings: '{"adapter":{"concurrent":null,"delay":null,"disableLED":false},"backupPath":"/config/zigbee2mqtt/coordinator_backup.json","databaseBackupPath":"/config/zigbee2mqtt/database.db.backup","databasePath":"/config/zigbee2mqtt/database.db","network":{"channelList":[11],"extendedPanID":[221,221,221,221,221,221,221,221],"networkKey":"HIDDEN","panID":6754},"serialPort":{"path":"/dev/ttyUSB0"}}'

[Koenkk]

@snakuzzo can you find out at which zigbee-herdsman version it stops working? (you can keep running the latest z2m)

First setup a local copy of zigbee-hersdman: (note that node.js has to be installed on your system)

cd /opt
git clone https://github.com/Koenkk/zigbee-herdsman.git
cd zigbee-herdsman
git checkout tags/v0.13.117
npm ci && npm run build

Update your docker run command to mount the following volume: -v /opt/zigbee-herdsman:/app/node_modules/zigbee-herdsman. Now start the z2m container, verify that z2m 1.21.1 is started with herdsman 0.13.117. First verify that the restarting problem does not appear now.

Now start increasing the herdsman version:

cd /opt/zigbee-herdsman
git checkout tags/v0.13.118
npm ci && npm run build

Restart z2m, check if bug appears again, if not increment herdsman version again.

[snakuzzo]

Ok...no problem. For now I tried z2m 1.21 + zigbee-herdsman 0.13.117 ... and it works fine (good news!) Now I'm busy...I will try later the other versions.

Note: before compiling modules you need to check nodeJS version installed, because you have to compile node modules using right nodeJS version (I used 14.7.6 that is the nodeJS version present in zigbee2mqtt image)

[snakuzzo]

Hi @Koenkk Tested every zigbee-herdsman versions from 0.13.117 to 0.13.144 on zigbee2mqtt 1.21.1 using Docker (docker-compose) and compiling every version of zigbee-herdsman with nodeJS 14.7.6 and CC2530 adapter

Results...

0.13.117 -> Works perfectly
0.13.118 -> Exit immediately ... no errors
0.13.119 -> Exit immediately ... no errors
0.13.120 -> Exit immediately ... no errors
0.13.121 -> Exit immediately ... no errors 
0.13.122 -> Exit immediately ... no errors
0.13.123 -> Exit immediately ... no errors
0.13.124 -> Exit immediately ... no errors
0.13.125 -> Exit immediately ... no errors
0.13.126 -> Exit immediately ... no errors
0.13.127 -> Exit immediately ... no errors
0.13.128 -> Exit immediately ... no errors
0.13.129 -> Exit immediately ... no errors
0.13.130 -> Exit immediately ... no errors
0.13.131 -> Exit immediately ... no errors
0.13.132 -> Exit immediately ... no errors
0.13.133 -> Exit immediately ... no errors
0.13.134 -> Exit immediately ... no errors
0.13.135 -> Exit immediately ... no errors
0.13.136 -> Exit immediately ... no errors
0.13.137 -> Exit immediately ... no errors
0.13.138 -> Exit immediately ... no errors
0.13.139 -> Exit immediately ... no errors
0.13.140 -> Partially works - it needs disconnect/reconnect on container restart
0.13.141 -> Partially works - it needs disconnect/reconnect on container restart
0.13.142 -> Exit immediately ... no errors
0.13.143 -> Partially works - it needs disconnect/reconnect on container restart
0.13.144 -> Partially works - it needs disconnect/reconnect on container restart

HERE you can find a log example about "exit emmediatly" result

[Koenkk]

@snakuzzo can you try on herdsman 0.13.144:

cd /opt/zigbee-herdsman
git revert 779335fd39881ab8361b7fd9ad877be5342d8354 --no-commit
npm ci && npm run build