search

Koenkk / zigbee2mqtt

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

Trouble upgrading Home Assistant Zigbee2MQTT add-on v1.35.3-1 to 1.40.1-1 #23930

Open mk1blacklimited opened 2 months ago

mk1blacklimited commented 2 months ago

What happened?

Trying to upgrade Home Assistant Zigbee2MQTT add-on v1.35.3-1 to 1.40.1-1. Upgrade seems to go well, but z2m never seems to get ready:

[09:55:23] INFO: Preparing to start... [09:55:23] INFO: Socat not enabled [09:55:24] INFO: Starting Zigbee2MQTT... Starting Zigbee2MQTT without watchdog. [2024-09-10 09:55:25] info: z2m: Logging to console, file (filename: log.log) [2024-09-10 09:55:25] info: z2m: Starting Zigbee2MQTT version 1.40.1 (commit #unknown) [2024-09-10 09:55:25] info: z2m: Starting zigbee-herdsman (0.57.3) [2024-09-10 09:55:26] info: zh:zstack:znp: Opening SerialPort with {"path":"/dev/serial/by-id/usb-Silicon_Labs_Sonoff_Zigbee_3.0_USB_Dongle_Plus_0001-if00-port0","baudRate":115200,"rtscts":false,"autoOpen":false} [2024-09-10 09:55:26] info: zh:zstack:znp: Serialport opened

...and there it stops. WebUI is not accessible (502 bad gateway).

After trying to restore v1.35.3-1 it fails to start:

[09:59:14] INFO: Preparing to start... [09:59:14] INFO: Socat not enabled [09:59:14] INFO: Starting Zigbee2MQTT... Zigbee2MQTT:info 2024-09-10 09:59:16: Logging to console and directory: '/config/zigbee2mqtt/log/2024-09-10.09-59-16' filename: log.txt Zigbee2MQTT:info 2024-09-10 09:59:16: Starting Zigbee2MQTT version 1.35.3 (commit #unknown) Zigbee2MQTT:info 2024-09-10 09:59:16: Starting zigbee-herdsman (0.33.8) Zigbee2MQTT:error 2024-09-10 09:59:16: Error while starting zigbee-herdsman Zigbee2MQTT:error 2024-09-10 09:59:16: Failed to start zigbee Zigbee2MQTT:error 2024-09-10 09:59:16: Check https://www.zigbee2mqtt.io/guide/installation/20_zigbee2mqtt-fails-to-start.html for possible solutions Zigbee2MQTT:error 2024-09-10 09:59:16: Exiting... Zigbee2MQTT:error 2024-09-10 09:59:16: RangeError: Attempt to access memory outside buffer bounds at new NodeError (node:internal/errors:405:5) at boundsError (node:internal/buffer:86:11) at Buffer.readUInt16BE (node:internal/buffer:334:5) at /app/node_modules/zigbee-herdsman/src/utils/backup.ts:102:89 at Array.map () at Object.fromUnifiedBackup (/app/node_modules/zigbee-herdsman/src/utils/backup.ts:101:33) at AdapterBackup.getStoredBackup (/app/node_modules/zigbee-herdsman/src/adapter/z-stack/adapter/adapter-backup.ts:50:32) at ZnpAdapterManager.determineStrategy (/app/node_modules/zigbee-herdsman/src/adapter/z-stack/adapter/manager.ts:134:24) at ZnpAdapterManager.start (/app/node_modules/zigbee-herdsman/src/adapter/z-stack/adapter/manager.ts:63:26) at Controller.start (/app/node_modules/zigbee-herdsman/src/controller/controller.ts:132:29)

Home Assistant info:

Core 2024.9.1 Supervisor 2024.08.0 Operating System 13.1 Frontend 20240906.0

What did you expect to happen?

Successful upgrade.

How to reproduce it (minimal and precise)

Restore complete HASS with z2m 1.35.3-1. Upgrade z2m to 1.40.1-1.

Zigbee2MQTT version

1.35.3-1

Adapter firmware version

20220219

Adapter

Sonoff Dongle P

Setup

Home Assistant Add-on, x86-64

Debug log

No response

Koenkk commented 2 months ago

Could you try to upgrade and before starting rename coordinator_backup.json to coordinator_backup.json.old in the z2m data folder?

mk1blacklimited commented 2 months ago

Done, same problem unfortunately, log:

[14:58:48] INFO: Preparing to start... [14:58:48] INFO: Socat not enabled [14:58:49] INFO: Starting Zigbee2MQTT... Starting Zigbee2MQTT without watchdog. [2024-09-10 14:58:50] info: z2m: Logging to console, file (filename: log.log) [2024-09-10 14:58:50] info: z2m: Starting Zigbee2MQTT version 1.40.1 (commit #unknown) [2024-09-10 14:58:50] info: z2m: Starting zigbee-herdsman (0.57.3) [2024-09-10 14:58:50] info: zh:zstack:znp: Opening SerialPort with {"path":"/dev/serial/by-id/usb-Silicon_Labs_Sonoff_Zigbee_3.0_USB_Dongle_Plus_0001-if00-port0","baudRate":115200,"rtscts":false,"autoOpen":false} [2024-09-10 14:58:50] info: zh:zstack:znp: Serialport opened

Koenkk commented 2 months ago

Could you provide the complete log? I don't see any error in there.

mk1blacklimited commented 2 months ago

Well, that’s just the thing, after it says «Serialport opened» there’s nothing in the log.

mk1blacklimited commented 2 months ago

Is there a way to upgrade to a lesser version of the z2m addon in HA?

Koenkk commented 2 months ago

I think not, do you see anything in the debug log?

See this on how to enable debug logging.

mk1blacklimited commented 2 months ago

I can't see anything I can perceive as a clear error. Is it OK to attach the log file here (i.e. is there something I should remove from the file before posting it)?

mk1blacklimited commented 2 months ago

@Koenkk - ping :)

mk1blacklimited commented 1 month ago

Just tried 1.40.2-1, still the same problem. Really need help here. I have an older FW version in the stick (20220219), could that be the problem?

Koenkk commented 1 month ago

I have an older FW version in the stick (20220219), could that be the problem?

Try upgrading and see if it helps

mk1blacklimited commented 4 weeks ago

Right, upgraded to 20240710. z2m v1.35.3-1 worked fine after upgrading the firmware. Then I tried to upgrade z2m 1.40.2-1:

[09:30:12] INFO: Preparing to start... [09:30:12] INFO: Socat not enabled [09:30:12] INFO: Starting Zigbee2MQTT... Starting Zigbee2MQTT without watchdog. [2024-10-30 09:30:14] info: z2m: Logging to console, file (filename: log.log) [2024-10-30 09:30:14] info: z2m: Starting Zigbee2MQTT version 1.40.2 (commit #unknown) [2024-10-30 09:30:14] info: z2m: Starting zigbee-herdsman (2.1.3) [2024-10-30 09:30:14] error: zh:zstack:znp: Failed to determine if path is valid: 'Error: spawn udevadm ENOENT' [2024-10-30 09:30:14] info: zh:zstack:znp: Opening SerialPort with {"path":"/dev/serial/by-id/usb-Silicon_Labs_Sonoff_Zigbee_3.0_USB_Dongle_Plus_0001-if00-port0","baudRate":115200,"rtscts":false,"autoOpen":false} [2024-10-30 09:30:14] info: zh:zstack:znp: Serialport opened [2024-10-30 09:30:14] error: zh:zstack:znp: Error while parsing to ZpiObject 'TypeError: Cannot read properties of undefined (reading 'execute')'

Note the last line, haven't seen that before.

stopped z2m:

[2024-10-30 09:33:28] error: z2m: Not connected to MQTT server! [2024-10-30 09:33:28] error: z2m: Cannot send message: topic: 'zigbee2mqtthjemme/bridge/state', payload: '{"state":"offline"} [2024-10-30 09:33:28] info: z2m: Disconnecting from MQTT server [2024-10-30 09:33:28] info: z2m: Stopping zigbee-herdsman... [2024-10-30 09:33:36] info: zh:controller: Wrote coordinator backup to '/config/zigbee2mqtt/coordinator_backup.json' [2024-10-30 09:33:36] info: zh:zstack:znp: closing [2024-10-30 09:33:36] info: zh:zstack:znp: Port closed [2024-10-30 09:33:36] info: z2m: Stopped zigbee-herdsman [2024-10-30 09:33:36] info: z2m: Stopped Zigbee2MQTT

Set z2m not to start automatically after Home Assistant restart.

Restarted Home Assistant and started z2m:

[09:36:03] INFO: Preparing to start... [09:36:03] INFO: Socat not enabled [09:36:04] INFO: Starting Zigbee2MQTT... Starting Zigbee2MQTT without watchdog. [2024-10-30 09:36:05] info: z2m: Logging to console, file (filename: log.log) [2024-10-30 09:36:05] info: z2m: Starting Zigbee2MQTT version 1.40.2 (commit #unknown) [2024-10-30 09:36:05] info: z2m: Starting zigbee-herdsman (2.1.3) [2024-10-30 09:36:06] error: zh:zstack:znp: Failed to determine if path is valid: 'Error: spawn udevadm ENOENT' [2024-10-30 09:36:06] info: zh:zstack:znp: Opening SerialPort with {"path":"/dev/serial/by-id/usb-Silicon_Labs_Sonoff_Zigbee_3.0_USB_Dongle_Plus_0001-if00-port0","baudRate":115200,"rtscts":false,"autoOpen":false} [2024-10-30 09:36:06] info: zh:zstack:znp: Serialport opened

And then nothing. :(

This is the configuration:

2024-10-30 09_44_10-Clipboard
Koenkk commented 4 weeks ago

Could you activate the debug logging? You probably need to use the file explorer addon to edit the z2m configuration.yaml.

See this on how to enable debug logging.

mk1blacklimited commented 3 weeks ago

I've done that before, and then I asked: "Is it OK to attach the log file here (i.e. is there something I should remove from the file before posting it)?" which I failed to get a reply to. :) If it's OK to post here then I will ASAP. :)

Koenkk commented 3 weeks ago

Please post it here.

mk1blacklimited commented 3 weeks ago

OK, here it is. log.log

Koenkk commented 3 weeks ago

It seems it cannot connect to the MQTT broker:

[2024-09-19 12:45:23] error:    z2m: Not connected to MQTT server!
[2024-09-19 12:45:23] error:    z2m: Cannot send message: topic: 'zigbee2mqtthjemme/bridge/state', payload: '{"state":"offline"}
[2024-09-19 12:45:23] info:     z2m: Disconnecting from MQTT server
[2024-09-19 12:45:23] info:     z2m: Stopping zigbee-herdsman...

Try following step 5 of https://github.com/zigbee2mqtt/hassio-zigbee2mqtt/blob/master/README.md

mk1blacklimited commented 3 weeks ago

OK - updated z2m to 1.41.0-1. Then I got this in the log page:

image

Configured MQTT as such:

image

Still the same.

Turned on debug log:

[2024-11-07 09:28:16] info: z2m: Logging to console, file (filename: log.log) [2024-11-07 09:28:16] info: z2m: Starting Zigbee2MQTT version 1.41.0 (commit #unknown) [2024-11-07 09:28:16] info: z2m: Starting zigbee-herdsman (2.1.7) [2024-11-07 09:28:16] info: zh:zstack:znp: Opening SerialPort with {"path":"/dev/serial/by-id/usb-Silicon_Labs_Sonoff_Zigbee_3.0_USB_Dongle_Plus_0001-if00-port0","baudRate":115200,"rtscts":false,"autoOpen":false} [2024-11-07 09:28:16] info: zh:zstack:znp: Serialport opened [2024-11-07 09:28:47] error: z2m: Failed to call 'Frontend' 'stop' (TypeError: Cannot read properties of undefined (reading 'clients') at Frontend.stop (/app/lib/extension/frontend.ts:114:18) at Controller.callExtensions (/app/lib/controller.ts:399:17) at Controller.stop (/app/lib/controller.ts:265:9) at stop (/app/index.js:165:5) at process.handleQuit (/app/index.js:173:13)) [2024-11-07 09:28:47] error: z2m: Not connected to MQTT server! [2024-11-07 09:28:47] error: z2m: Cannot send message: topic: 'zigbee2mqtthjemme/bridge/state', payload: '{"state":"offline"} [2024-11-07 09:28:47] info: z2m: Disconnecting from MQTT server [2024-11-07 09:28:47] info: z2m: Stopping zigbee-herdsman... [2024-11-07 09:28:55] info: zh:controller: Wrote coordinator backup to '/config/zigbee2mqtt/coordinator_backup.json' [2024-11-07 09:28:55] info: zh:zstack:znp: closing [2024-11-07 09:28:55] info: zh:zstack:znp: Port closed [2024-11-07 09:28:55] info: z2m: Stopped zigbee-herdsman [2024-11-07 09:28:55] info: z2m: Stopped Zigbee2MQTT

MQTT server (addon in HomeAssistant) is definitly running, nothing else has trouble connecting to it.

Koenkk commented 3 weeks ago

It seems the error is a bit different now, could you provide the debug log again?