Koenkk / zigbee2mqtt

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

Zigbee2MQTT Web Ui not working after host update #23134

Open nicola-spreafico opened 1 month ago

nicola-spreafico commented 1 month ago

What happened?

Hello, before the activities of this morning, all the infrastructure were working very fine since many months, Z2M ok, MQTT ok, HA ok, no issue.

This morning I did a Proxmox update as it offered me to install some updates. After that, the Z2M web interface stopped working with the ERR_CONNECTION_REFUSED error.

I did not change anything in the Z2M LXC specifically, I even tried restoring a backup from yesterday, but the issue is still persisting. This is my configuration yaml, this file has had no changes for many weeks. The last modification I made around april is moving to the ember driver, as defined in the following configuration:

homeassistant: true
advanced:
  network_key:
    ....
  pan_id: 55519
  ext_pan_id:
    ....
  homeassistant_legacy_entity_attributes: false
  legacy_api: false
  legacy_availability_payload: false
  transmit_power: 20
  log_syslog:
    app_name: Zigbee2MQTT
    eol: /n
    host: localhost
    localhost: localhost
    path: /dev/log
    pid: process.pid
    port: 514
    protocol: udp4
    type: '5424'
  channel: 15
  log_level: debug
mqtt:
  base_topic: zigbee2mqtt_01
  server: mqtt://192.168.50.208:1883
  user: xxxxxx
  password: xxxx
  keepalive: 60
  reject_unauthorized: true
  version: 4
serial:
  port: tcp://192.168.50.204:6638
  baudrate: 115200
  adapter: ember
  disable_led: false
  rtscts: false
frontend:
  port: 9442
device_options:
  legacy: false

Besides the web interface not being accessible, it seems that the MQTT is not actually receiving any data, so all the functionalities are currently offline.

I did a quick check on all existing VM and LXC and it seems that the only issue generated by this update is this one, so I'm not sure if the root cause of the issue is on the Proxmox host side or the specific Z2M LXC.

I already lost 3 hours on this, I tried to reboot many times, restoring backup from yesterday, updating the coordinator firmware, rebooting both Z2M and MQTT, rebooting the coordinator itself, rebooting the entire Proxmox, checking the Z2M logs over and over, I'm currently out of ideas and a bit hopeless on this matter.

I appreciate any help I can receive on this. Thank you

Zigbee2MQTT version

1.38.0

Adapter firmware version

core firmware: v2.3.6, zigbee firmware: 20240510

Adapter

SM-LIGHT SLZB-06M

Setup

Beelink SER5 miniPC with Proxmox 8.2.4 - Z2M installed as LXC separated from Home Assistant

Debug log

[2024-06-22 19:43:10] info:     z2m: Logging to console, file (filename: log.log)
[2024-06-22 19:43:10] info:     z2m: Starting Zigbee2MQTT version 1.38.0 (commit #0e6da85d)
[2024-06-22 19:43:10] info:     z2m: Starting zigbee-herdsman (0.49.2)
[2024-06-22 19:43:10] info:     zh:ember: Using default stack config.
[2024-06-22 19:43:10] info:     zh:ember: ======== Ember Adapter Starting ========
[2024-06-22 19:43:10] info:     zh:ember:ezsp: ======== EZSP starting ========
[2024-06-22 19:43:10] info:     zh:ember:uart:ash: ======== ASH NCP reset ========
[2024-06-22 19:43:10] info:     zh:ember:uart:ash: Socket ready
[2024-06-22 19:43:10] info:     zh:ember:uart:ash: ======== ASH starting ========
[2024-06-22 19:43:10] error:    zh:ember:uart:ash: Received frame with CRC error
[2024-06-22 19:43:10] error:    zh:ember:uart:ash: Received ERROR from NCP while connecting, with code=ERROR_EXCEEDED_MAXIMUM_ACK_TIMEOUT_COUNT.
[2024-06-22 19:43:10] error:    zh:ember:uart:ash: ASH disconnected | NCP status: ASH_NCP_FATAL_ERROR
[2024-06-22 19:43:10] error:    zh:ember:uart:ash: Error while parsing received frame, status=ASH_NCP_FATAL_ERROR.
[2024-06-22 19:43:10] info:     zh:ember:uart:ash: ======== ASH NCP reset ========
[2024-06-22 19:43:10] info:     zh:ember:uart:ash: ======== ASH starting ========
[2024-06-22 19:43:11] info:     zh:ember:uart:ash: ======== ASH connected ========
[2024-06-22 19:43:11] info:     zh:ember:uart:ash: ======== ASH started ========
[2024-06-22 19:43:11] info:     zh:ember:ezsp: ======== EZSP started ========
[2024-06-22 19:43:12] warning:  zh:ember:uart:ash: Frame(s) in progress cancelled in [1ac1020b0a527e]
[2024-06-22 19:43:12] error:    zh:ember:uart:ash: Received unexpected reset from NCP, with reason=RESET_SOFTWARE.
[2024-06-22 19:43:12] error:    zh:ember:uart:ash: ASH disconnected: ASH_ERROR_NCP_RESET | NCP status: ASH_NCP_FATAL_ERROR
[2024-06-22 19:43:12] error:    zh:ember:uart:ash: Error while parsing received frame, status=HOST_FATAL_ERROR.
[2024-06-22 19:43:12] error:    zh:ember: !!! NCP FATAL ERROR reason=HOST_FATAL_ERROR. ATTEMPTING RESET... !!!
[2024-06-22 19:43:12] info:     zh:ember:queue: Request dispatching stopped; queue=0 priorityQueue=0
[2024-06-22 19:43:12] info:     zh:ember:uart:ash: ASH COUNTERS since last clear:
[2024-06-22 19:43:12] info:     zh:ember:uart:ash:   Total frames: RX=2, TX=3
[2024-06-22 19:43:12] info:     zh:ember:uart:ash:   Cancelled   : RX=1, TX=0
[2024-06-22 19:43:12] info:     zh:ember:uart:ash:   DATA frames : RX=0, TX=1
[2024-06-22 19:43:12] info:     zh:ember:uart:ash:   DATA bytes  : RX=0, TX=4
[2024-06-22 19:43:12] info:     zh:ember:uart:ash:   Retry frames: RX=0, TX=0
[2024-06-22 19:43:12] info:     zh:ember:uart:ash:   ACK frames  : RX=0, TX=1
[2024-06-22 19:43:12] info:     zh:ember:uart:ash:   NAK frames  : RX=0, TX=0
[2024-06-22 19:43:12] info:     zh:ember:uart:ash:   nRdy frames : RX=0, TX=0
[2024-06-22 19:43:12] info:     zh:ember:uart:ash:   CRC errors      : RX=0
[2024-06-22 19:43:12] info:     zh:ember:uart:ash:   Comm errors     : RX=0
[2024-06-22 19:43:12] info:     zh:ember:uart:ash:   Length < minimum: RX=0
[2024-06-22 19:43:12] info:     zh:ember:uart:ash:   Length > maximum: RX=0
[2024-06-22 19:43:12] info:     zh:ember:uart:ash:   Bad controls    : RX=0
[2024-06-22 19:43:12] info:     zh:ember:uart:ash:   Bad lengths     : RX=0
[2024-06-22 19:43:12] info:     zh:ember:uart:ash:   Bad ACK numbers : RX=0
[2024-06-22 19:43:12] info:     zh:ember:uart:ash:   Out of buffers  : RX=0
[2024-06-22 19:43:12] info:     zh:ember:uart:ash:   Retry dupes     : RX=0
[2024-06-22 19:43:12] info:     zh:ember:uart:ash:   Out of sequence : RX=0
[2024-06-22 19:43:12] info:     zh:ember:uart:ash:   ACK timeouts    : RX=0
[2024-06-22 19:43:12] info:     zh:ember:uart:ash: ======== ASH stopped ========
[2024-06-22 19:43:12] info:     zh:ember:ezsp: ======== EZSP stopped ========
[2024-06-22 19:43:12] info:     zh:ember: ======== Ember Adapter Stopped ========
[2024-06-22 19:43:13] info:     zh:ember: ======== Ember Adapter Starting ========
[2024-06-22 19:43:13] info:     zh:ember:ezsp: ======== EZSP starting ========
[2024-06-22 19:43:13] info:     zh:ember:uart:ash: ======== ASH NCP reset ========
[2024-06-22 19:43:13] info:     zh:ember:uart:ash: Socket ready
[2024-06-22 19:43:13] info:     zh:ember:uart:ash: ======== ASH starting ========
[2024-06-22 19:43:14] info:     zh:ember:uart:ash: ======== ASH connected ========
[2024-06-22 19:43:14] info:     zh:ember:uart:ash: ======== ASH started ========
[2024-06-22 19:43:14] info:     zh:ember:ezsp: ======== EZSP started ========
[2024-06-22 19:43:14] info:     zh:ember: [STACK STATUS] Network up.
[2024-06-22 19:43:14] info:     zh:ember: [INIT TC] NCP network matches config.
[2024-06-22 19:43:14] info:     zh:ember: [CONCENTRATOR] Started source route discovery. 1247ms until next broadcast.
[2024-06-22 19:43:14] info:     zh:ember:queue: Request dispatching started.
[2024-06-22 19:43:14] info:     zh:ember:ezsp: Received network/route error ROUTE_ERROR_MANY_TO_ONE_ROUTE_FAILURE for "27845".
[2024-06-22 19:43:14] info:     zh:ember:ezsp: Received network/route error ROUTE_ERROR_MANY_TO_ONE_ROUTE_FAILURE for "16298".
[2024-06-22 19:43:14] info:     zh:ember:ezsp: Received network/route error ROUTE_ERROR_MANY_TO_ONE_ROUTE_FAILURE for "27845".
[2024-06-22 19:43:18] info:     zh:ember:ezsp: Received network/route error ROUTE_ERROR_MANY_TO_ONE_ROUTE_FAILURE for "27845".
[2024-06-22 19:43:18] info:     zh:ember:ezsp: Received network/route error ROUTE_ERROR_MANY_TO_ONE_ROUTE_FAILURE for "16298".
[2024-06-22 19:43:18] info:     zh:ember:ezsp: Received network/route error ROUTE_ERROR_MANY_TO_ONE_ROUTE_FAILURE for "27845".
[2024-06-22 19:43:23] info:     zh:ember:ezsp: Received network/route error ROUTE_ERROR_MANY_TO_ONE_ROUTE_FAILURE for "27845".
[2024-06-22 19:43:24] info:     zh:ember:ezsp: Received network/route error ROUTE_ERROR_MANY_TO_ONE_ROUTE_FAILURE for "27845".
[2024-06-22 19:43:28] info:     zh:ember:ezsp: Received network/route error ROUTE_ERROR_MANY_TO_ONE_ROUTE_FAILURE for "27845".
[2024-06-22 19:43:28] info:     zh:ember:ezsp: Received network/route error ROUTE_ERROR_MANY_TO_ONE_ROUTE_FAILURE for "27845".
[2024-06-22 19:43:29] info:     zh:ember:ezsp: Received network/route error ROUTE_ERROR_MANY_TO_ONE_ROUTE_FAILURE for "27845".
[2024-06-22 19:43:34] info:     zh:ember:ezsp: Received network/route error ROUTE_ERROR_MANY_TO_ONE_ROUTE_FAILURE for "16298".
[2024-06-22 19:43:40] info:     zh:ember:ezsp: Received network/route error ROUTE_ERROR_SOURCE_ROUTE_FAILURE for "7782".
[2024-06-22 19:43:43] info:     zh:ember:ezsp: Received network/route error ROUTE_ERROR_MANY_TO_ONE_ROUTE_FAILURE for "16298".
[2024-06-22 19:43:43] info:     zh:ember:ezsp: Received network/route error ROUTE_ERROR_MANY_TO_ONE_ROUTE_FAILURE for "27845".
[2024-06-22 19:43:43] info:     zh:ember:ezsp: Received network/route error ROUTE_ERROR_MANY_TO_ONE_ROUTE_FAILURE for "27845".
[2024-06-22 19:43:44] info:     zh:ember:ezsp: Received network/route error ROUTE_ERROR_MANY_TO_ONE_ROUTE_FAILURE for "16298".
[2024-06-22 19:43:44] info:     zh:ember:ezsp: Received network/route error ROUTE_ERROR_MANY_TO_ONE_ROUTE_FAILURE for "16298".
[2024-06-22 19:43:44] info:     zh:ember:ezsp: Received network/route error ROUTE_ERROR_MANY_TO_ONE_ROUTE_FAILURE for "27845".
[2024-06-22 19:43:44] info:     zh:ember:ezsp: Received network/route error ROUTE_ERROR_MANY_TO_ONE_ROUTE_FAILURE for "16298".
[2024-06-22 19:43:44] info:     zh:ember:ezsp: Received network/route error ROUTE_ERROR_MANY_TO_ONE_ROUTE_FAILURE for "27845".
[2024-06-22 19:43:45] info:     zh:ember:ezsp: Received network/route error ROUTE_ERROR_SOURCE_ROUTE_FAILURE for "7782".
[2024-06-22 19:43:48] info:     zh:ember:ezsp: Received network/route error ROUTE_ERROR_MANY_TO_ONE_ROUTE_FAILURE for "16298".
[2024-06-22 19:43:48] info:     zh:ember:ezsp: Received network/route error ROUTE_ERROR_MANY_TO_ONE_ROUTE_FAILURE for "27845".
[2024-06-22 19:43:48] info:     zh:ember:ezsp: Received network/route error ROUTE_ERROR_MANY_TO_ONE_ROUTE_FAILURE for "27845".
[2024-06-22 19:43:48] info:     zh:ember:ezsp: Received network/route error ROUTE_ERROR_MANY_TO_ONE_ROUTE_FAILURE for "16298".
[2024-06-22 19:43:49] info:     zh:ember:ezsp: Received network/route error ROUTE_ERROR_MANY_TO_ONE_ROUTE_FAILURE for "16298".
[2024-06-22 19:43:51] info:     zh:ember:ezsp: Received network/route error ROUTE_ERROR_SOURCE_ROUTE_FAILURE for "7782".
[2024-06-22 19:44:00] info:     zh:ember:ezsp: Received network/route error ROUTE_ERROR_MANY_TO_ONE_ROUTE_FAILURE for "27845".
[2024-06-22 19:44:00] info:     zh:ember:ezsp: Received network/route error ROUTE_ERROR_MANY_TO_ONE_ROUTE_FAILURE for "27845".
[2024-06-22 19:44:00] info:     zh:ember:ezsp: Received network/route error ROUTE_ERROR_MANY_TO_ONE_ROUTE_FAILURE for "27845".
[2024-06-22 19:44:01] info:     zh:ember:ezsp: Received network/route error ROUTE_ERROR_MANY_TO_ONE_ROUTE_FAILURE for "16298".
[2024-06-22 19:44:01] info:     zh:ember:ezsp: Received network/route error ROUTE_ERROR_MANY_TO_ONE_ROUTE_FAILURE for "27845".
[2024-06-22 19:44:01] info:     zh:ember:ezsp: Received network/route error ROUTE_ERROR_MANY_TO_ONE_ROUTE_FAILURE for "27845".
[2024-06-22 19:44:01] info:     zh:ember:ezsp: Received network/route error ROUTE_ERROR_MANY_TO_ONE_ROUTE_FAILURE for "27845".
[2024-06-22 19:44:02] info:     zh:ember:ezsp: Received network/route error ROUTE_ERROR_MANY_TO_ONE_ROUTE_FAILURE for "27845".
[2024-06-22 19:44:02] info:     zh:ember:ezsp: Received network/route error ROUTE_ERROR_MANY_TO_ONE_ROUTE_FAILURE for "27845".
[2024-06-22 19:44:03] info:     zh:ember:ezsp: Received network/route error ROUTE_ERROR_MANY_TO_ONE_ROUTE_FAILURE for "27845".
[2024-06-22 19:44:03] info:     zh:ember:ezsp: Received network/route error ROUTE_ERROR_MANY_TO_ONE_ROUTE_FAILURE for "16298".
[2024-06-22 19:44:03] info:     zh:ember:ezsp: Received network/route error ROUTE_ERROR_SOURCE_ROUTE_FAILURE for "7782".
[2024-06-22 19:44:03] info:     zh:ember:ezsp: Received network/route error ROUTE_ERROR_MANY_TO_ONE_ROUTE_FAILURE for "16298".
[2024-06-22 19:44:38] info:     zh:ember:ezsp: Received network/route error ROUTE_ERROR_MANY_TO_ONE_ROUTE_FAILURE for "7782".
[2024-06-22 19:44:47] info:     zh:ember:ezsp: Received network/route error ROUTE_ERROR_MANY_TO_ONE_ROUTE_FAILURE for "27845".
[2024-06-22 19:44:52] info:     zh:ember:ezsp: Received network/route error ROUTE_ERROR_MANY_TO_ONE_ROUTE_FAILURE for "16298".
[2024-06-22 19:44:52] info:     zh:ember:ezsp: Received network/route error ROUTE_ERROR_MANY_TO_ONE_ROUTE_FAILURE for "27845".
[2024-06-22 19:44:52] info:     zh:ember:ezsp: Received network/route error ROUTE_ERROR_MANY_TO_ONE_ROUTE_FAILURE for "16298".
[2024-06-22 19:44:52] info:     zh:ember:ezsp: Received network/route error ROUTE_ERROR_MANY_TO_ONE_ROUTE_FAILURE for "27845".
[2024-06-22 19:45:02] info:     zh:ember:ezsp: Received network/route error ROUTE_ERROR_MANY_TO_ONE_ROUTE_FAILURE for "27845".

[EDIT] From the terminal I changed the configuration to [adapter: ezsp] and started again. It seems is now back to working, but I did not change recently this one, the ember configuration has been running since more than 1 month.

After this, I tried to revert back again to ember (and did a restart) and it seems to be still running, so not sure what was the problem here or what is changed for the resolution. I'm getting a lot of battery sensor offline but I guess they went on timeout after a long period of time with the coordinator being down, I guess they will come back sooner or later.

This is the log after the last restart, ember driver is back and I did the final restart

2024-06-22 20:31:48] info:     z2m: Logging to console, file (filename: log.log)
[2024-06-22 20:31:48] info:     z2m: Starting Zigbee2MQTT version 1.38.0 (commit #0e6da85d)
[2024-06-22 20:31:48] info:     z2m: Starting zigbee-herdsman (0.49.2)
[2024-06-22 20:31:48] info:     zh:ember: Using default stack config.
[2024-06-22 20:31:48] info:     zh:ember: ======== Ember Adapter Starting ========
[2024-06-22 20:31:48] info:     zh:ember:ezsp: ======== EZSP starting ========
[2024-06-22 20:31:48] info:     zh:ember:uart:ash: ======== ASH NCP reset ========
[2024-06-22 20:31:48] info:     zh:ember:uart:ash: Socket ready
[2024-06-22 20:31:48] info:     zh:ember:uart:ash: ======== ASH starting ========
[2024-06-22 20:31:48] error:    zh:ember:uart:ash: Received frame with CRC error
[2024-06-22 20:31:49] info:     zh:ember:uart:ash: ======== ASH connected ========
[2024-06-22 20:31:49] info:     zh:ember:uart:ash: ======== ASH started ========
[2024-06-22 20:31:49] info:     zh:ember:ezsp: ======== EZSP started ========
[2024-06-22 20:31:50] info:     zh:ember: [STACK STATUS] Network up.
[2024-06-22 20:31:50] info:     zh:ember: [INIT TC] NCP network matches config.
[2024-06-22 20:31:50] info:     zh:ember: [CONCENTRATOR] Started source route discovery. 1247ms until next broadcast.
[2024-06-22 20:31:50] info:     zh:ember:queue: Request dispatching started.
[2024-06-22 20:31:50] info:     zh:ember:ezsp: Received network/route error ROUTE_ERROR_MANY_TO_ONE_ROUTE_FAILURE for "27845".
[2024-06-22 20:31:50] info:     z2m: zigbee-herdsman started (resumed)
[2024-06-22 20:31:50] info:     z2m: Coordinator firmware version: '{"meta":{"build":0,"ezsp":13,"major":7,"minor":4,"patch":1,"revision":"7.4.1 [GA]","special":0,"type":170},"type":"EmberZNet"}'
[2024-06-22 20:31:50] info:     zh:ember:ezsp: Received network/route error ROUTE_ERROR_MANY_TO_ONE_ROUTE_FAILURE for "27845".
[2024-06-22 20:31:50] info:     z2m: Set transmit power to '20'
[2024-06-22 20:31:50] info:     z2m: Currently 55 devices are joined:
BertrumUK commented 3 weeks ago

I am seeing the same issue after updating Proxmox this morning. I am running the latest version 1.39.0-1, but when trying to get into the UI I get a cloudflare error as I run HA behind CF.

I am using port 8099 and even trying to connect via the local IP and port I get no response. Nothing is being reported in the logs either.

Z2MQTT works fine in every other way, it's just that I cannot reach the Web UI.

nicola-spreafico commented 3 weeks ago

I want to add another experience I have, after I made it working as mentioned in my edit of first message, I had to shutdown the host where Proxmox is running, and once again after the startup I was having the same Z2M issue. So it seems something related of when the host is booting up (or at least Z2M is booting up).

I did again the trick of changing the driver back and forth, but it is not a definitive solution

BertrumUK commented 3 weeks ago

I am running the Sonoff CC2652P adaptor, but I get no errors for the adapter or the Web UI in the logs. It was working this morning before the Proxmox updates so I am guessing that something changed there to stop the Web UI from working now.

Will wait and see if others have similar issues after carrying our a Proxmox update.

BertrumUK commented 3 weeks ago

Rolling back to 1.38.0-1 fixed the issue for me. I updated to the latest update and I lose access to the UI again. Rolling back a 2nd time restores it.

mpuff commented 3 weeks ago

i have this problem on a raspberry pi installation, was working for min 1 year, but now I see in the zigbee logs the ui port is open, but no access to the ui, also no open port when I check with ss -ltn in the terminal. But I can everything control via mqtt, this is working

Micr0mega commented 3 weeks ago

I have similar symptoms, but have not updated my host system (Home Assistant Yellow). I did update to Home Assistant 2024.7.0 yesterday and for a few hours the web UI worked fine.

But after adding two new devices, the UI is not reachable anymore and gives 502: Bad gateway. However, all devices are working fine. Tried multiple restarts of Z2M and HA itself, but only the web UI stays unreachable, everything else functions as expected.

Rolling back to 1.38.0-1 fixed it for me as well.

mpuff commented 3 weeks ago

also another problem, with the safari browser the gui is never working, only with a browser like chrome for me :/

BertrumUK commented 3 weeks ago

similar issue to here

Timmmy001 commented 2 weeks ago

Fix it with a STRG+F5 in Firefox (Delete Cache/Reload). Chrome was ok.