v1.28 does not start! Had to rollback to 1.27.2

[initd0]

What happened?

I decided to update to 1.28.0 and addon would not start.

I did this twice.

Somewhere along the log searching, i saw something like "_zigbee2mqtt/json: Not Found ("No such container: addon_xxxx_zigbee2mqtt" but i didnt go look for that again.
So i restored back to 1.27.2 and it works.
I tried updating back to 1.28.0 because i thought something went wrong during the update, and still the same thing happened.
I am back on 1.27.2 again its working... the logs say this now:

22-10-02  INFO (SyncWorker_7) [supervisor.docker.addon] Starting Docker add-on zigbee2mqtt/zigbee2mqtt-amd64 with version 1.27.2-1
22-10-02  WARNING (MainThread) [supervisor.ingress] Fails Ingress panel for _zigbee2mqtt with 500
22-10-02  INFO (MainThread) [supervisor.backups.manager] Partial-Restore  done

What did you expect to happen?

i expected to update without issue

How to reproduce it (minimal and precise)

Update to 1.28.0 and wait to see that the addon does not start

Says starting... in its logs but doesnt.

Zigbee2MQTT version

1.28.0

Adapter firmware version

20210708

Adapter

CC2652R zzh!

Debug log

No response

[initd0]

Did i mention that 1.27.2 was working fine and i havent had any issues(like never) prior to 1.28.0 update?
Is anyone else having this update issue?

im on:
Home Assistant 2022.9.7
Supervisor 2022.09.1
Frontend 20220907.2 - latest

[cbarry]

This happened to me too.
The error is:

[15:42:17] INFO: Starting Zigbee2MQTT...
/app/node_modules/zigbee-herdsman-converters/index.js:91
if (converter.options) {
^
TypeError: Cannot read properties of undefined (reading 'options')
at Object.addDefinition [as addDeviceDefinition] (/app/node_modules/zigbee-herdsman-converters/index.js:91:23)
at new ExternalConverters (/app/lib/extension/externalConverters.ts:15:17)
at new Controller (/app/lib/controller.ts:84:58)
at start (/app/index.js:108:18)

[cbarry]

@initd0 Are you running any external converters?
When I remove the external converters from my Zigbee2MQTT configuration.yaml, it fixes this error.

I am thinking there was some breaking change in 1.28.0

[initd0]

@initd0 Are you running any external converters? When I remove the external converters from my Zigbee2MQTT configuration.yaml, it fixes this error.

I am thinking there was some breaking change in 1.28.0

No external converters on my end, just a simple CC2652R zzh! on 20210708, thats been running perfectly fine since the beginning up until this update. Is it possible when i restored back to 1.27.2 that 1.28.0 is still lingering somewhere in the files? I dont know where exactly to check. If i completely uninstall z2m, will it remove all my devices setups and configs? (i want to try and completely remove and re-install)

[scuppasteve]

I have the same issue, i tried rolling back and that didn't fix it. Below is my herdsman debug. I tried swapping cables and that didnt help. The adapter shows as available. I am using a TI LAUNCHXL-CC26X2R1.

[14:35:14] INFO: Preparing to start... [14:35:14] INFO: Socat not enabled [14:35:15] INFO: Zigbee Herdsman debug logging enabled [14:35:15] INFO: Starting Zigbee2MQTT... Zigbee2MQTT:debug 2022-10-03 14:35:17: Loaded state from file /config/zigbee2mqtt/state.json Zigbee2MQTT:info 2022-10-03 14:35:17: Logging to console and directory: '/config/zigbee2mqtt/log/2022-10-03.14-35-17' filename: log.txt Zigbee2MQTT:debug 2022-10-03 14:35:17: Removing old log directory '/config/zigbee2mqtt/log/2022-10-03.14-26-20' Zigbee2MQTT:info 2022-10-03 14:35:17: Starting Zigbee2MQTT version 1.28.0 (commit #unknown) Zigbee2MQTT:info 2022-10-03 14:35:17: Starting zigbee-herdsman (0.14.62) Zigbee2MQTT:debug 2022-10-03 14:35:17: 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/ttyACM1"}}' 2022-10-03T21:35:17.590Z zigbee-herdsman:adapter Failed to validate path: 'Error: spawn udevadm ENOENT' 2022-10-03T21:35:17.591Z 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/ttyACM1"},"databasePath":"/config/zigbee2mqtt/database.db","databaseBackupPath":"/config/zigbee2mqtt/database.db.backup","backupPath":"/config/zigbee2mqtt/coordinator_backup.json","adapter":{"disableLED":false,"concurrent":null,"delay":null}}' 2022-10-03T21:35:17.592Z zigbee-herdsman:adapter:zStack:znp:log Opening SerialPort with /dev/ttyACM1 and {"baudRate":115200,"rtscts":false,"autoOpen":false} 2022-10-03T21:35:17.596Z zigbee-herdsman:adapter:zStack:znp:log Serialport opened 2022-10-03T21:35:17.597Z zigbee-herdsman:adapter:zStack:znp:SREQ --> SYS - ping - {"capabilities":1} 2022-10-03T21:35:17.598Z zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,0,33,1,32] 2022-10-03T21:35:17.850Z zigbee-herdsman:adapter:zStack:znp:log Writing CC2530/CC2531 skip bootloader payload 2022-10-03T21:35:17.851Z zigbee-herdsman:adapter:zStack:unpi:writer --> buffer [239] 2022-10-03T21:35:18.853Z zigbee-herdsman:adapter:zStack:znp:SREQ --> SYS - ping - {"capabilities":1} 2022-10-03T21:35:18.853Z zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,0,33,1,32] 2022-10-03T21:35:19.105Z zigbee-herdsman:adapter:zStack:znp:log Skip bootloader for CC2652/CC1352 2022-10-03T21:35:19.558Z zigbee-herdsman:adapter:zStack:znp:SREQ --> SYS - ping - {"capabilities":1} 2022-10-03T21:35:19.559Z zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,0,33,1,32] 2022-10-03T21:35:25.561Z zigbee-herdsman:adapter:zStack:znp:SREQ --> SYS - ping - {"capabilities":1} 2022-10-03T21:35:25.563Z zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,0,33,1,32] 2022-10-03T21:35:31.568Z zigbee-herdsman:adapter:zStack:znp:SREQ --> SYS - ping - {"capabilities":1} 2022-10-03T21:35:31.569Z zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,0,33,1,32] Zigbee2MQTT:error 2022-10-03 14:35:37: Error while starting zigbee-herdsman Zigbee2MQTT:error 2022-10-03 14:35:37: Failed to start zigbee Zigbee2MQTT:error 2022-10-03 14:35:37: Check https://www.zigbee2mqtt.io/guide/installation/20_zigbee2mqtt-fails-to-start.html for possible solutions Zigbee2MQTT:error 2022-10-03 14:35:37: Exiting... Zigbee2MQTT:error 2022-10-03 14:35:37: 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:103:27) at Controller.start (/app/node_modules/zigbee-herdsman/src/controller/controller.ts:132:29) at Zigbee.start (/app/lib/zigbee.ts:58:27) at Controller.start (/app/lib/controller.ts:101:27) at start (/app/index.js:109:5)

[Koenkk]

@initd0 do you have any z2m logs? The logging you provided is from HA and on first sight it looks to be a HA issue

@scuppasteve in your case z2m cannot connect to the adapter; I don't expect that z2m 1.28.0 caused this issue. Please check https://www.zigbee2mqtt.io/guide/installation/20_zigbee2mqtt-fails-to-start.html#error-srsp-sys-ping-after-6000ms

[scuppasteve]

@scuppasteve in your case z2m cannot connect to the adapter; I don't expect that z2m 1.28.0 caused this issue. Please check https://www.zigbee2mqtt.io/guide/installation/20_zigbee2mqtt-fails-to-start.html#error-srsp-sys-ping-after-6000ms

I updated z2m and the home assistant core. I have been running this setup for like 3 years and have touched the hardware. The adapter shows as connected I don't have zha stuff configured I have been using z2m for a while. I am not sure what else it could be.

[initd0]

@initd0 do you have any z2m logs? The logging you provided is from HA and on first sight it looks to be a HA issue

@Koenkk I tried updating back to 1.28.0 again now and everything seems to be operating ok (i dont know why or how), but the logs are the following:

[12:07:42] INFO: Preparing to start...
[12:07:43] INFO: Socat not enabled
[12:07:43] INFO: Starting Zigbee2MQTT...

and stops there.

But up until the previous version 1.27.2 the normal startup logs used to show something like this:

s6-rc: info: service z2m: starting
s6-rc: info: service socat: starting
s6-rc: info: service s6rc-oneshot-runner: starting
s6-rc: info: service s6rc-oneshot-runner successfully started
s6-rc: info: service fix-attrs: starting
s6-rc: info: service fix-attrs successfully started
s6-rc: info: service legacy-cont-init: starting
s6-rc: info: service z2m successfully started
s6-rc: info: service socat successfully started
s6-rc: info: service legacy-cont-init successfully started
s6-rc: info: service legacy-services: starting
s6-rc: info: service legacy-services successfully started
[10:00:05] INFO: Socat not enabled
[10:00:06] INFO: Handing over control to Zigbee2MQTT Core ...

Has the normal startup changed the way you log it?

[Koenkk]

Has the normal startup changed the way you log it?

Yes, the logging for 1.28.0 looks as expected (no s6 anymore)

[github-actions]

This issue is stale because it has been open 30 days with no activity. Remove stale label or comment or this will be closed in 7 days

[initd0]

Has the normal startup changed the way you log it?

Yes, the logging for 1.28.0 looks as expected (no s6 anymore)

Despite the errors i had previously in the supervisor and how the sensors werent actually starting up, its all ok now, dont know how it resolved itself.
But regarding the startup logs of z2m.. Instead of the successful startup of z2m ending with INFO: Starting Zigbee2MQTT...
Maybe it should have an additional line once started, confirming that everything is ok. Such as: INFO: Started Zigbee2MQTT!
Otherwise it gives the impression that its hanging on startup.

[Koenkk]

Added!

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

Assuming this ca be closed now.

[initd0]

@Koenkk when you make the changes to the dev branches such as this, when does it go over to the stable branch? Because this is not on the stable branch yet.

[Koenkk]

@initd0 with every 1st of the month release.