Koenkk / zigbee2mqtt

Zigbee 🐝 to MQTT bridge πŸŒ‰, get rid of your proprietary Zigbee bridges πŸ”¨
https://www.zigbee2mqtt.io
GNU General Public License v3.0
12.17k stars 1.68k forks source link

all my powered devices (routers) down and BUFFER FULL on the coordinator #24387

Open silkyclouds opened 1 month ago

silkyclouds commented 1 month ago

What happened?

Hi,

I noticed some slowness when trying to use my zigbee devices this morning, and took that opportunity to update HA to latest version, knowing it would have to be restarted, sometimes, a restart fixes such things...

I now run HA version 2024.10.2, and Z2M Current version: 1.40.2-1. My controller is a sonoff zigbee dongle (the P model) and is up-to-date as well, latest FW flashed on it from @Koenkk )

weird issue, I can see all my "non-router" devices listed. but all the non battery powered ones are gone. here is what I can see in Z2M logs at start :

[08:10:24] INFO: Preparing to start... [08:10:25] INFO: Socat not enabled [08:10:28] INFO: Starting Zigbee2MQTT... Starting Zigbee2MQTT without watchdog. [2024-10-18 08:10:44] error: zh:zstack:znp: Failed to determine if path is valid: 'Error: spawn udevadm ENOENT' [2024-10-18 08:12:12] error: z2m: Failed to call 'Groups' 'start' (AssertionError [ERR_ASSERTION]: GroupID must be at least 1 at Function.create (/app/node_modules/zigbee-herdsman/src/controller/model/group.ts:129:15) at Controller.createGroup (/app/node_modules/zigbee-herdsman/src/controller/controller.ts:505:22) at Zigbee.createGroup (/app/lib/zigbee.ts:409:23) at Groups.syncGroupsWithSettings (/app/lib/extension/groups.ts:81:118) at Groups.start (/app/lib/extension/groups.ts:52:20) at Controller.callExtensions (/app/lib/controller.ts:399:42) at processTicksAndRejections (node:internal/process/task_queues:95:5) at Controller.start (/app/lib/controller.ts:218:9) at start (/app/index.js:154:5))

the logs whill the keep looping on ping failure messages. Restarting Z2M keeps displaying the same error, and I can't get my devices to get back up.

it looks like udev ain't found anymore, did something change in latest HASS ?

zh:zstack:znp: Failed to determine if path is valid: 'Error: spawn udevadm ENOENT'

and after that, there is this group ID problem, but I'm unsure how to fix this :

Failed to call 'Groups' 'start' (AssertionError [ERR_ASSERTION]: GroupID must be at least 1

here is how it looks in the GUI :

image

As you might imagine, this is really, really problematic. Do anyone else encounter the same issue ? any clue about that error message ?

What did you expect to happen?

my line powered / router devices should show up !

How to reproduce it (minimal and precise)

no idea, it started this morning after latest HA update.

Zigbee2MQTT version

1.40.2-1

Adapter firmware version

CC1352P2_CC2652P_launchpad_coordinator_20240710

Adapter

Sonoff dongle (P model)

Setup

HASS in a VM, passed coordinator, Z2M as an add-on.

Debug log

[08:24:14] INFO: Preparing to start... [08:24:14] INFO: Socat not enabled [08:24:15] INFO: Starting Zigbee2MQTT... Starting Zigbee2MQTT without watchdog. [2024-10-18 08:24:18] error: zh:zstack:znp: Failed to determine if path is valid: 'Error: spawn udevadm ENOENT' [2024-10-18 08:24:18] error: z2m: Failed to set permit join to false (--> 'SREQ: AF - dataRequestExt - {"dstaddrmode":2,"dstaddr":"0x000000000000fffd","destendpoint":242,"dstpanid":0,"srcendpoint":242,"clusterid":33,"transid":1,"options":0,"radius":30,"len":6,"data":{"type":"Buffer","data":[25,2,2,10,0,0]}}' failed with status '(0x11: BUFFER_FULL)' (expected '(0x00: SUCCESS)')) [2024-10-18 08:24:19] error: z2m: Failed to call 'Groups' 'start' (AssertionError [ERR_ASSERTION]: GroupID must be at least 1 at Function.create (/app/node_modules/zigbee-herdsman/src/controller/model/group.ts:129:15) at Controller.createGroup (/app/node_modules/zigbee-herdsman/src/controller/controller.ts:505:22) at Zigbee.createGroup (/app/lib/zigbee.ts:409:23) at Groups.syncGroupsWithSettings (/app/lib/extension/groups.ts:81:118) at Groups.start (/app/lib/extension/groups.ts:52:20) at Controller.callExtensions (/app/lib/controller.ts:399:42) at processTicksAndRejections (node:internal/process/task_queues:95:5) at Controller.start (/app/lib/controller.ts:218:9) at start (/app/index.js:154:5)) [2024-10-18 08:24:25] warning: z2m: Failed to ping 'Chambre Raph et Cel - luminaire - tradfri led light' (attempt 1/1, ZCL command 0x90fd9ffffed4466f/1 genBasic.read(["zclVersion"], {"timeout":10000,"disableResponse":false,"disableRecovery":true,"disableDefaultResponse":true,"direction":0,"reservedBits":0,"writeUndiv":false}) failed (--> 'SREQ: AF - dataRequest - {"dstaddr":51290,"destendpoint":1,"srcendpoint":1,"clusterid":0,"transid":9,"options":0,"radius":30,"len":5,"data":{"type":"Buffer","data":[16,10,0,0,0]}}' failed with status '(0x11: BUFFER_FULL)' (expected '(0x00: SUCCESS)'))) [2024-10-18 08:24:27] warning: z2m: Failed to ping 'Chambre d'amis - luminaire (led centre) - tradfri led light' (attempt 1/1, ZCL command 0x90fd9ffffe175760/1 genBasic.read(["zclVersion"], {"timeout":10000,"disableResponse":false,"disableRecovery":true,"disableDefaultResponse":true,"direction":0,"reservedBits":0,"writeUndiv":false}) failed (--> 'SREQ: AF - dataRequest - {"dstaddr":47180,"destendpoint":1,"srcendpoint":1,"clusterid":0,"transid":10,"options":0,"radius":30,"len":5,"data":{"type":"Buffer","data":[16,11,0,0,0]}}' failed with status '(0x11: BUFFER_FULL)' (expected '(0x00: SUCCESS)'))) [2024-10-18 08:24:29] warning: z2m: Failed to ping 'Chambre d'amis - luminaire (led gauche) - tradfri led light' (attempt 1/1, ZCL command 0x000b57fffeb89236/1 genBasic.read(["zclVersion"], {"timeout":10000,"disableResponse":false,"disableRecovery":true,"disableDefaultResponse":true,"direction":0,"reservedBits":0,"writeUndiv":false}) failed (--> 'SREQ: AF - dataRequest - {"dstaddr":25054,"destendpoint":1,"srcendpoint":1,"clusterid":0,"transid":11,"options":0,"radius":30,"len":5,"data":{"type":"Buffer","data":[16,12,0,0,0]}}' failed with status '(0x11: BUFFER_FULL)' (expected '(0x00: SUCCESS)'))) [2024-10-18 08:24:31] warning: z2m: Failed to ping 'Salon - étagère de droite - tradfri led light' (attempt 1/1, ZCL command 0x040d84fffed2e6cd/1 genBasic.read(["zclVersion"], {"timeout":10000,"disableResponse":false,"disableRecovery":true,"disableDefaultResponse":true,"direction":0,"reservedBits":0,"writeUndiv":false}) failed (--> 'SREQ: AF - dataRequest - {"dstaddr":56423,"destendpoint":1,"srcendpoint":1,"clusterid":0,"transid":12,"options":0,"radius":30,"len":5,"data":{"type":"Buffer","data":[16,13,0,0,0]}}' failed with status '(0x11: BUFFER_FULL)' (expected '(0x00: SUCCESS)'))) [2024-10-18 08:24:33] warning: z2m: Failed to ping 'Salon - barre son / etc. - prise tuya' (attempt 1/1, ZCL command 0xa4c13801c3d05d22/1 genBasic.read(["zclVersion"], {"timeout":10000,"disableResponse":false,"disableRecovery":true,"disableDefaultResponse":true,"direction":0,"reservedBits":0,"writeUndiv":false}) failed (--> 'SREQ: AF - dataRequest - {"dstaddr":17038,"destendpoint":1,"srcendpoint":1,"clusterid":0,"transid":13,"options":0,"radius":30,"len":5,"data":{"type":"Buffer","data":[16,14,0,0,0]}}' failed with status '(0x11: BUFFER_FULL)' (expected '(0x00: SUCCESS)'))) [2024-10-18 08:24:35] warning: z2m: Failed to ping 'Salon - étagère de gauche - tradfri led light' (attempt 1/1, ZCL command 0x84b4dbfffe770a09/1 genBasic.read(["zclVersion"], {"timeout":10000,"disableResponse":false,"disableRecovery":true,"disableDefaultResponse":true,"direction":0,"reservedBits":0,"writeUndiv":false}) failed (--> 'SREQ: AF - dataRequest - {"dstaddr":1987,"destendpoint":1,"srcendpoint":1,"clusterid":0,"transid":14,"options":0,"radius":30,"len":5,"data":{"type":"Buffer","data":[16,15,0,0,0]}}' failed with status '(0x11: BUFFER_FULL)' (expected '(0x00: SUCCESS)'))) [2024-10-18 08:24:37]

silkyclouds commented 1 month ago

One more time, I could not love proxmox more :

image

I will let you know if things get back working after restoring my nightly backup...

But I think there is something wrong with last HASS / Z2M combo.

silkyclouds commented 1 month ago

I've rolled back to previous version of HA, same issue, do you think my coordinator died ? Is it possible ???

I've check Z2M changelog, and it was updated 2 weeks ago, meaning it worked without any issue for approx 2 weeks, and suddenly stopped working.

As a reminder, this morning, I COULD act on my bulbs and other devices, but it was crazy "slow". and after a reboot, they were all gone.

As Z2M do start, I believe it can communicate with the coordinator though. My home is KAPUT, please help me :D

silkyclouds commented 1 month ago

a little more investigation seem to show me that every single message I can see in the log indicated my coordination BUFFER is full :

[2024-10-18 10:58:58] warning: z2m: Failed to ping 'Cave - prise seche linge - prise tuya' (attempt 1/1, ZCL command 0xa4c138001c0367c7/1 genBasic.read(["zclVersion"], {"timeout":10000,"disableResponse":false,"disableRecovery":true,"disableDefaultResponse":true,"direction":0,"reservedBits":0,"writeUndiv":false}) failed (--> 'SREQ: AF - dataRequest - {"dstaddr":39604,"destendpoint":1,"srcendpoint":1,"clusterid":0,"transid":147,"options":0,"radius":30,"len":5,"data":{"type":"Buffer","data":[16,148,0,0,0]}}' failed with status '(0x11: BUFFER_FULL)' (expected '(0x00: SUCCESS)')))

Great-Chart commented 1 month ago

Hi - I've been suffering random drop out issues that I suspect are more interference related than FW related problems with coordinator. Reading your summary (via linked article) can I ask about the process you followed for moving your zigbee network to another channel and how that went for any re-pairing etc?

Aware a recent Z2M update added this feature in Tools/Setting under the advanced tab. Does it just require the add on restarting or HA etc and do the battery / end devices get restored without intervention?

Welcome feedback from your experiences her; including any devices not liking ch25

silkyclouds commented 1 month ago

Hi - I've been suffering random drop out issues that I suspect are more interference related than FW related problems with coordinator. Reading your summary (via linked article) can I ask about the process you followed for moving your zigbee network to another channel and how that went for any re-pairing etc?

Aware a recent Z2M update added this feature in Tools/Setting under the advanced tab. Does it just require the add on restarting or HA etc and do the battery / end devices get restored without intervention?

Welcome feedback from your experiences her; including any devices not liking ch25

I'd like to tell you removing the coordinator backup file , changing the channel to 25, and rebooting was the solution. But damn, tonight, everything broke again.

No more zigbee device available tonight.

silkyclouds commented 4 weeks ago

This is hell on earth, really. all the devices get back, and will suddenly disappear, with no reason. As all my lights are controller through zigbee buttons, I can't control any lights anymore... @Koenkk do you have any idea on how I could debug this issue ? All my devices disconnected at once, and I'm getting BUFFER FULL errors again... :(

While everything disconnects from within Z2M, and obviously from HA:

image

I confirm that the buttons I paired to Z2M groups or individual devices do work enabling / disabling them. The problem is really located at coordinator side.

So the "good" point is I was "smart" enough in the past to bind the buttons ditrectly to the lights, mainly because I didn't want to be HA dependent to start my bulbs. But the bad point is I have some zones (bathroom / basement) where I'm using sonoff ZBMINI-L devices, and these devices can't be binded. My wife is turning crazy and screams at me since two days...

I need to figure out why my coordinator started to have buffer issues, suddenly.

FYI, I updated to latest Z-stack FW about a week ago, could it be that there was a regression and that this buffer issue appeared due to this ?

EDIT : I want to comment on my previous assumption. I don't believe the BUFFER FULL happened due to interferences anymore. I have to disconnect the coordinator physically, and plug it back, in order to empty its buffer, and finally get it to work again (for some time) till it will be full...

I will try to reduce the frequency of the zigbee devices updates...

Is there another, better coordinator to recommend ?

silkyclouds commented 4 weeks ago

by the way I've changed the conf in order to lower the amount of updates that way :

homeassistant: true
permit_join: false
mqtt:
  base_topic: zigbee2mqtt
  server: mqtt://core-mosquitto:1883
  user: addons
  password: blablabla
  reject_unauthorized: true
  version: 4

serial:
  port: >-
    /dev/serial/by-id/usb-Silicon_Labs_Sonoff_Zigbee_3.0_USB_Dongle_Plus_0001-if00-port0

frontend:
  port: 8099

advanced:
  homeassistant_legacy_entity_attributes: false
  legacy_api: false
  legacy_availability_payload: false
  log_level: warning
  log_syslog:
    app_name: Zigbee2MQTT
    eol: /n
    host: localhost
    localhost: localhost
    path: /dev/log
    pid: process.pid
    port: 123
    protocol: tcp4
    type: '5424'
  transmit_power: 10
  channel: 25
  adapter_delay: 1000    log_directory: /app/data/log/

device_options:
  legacy: false
  last_seen: false  
availability:
  active:
    timeout: 60  
    timeout: 1200 
Koenkk commented 4 weeks ago

FYI, I updated to latest Z-stack FW about a week ago, could it be that there was a regression and that this buffer issue appeared due to this ?

That could be, try reverting to the previous fw

Nerivec commented 4 weeks ago

About the two original errors mentioned:

error: zh:zstack:znp: Failed to determine if path is valid: 'Error: spawn udevadm ENOENT'

Shouldn't be a problem as long as the adapter starts after that, it's just an optional validation during startup.

error: z2m: Failed to call 'Groups' 'start' (AssertionError [ERR_ASSERTION]: GroupID must be at least 1

Looks like you have a group with ID zero (in all likelihood) in your configuration.yaml and/or database.db. You might have to dig in and remove it manually, then re-create it with a proper ID (note: if you don't set an ID at all in the UI (or via MQTT) when creating the group, just the name, it will automatically increment from the previous ID and ensure it is proper.).

silkyclouds commented 3 weeks ago

FYI, I updated to latest Z-stack FW about a week ago, could it be that there was a regression and that this buffer issue appeared due to this ?

That could be, try reverting to the previous fw

(venv) root@proxmox:~/cc2538-bsl-master# python cc2538-bsl.py -p /dev/serial/by-id/usb-Silicon_Labs_Sonoff_Zigbee_3.0_USB_Dongle_Plus_0001-if00-port0 -evw --bootloader-sonoff-usb CC1352P2_CC2652P_launchpad_coordinator_20230507.hex
sonoff
Opening port /dev/serial/by-id/usb-Silicon_Labs_Sonoff_Zigbee_3.0_USB_Dongle_Plus_0001-if00-port0, baud 500000
Reading data from CC1352P2_CC2652P_launchpad_coordinator_20230507.hex
Your firmware looks like an Intel Hex file
Connecting to target...
CC1350 PG2.0 (7x7mm): 352KB Flash, 20KB SRAM, CCFG.BL_CONFIG at 0x00057FD8
Primary IEEE Address: 00:12:4B:00:26:B6:9B:6C
Performing mass erase
Erasing all main bank flash sectors
Erase done
Writing 360448 bytes starting at address 0x00000000
Write 104 bytes at 0x00057F988
Write done
Verifying by comparing CRC32 calculations.
Verified (match: 0xe83aa727)

back to good old 20230507. I'll see if it keep fulfilling the buffer. I will keep you posted gents. Thanks for the answers by the way ! :)

EDIT :

I am definitely not lucky recently :

[2024-10-21 08:48:23] error:    z2m: Error while starting zigbee-herdsman
[2024-10-21 08:48:23] error:    z2m: Failed to start zigbee
[2024-10-21 08:48:23] error:    z2m: Check https://www.zigbee2mqtt.io/guide/installation/20_zigbee2mqtt-fails-to-start.html for possible solutions
[2024-10-21 08:48:23] error:    z2m: Exiting...
[2024-10-21 08:48:24] error:    z2m: Error: network commissioning timed out - most likely network with the same panId or extendedPanId already exists nearby (Error: AREQ - ZDO - stateChangeInd after 60000ms
    at Object.start (/app/node_modules/zigbee-herdsman/src/utils/waitress.ts:59:23)
    at ZnpAdapterManager.beginCommissioning (/app/node_modules/zigbee-herdsman/src/adapter/z-stack/adapter/manager.ts:370:31)
    at ZnpAdapterManager.start (/app/node_modules/zigbee-herdsman/src/adapter/z-stack/adapter/manager.ts:91:21)
    at ZStackAdapter.start (/app/node_modules/zigbee-herdsman/src/adapter/z-stack/adapter/zStackAdapter.ts:158:16)
    at Controller.start (/app/node_modules/zigbee-herdsman/src/controller/controller.ts:137:29)
    at Zigbee.start (/app/lib/zigbee.ts:69:27)
    at Controller.start (/app/lib/controller.ts:161:27)
    at start (/app/index.js:154:5))
    at ZnpAdapterManager.beginCommissioning (/app/node_modules/zigbee-herdsman/src/adapter/z-stack/adapter/manager.ts:372:23)
    at ZnpAdapterManager.start (/app/node_modules/zigbee-herdsman/src/adapter/z-stack/adapter/manager.ts:91:21)
    at ZStackAdapter.start (/app/node_modules/zigbee-herdsman/src/adapter/z-stack/adapter/zStackAdapter.ts:158:16)
    at Controller.start (/app/node_modules/zigbee-herdsman/src/controller/controller.ts:137:29)
    at Zigbee.start (/app/lib/zigbee.ts:69:27)
    at Controller.start (/app/lib/controller.ts:161:27)
    at start (/app/index.js:154:5)
silkyclouds commented 3 weeks ago

[2024-10-21 08:48:23] error: z2m: Error while starting zigbee-herdsman [2024-10-21 08:48:23] error: z2m: Failed to start zigbee [2024-10-21 08:48:23] error: z2m: Check https://www.zigbee2mqtt.io/guide/installation/20_zigbee2mqtt-fails-to-start.html for possible solutions [2024-10-21 08:48:23] error: z2m: Exiting... [2024-10-21 08:48:24] error: z2m: Error: network commissioning timed out - most likely network with the same panId or extendedPanId already exists nearby (Error: AREQ - ZDO - stateChangeInd after 60000ms at Object.start (/app/node_modules/zigbee-herdsman/src/utils/waitress.ts:59:23) at ZnpAdapterManager.beginCommissioning (/app/node_modules/zigbee-herdsman/src/adapter/z-stack/adapter/manager.ts:370:31) at ZnpAdapterManager.start (/app/node_modules/zigbee-herdsman/src/adapter/z-stack/adapter/manager.ts:91:21) at ZStackAdapter.start (/app/node_modules/zigbee-herdsman/src/adapter/z-stack/adapter/zStackAdapter.ts:158:16) at Controller.start (/app/node_modules/zigbee-herdsman/src/controller/controller.ts:137:29) at Zigbee.start (/app/lib/zigbee.ts:69:27) at Controller.start (/app/lib/controller.ts:161:27) at start (/app/index.js:154:5)) at ZnpAdapterManager.beginCommissioning (/app/node_modules/zigbee-herdsman/src/adapter/z-stack/adapter/manager.ts:372:23) at ZnpAdapterManager.start (/app/node_modules/zigbee-herdsman/src/adapter/z-stack/adapter/manager.ts:91:21) at ZStackAdapter.start (/app/node_modules/zigbee-herdsman/src/adapter/z-stack/adapter/zStackAdapter.ts:158:16) at Controller.start (/app/node_modules/zigbee-herdsman/src/controller/controller.ts:137:29) at Zigbee.start (/app/lib/zigbee.ts:69:27) at Controller.start (/app/lib/controller.ts:161:27) at start (/app/index.js:154:5)

sorry I didn't see your answer on these points.

I've checked the error and indeed did read koen comment about it being a message I could skip.

I've also edited my config file where I indeed had a calibration thing, so second error message is not there anymore.

Great-Chart commented 3 weeks ago

Hi @silkyclouds - wondered if you'd had improvements with reverting to earlier firmware here? I've been trying to fathom out issues with my network using the Sonoff Dongle-P and experienced buffer full related issues with 20240710 and worked my way back to 20221226 which seemed the most stable. But it goes through periods of needing some devices re-paired, some re-interviewed etc and nominally spacing apart the times when the devices get pinged before it stabilises.

I can get a day and a half if lucky but at other times its much less. Z2M certainly seems to hang when pinging devices (availability @ 15 mins) as if its pre-occupied with a device that's non-responsive temporarily and cannot keep up with the others. I've removed a number of devices completely and disabled several more to try and improve / vary things but nothing is a step in the right direction as yet.

There are numerous posts covering concerns over firmware and/or reporting devices going offline but nothing seems to have surfaced as yet to indicate what course of action to take. I had hoped that you might have seen some improvements with the recent revisions you applied for availability / timeout etc

silkyclouds commented 3 weeks ago

Hi @silkyclouds - wondered if you'd had improvements with reverting to earlier firmware here? I've been trying to fathom out issues with my network using the Sonoff Dongle-P and experienced buffer full related issues with 20240710 and worked my way back to 20221226 which seemed the most stable. But it goes through periods of needing some devices re-paired, some re-interviewed etc and nominally spacing apart the times when the devices get pinged before it stabilises.

I can get a day and a half if lucky but at other times its much less. Z2M certainly seems to hang when pinging devices (availability @ 15 mins) as if its pre-occupied with a device that's non-responsive temporarily and cannot keep up with the others. I've removed a number of devices completely and disabled several more to try and improve / vary things but nothing is a step in the right direction as yet.

There are numerous posts covering concerns over firmware and/or reporting devices going offline but nothing seems to have surfaced as yet to indicate what course of action to take. I had hoped that you might have seen some improvements with the recent revisions you applied for availability / timeout etc

Hi,

I indeed flashed the device back to previous (2023XXXX) FW. It then started to complain about the reuse of the panId. A real pain that cost me an extra couple of hours, and I finally decided to change the damn PanId. Problem is that all my devices (obviously) had to be paired again.

As I have a skyconnect on a shelf, I decided to give it a try (I had to re-pair everything, anyway).

So, after a few more hours figuring out why it was not working out of the box, then one extra hour trying to know why I could not flash it using HA web flasher, which addon needed to be installed to do so, etc.) I finally have my skyconnect running in Z2M using the ember protocol.

I can't say I'm super happy about it as lag still occurs, group binding seems to be a pain (sometimes, only one or two of my bulbs will light up!) and pairing seems to be quite more complicated to get to happen. (I have to re-pair devices deveral times before it works.)

the LQI's are way better though. but I cannot feel any difference (latency wise, stability wise) with the time I was using sonoff's coordinator.

I also now run into a log of warning messages about WRONG_ROUTE, ... definitely not wonderful.

I wish moving to the skyconnect would have fixed all my zigbee issues, but I'm pretty far from it.

Nerivec commented 3 weeks ago

I also now run into a log of warning messages about WRONG_ROUTE, ... definitely not wonderful.

What's the exact message?

It sounds like interferences might be your issue if you experience the same kind of instability with two completely different adapters and brand new networks. That, or one (or several) of the devices on your network is messing things up; some are known to be capable of basically bringing down the whole network because of terrible design (most often Tuya, like this one).

Did you try running a network scan with the Skyconnect with Ember ZLI to see if you have issues with channel interference?

With ember, once you get several hours worth of logs, you can also try to put them through https://nerivec.github.io/z2m-ember-helper/ it might point you in the direction of trouble devices.

silkyclouds commented 3 weeks ago

I also now run into a log of warning messages about WRONG_ROUTE, ... definitely not wonderful.

What's the exact message?

It sounds like interferences might be your issue if you experience the same kind of instability with two completely different adapters and brand new networks. That, or one (or several) of the devices on your network is messing things up; some are known to be capable of basically bringing down the whole network because of terrible design (most often Tuya, like this one).

Did you try running a network scan with the Skyconnect with Ember ZLI to see if you have issues with channel interference?

With ember, once you get several hours worth of logs, you can also try to put them through https://nerivec.github.io/z2m-ember-helper/ it might point you in the direction of trouble devices.

This is really helpful. I will gather some hours of logs and pass them through your tool. I'll be off for a few days but this will definitely be helping !

silkyclouds commented 3 weeks ago

by the way, I noticed that as soon I do pair a new device I get this error :

zh:ember:ezsp: ERROR Transaction failure; status=ERROR_WRONG_DIRECTION. Last Frame: [FRAME: ID=52:"SEND_UNICAST" Seq=9 Len=24].

The device gets detected correctly most of the time, though.

silkyclouds commented 2 weeks ago

I can't say the usage of ember is free of error messages. Strangely, everything seems more reactive, stable, and I've got no disconnections like I used to have with my sonoff P dongle. but I'm getting sooooo many error messages all the time :

error 2024-10-30 15:55:50zh:ember:ezsp: ERROR Transaction failure; status=ERROR_WRONG_DIRECTION. Last Frame: [FRAME: ID=52:"SEND_UNICAST" Seq=32 Len=24].
error 2024-10-30 15:55:55zh:controller: Interview failed for '0x4c5bb3fffe8f750f with error 'Error: Interview failed because can not get active endpoints ('0x4c5bb3fffe8f750f')'
error 2024-10-30 15:55:55z2m: Failed to interview '0x4c5bb3fffe8f750f', device has not successfully been paired
Nerivec commented 2 weeks ago

That WRONG_DIRECTION error is a bit strange sometimes... still trying to get more info on that one. It doesn't appear to behave as intended sometimes. Do you have a fuller log (debug), so I can take a look?

silkyclouds commented 2 weeks ago

That WRONG_DIRECTION error is a bit strange sometimes... still trying to get more info on that one. It doesn't appear to behave as intended sometimes. Do you have a fuller log (debug), so I can take a look?

I just did enable debug again.

Lets wait for a day or two, and i'll send you the debug logs somewhere after that. :)

thanks !

Nerivec commented 2 weeks ago

If you feel up to the task, you can try to modify your install a bit to see if removing the check causes problem or not.

silkyclouds commented 2 weeks ago

Sure, but as I told you, there are LOADS of other warnings and error messages.

I've spent several days re-organising my whole HA setup, rebuilding my dashboards, automations, scenes... as I had to re-pair all my devices (I've moved from the zonoff P dongle to a skyconnect I had on a shelf).

Let me share my debug logs first as I'm afraid there are way more warnings and errors.

it's pretty weird, as these messages were NOT existing with the sonoff (non ember) coordinator, though it was unstable as well, and seemed to loose the end devices way easier.

This is a fresh new zigbee network created from scratch.

log.log

I'm obviously OK to disable any check you want after that check. :)

silkyclouds commented 2 weeks ago

I also see a lot of these ones popping up when in debug mode:

zh:ember:ezsp: Received network/route error ROUTE_ERROR_MANY_TO_ONE_ROUTE_FAILURE for "38264".
image
Nerivec commented 2 weeks ago

Ember is more verbose than zStack for sure. zStack doesn't have as many options to report "general errors" like this, so, Z2M just can't know about them. Hiding these errors would be counterproductive since they are available here; very useful in optimizing networks, and allows for tools like the one I mentioned before.

Route errors are common enough though (unless you have a very stable, very "uninterfered-with" network). Check with the above tool, once you have a decent size log file (several hours), it should tell you if there are any "particularly offending" devices, points worth taking a closer look at, etc.. Note: The presence of Tuya TSxxx usually leads to quite a few of these.

silkyclouds commented 2 weeks ago

Ember is more verbose than zStack for sure. zStack doesn't have as many options to report "general errors" like this, so, Z2M just can't know about them. Hiding these errors would be counterproductive since they are available here; very useful in optimizing networks, and allows for tools like the one I mentioned before.

Route errors are common enough though (unless you have a very stable, very "uninterfered-with" network). Check with the above tool, once you have a decent size log file (several hours), it should tell you if there are any "particularly offending" devices, points worth taking a closer look at, etc..

Oh true, I totally forgot about your previous message.

Thing is, I think ember is way way more verbose, indeed :

image

meaning that, when I enter my amount of routers / end devices and load a 10MB file, it actualy only covers a few minutes of logs :

image

I will put log_rotation: false for a while and then see if I can inject the log again in the webui. but as it created 10MB logs every 5 minutes, I wonder if this will work.

silkyclouds commented 2 weeks ago

bythe way, I started playing with ember-zli, but I got scared at that point :

root@proxmox:~# ember-zli router
[2024-10-31 09:56:49.634] info:     cli: Data folder: /root/ember-zli.
βœ” Adapter connection type Serial
βœ” Adapter firmware baudrate 115200
βœ” Serial port Nabu Casa  usb-Nabu_Casa_SkyConnect_v1.0_329ebaaaed56ed11959652ca5720eef3-if00-port0 (/dev/ttyUSB0)
βœ” Flow control Software Flow Control (rtscts=false)
[2024-10-31 09:56:49.843] info:     zh:ember:ezsp: ======== EZSP starting ========
[2024-10-31 09:56:49.844] info:     zh:ember:uart:ash: ======== ASH Adapter reset ========
[2024-10-31 09:56:49.845] info:     zh:ember:uart:ash: RTS/CTS config is off, enabling software flow control.
[2024-10-31 09:56:49.852] info:     zh:ember:uart:ash: Serial port opened
[2024-10-31 09:56:49.853] info:     zh:ember:uart:ash: ======== ASH starting ========
[2024-10-31 09:56:49.950] info:     zh:ember:uart:ash: ======== ASH connected ========
[2024-10-31 09:56:49.966] info:     zh:ember:uart:ash: ======== ASH started ========
[2024-10-31 09:56:49.967] info:     zh:ember:ezsp: ======== EZSP started ========
[2024-10-31 09:56:49.987] info:     ember: NCP EZSP protocol version (13) lower than Host. Switched.
[2024-10-31 09:56:49.999] info:     ember: NCP version: {"ezsp":13,"revision":"7.4.3 [GA]","build":0,"major":7,"minor":4,"patch":3,"special":0,"type":170}
[2024-10-31 09:56:49.000] info:     cli: Using default stack config.
βœ” Menu Join network
βœ” A network is present in the adapter. Leave and continue join? no
[2024-10-31 09:56:49.771] info:     cli: Join cancelled.

Could you eventually let me know which commands I should run to avoid resetting the existing network of my skyconnect, and simply scan the environment to see if it interferes with my (single, with only a few IoT devices connected to 2.4ghz) wifi network?

Nerivec commented 2 weeks ago

You can use info level for the helper, it should drastically reduce the size of your logs. You can also append each file to the previous one, they should follow each other (can check the last line timestamp vs the first line timestamp of the next).

For ember-zli, you used the router command. You have to use the stack command instead https://github.com/Nerivec/ember-zli/wiki/Stack#scan-network

silkyclouds commented 2 weeks ago

You can use info level for the helper, it should drastically reduce the size of your logs. You can also append each file to the previous one, they should follow each other (can check the last line timestamp vs the first line timestamp of the next).

For ember-zli, you used the router command. You have to use the stack command instead https://github.com/Nerivec/ember-zli/wiki/Stack#scan-network

OK, I've ran into issues yesterday which totally screwed my HASS VM, but this morning I've managed to inject info level logs.

log.log

image

So far, it keeps telling me I should wait a little more to get relevant stats. I'll update you with an up-to-date log.

The ping issues are "normal" as it is normal these devices are powered off at the moment.

But what about these already ?

Network/Router Errors: 1682 -> I guess this is the count of these:

ROUTE_ERROR_MANY_TO_ONE_ROUTE_FAILURE and ROUTE_ERROR_SOURCE_ROUTE_FAILURE

I started looking at the devices that generates all these routes issues. and it affects a lot of different devices and models, searching for the Ids in Z2M reported me (this is a non exhaustive list) :

TS011F_plug_1

LED1937T5

SP 220

E2206

LED1536G5

HGZB-01A

While all devices seem to be impacted, the devices that has the higher level of errors are, non suprisingly, the Tuya TS011F_plug_1. Still, I have more than 30 of these plugs at home, so I'd rather figure out a way to improve things and keep the devices running, than replacing all of them. Also, I can't say they are not acting correctly. They do report their power usage, and do power on and off without severe issues. Some "older" models sometimes takes a little longer to respond though.

Navigating to the extra tabs actually makes me quite scared about my zigbee network.

CCA failure count is high (1.1515 vs 0.0102 "ideal")
This can indicate interferences on the 2.4GHz band on or around the current channel (WiFi, other Zigbee...).

Packet retry count is high (25.1566 vs 2.0597 "ideal")
This can indicate general instability in your network (unresponsive devices, bad routers...).

Stale neighbors count is high (175.75 vs 1 "ideal")
This can indicate poor link quality between devices. Note: This is influenced by pairing/re-pairing.

Bonus : Something weird -> I've started to record these logs at 10PM, and it is now 8.54AM. Still, the tool tells me I only gathered 4.58 hours of logs.

As a reminder, I disabled 2.4ghz wifi for my main devices, and I keep running a 2.4ghz wifi network only for some ESP and older devices (I cannot fix the channel, as I am using terrible deco X50 mesh routers...). My home is located in the countryside, meaning that except for the unique IoT (2.4ghz) network running, there is no such thing as neighbors wifi interferences. The house is an OLD house (1870s approx.), and has some serious walls, but there are routers litterally everywhere, as each light bulb acts as a router (all my light bulbs are tradfri bulbs) + I have approx 35 smart plugs acting as routers, I really would expect things to be stable and to have enough zigbee coverage with all these devices acting as routers.

I did respect a specific order when I re-paired all my devices :

  1. the coordinator in the basement, I started to pair all the smart plugs in the basement, then went up to the upper floor
  2. I then paired all the light bulbs
  3. and finally, the end devices

Since I've moved to ember, I did not notice any end device leaving the network as they did before, when using the sonoff dongle (so this is an improvement).

My zigbee channel is 25. I will updade you with some information gathered using ember-zli...

In general, I can see I did (using my previous sonoff P dongle) and still do (using the skyconnect) have some weird latency when enabling some bulbs.

Nerivec commented 2 weeks ago

Note: as mentioned on the site, the "ideals" are based on a running network with nearly zero issues, so, for a network with a bit of troubles, it is expected that the numbers be higher.

Are you regularly taking routers offline? That can hugely impact the network. Routers are not meant to be powered off completely as it can disrupts the surrounding neighbors for a while.

Route errors do not necessarily mean you will "see" issues, just that the backbone isn't very strong. Devices may however start looking for new connections, and disrupt things for a little while (which might be perceived as latencies in some cases I guess).

About the logs duration, did you append logs together? It can mess things up if the order of the timestamps is not respected. If not, check the timestamp of the first line, and last line, to be sure the log file matches what you'd expect.

silkyclouds commented 2 weeks ago

Note: as mentioned on the site, the "ideals" are based on a running network with nearly zero issues, so, for a network with a bit of troubles, it is expected that the numbers be higher.

Are you regularly taking routers offline? That can hugely impact the network. Routers are not meant to be powered off completely as it can disrupts the surrounding neighbors for a while.

Route errors do not necessarily mean you will "see" issues, just that the backbone isn't very strong. Devices may however start looking for new connections, and disrupt things for a little while (which might be perceived as latencies in some cases I guess).

About the logs duration, did you append logs together? It can mess things up if the order of the timestamps is not respected. If not, check the timestamp of the first line, and last line, to be sure the log file matches what you'd expect.

So, no, I only have two out of all my routers which goes "offline" and this is due to some recent changes. But all the other ones are plugged and powered on 24/7.

so approx 64 devices acting as routers.

I also agree that if routes can't be "fixed", and devices search their way to the coordinator, then I could perceive the time needed for a device to find its route as a latency.

About the log duration, I've simply disabled log rotation : log_rotation: false. I therefore have one single log.

here is the new version of the log log.log

Do you see anything special here that I should investigate to avoid these error messages ? and improve routing ? I always felt that routing in a zigbee network is a serious point of failure, I would expect the devices to stick to their best route once they found the shortest route to the coordinator.

Nerivec commented 2 weeks ago

There's a decent spike (x2-3) in errors for 10 and 11AM (10 to 12), can you see anything that could affect it (particularly the failed CCAs, which means interference on the 2.4GHz band, wifi, thread, zigbee, some proprietary wireless -like Logitech Unify-). Could be just increased usage, but checking to be sure.

These are way off on the route errors: 16687 / 0x412F 29145 / 0x71D9 31087 / 0x796F 33037 / 0x810D 38264 / 0x9578

silkyclouds commented 2 weeks ago

There's a decent spike (x2-3) in errors for 10 and 11AM (10 to 12), can you see anything that could affect it (particularly the failed CCAs, which means interference on the 2.4GHz band, wifi, thread, zigbee, some proprietary wireless -like Logitech Unify-). Could be just increased usage, but checking to be sure.

These are way off on the route errors: 16687 / 0x412F 29145 / 0x71D9 31087 / 0x796F 33037 / 0x810D 38264 / 0x9578

I think it's all increased usage, because nothing automatic is happening at these hours.

Also, as I said, my IoT network (that has unfortunately to remain in 2.4ghz, thanks ESPs...) only has a limited set of devices connected.

By the way, All the problematic outlets (all the ones you listed are tuya plugs) are located in my kitchen, which is actually situated in an annex, placed behind the perimeter wall of my house. The perimeter wall is approximately 1.5 meters wide. I have the impression that this area might be poorly serviced.

Nerivec commented 2 weeks ago

I believe you can flash the Dongle-P to router mode (not that familiar with zStack things), than you could place it near that perimeter wall (but on that side), so it picks up a better signal, and hopefully, relays it better for the other side of the wall.

silkyclouds commented 2 weeks ago

I believe you can flash the Dongle-P to router mode (not that familiar with zStack things), than you could place it near that perimeter wall (but on that side), so it picks up a better signal, and hopefully, relays it better for the other side of the wall.

a few questions though. if I do flash it as a router, what will be the added value of using it as I already do have 66 routers in the house ?

And would I have to flash it so it can manage ember ?

Nerivec commented 1 week ago

I figured you maybe did not have a router very close to that wall you mentioned. It takes the old adapter out of the shelf and puts it to use πŸ˜‰ Once flashed, it will become a regular router device (just like a light bulb, but without the light part 😬), so, it shouldn't matter what coordinator type you have. Its only job becomes routing traffic.

https://github.com/Koenkk/Z-Stack-firmware/tree/master/router/Z-Stack_3.x.0/bin

silkyclouds commented 1 week ago

I figured you maybe did not have a router very close to that wall you mentioned. It takes the old adapter out of the shelf and puts it to use πŸ˜‰ Once flashed, it will become a regular router device (just like a light bulb, but without the light part 😬), so, it shouldn't matter what coordinator type you have. Its only job becomes routing traffic.

https://github.com/Koenkk/Z-Stack-firmware/tree/master/router/Z-Stack_3.x.0/bin

I understand this but back to my comment, I do have several plugs connected behind that wall, and they all do have very good LQI values. I think I really have to go deeper in the analysis of the network using your ember-zli tool.

silkyclouds commented 1 week ago

there we go :

root@proxmox:~/ember-zli# ember-zli stack
[2024-11-04 18:20:24.170] info:     cli: Data folder: /root/ember-zli.
βœ” Path: /dev/ttyUSB0, Baudrate: 115200, RTS/CTS: false. Use this config? yes
[2024-11-04 18:20:24.374] info:     zh:ember:ezsp: ======== EZSP starting ========
[2024-11-04 18:20:24.375] info:     zh:ember:uart:ash: ======== ASH Adapter reset ========
[2024-11-04 18:20:24.376] info:     zh:ember:uart:ash: RTS/CTS config is off, enabling software flow control.
[2024-11-04 18:20:24.381] info:     zh:ember:uart:ash: Serial port opened
[2024-11-04 18:20:24.381] info:     zh:ember:uart:ash: ======== ASH starting ========
[2024-11-04 18:20:24.479] info:     zh:ember:uart:ash: ======== ASH connected ========
[2024-11-04 18:20:24.495] info:     zh:ember:uart:ash: ======== ASH started ========
[2024-11-04 18:20:24.496] info:     zh:ember:ezsp: ======== EZSP started ========
[2024-11-04 18:20:24.515] info:     ember: NCP EZSP protocol version (13) lower than Host. Switched.
[2024-11-04 18:20:24.524] info:     ember: NCP version: {"ezsp":13,"revision":"7.4.3 [GA]","build":0,"major":7,"minor":4,"patch":3,"special":0,"type":170}
βœ” Menu Get stack info
[2024-11-04 18:20:24.820] info:     cli: EmberZNet: 7.4.3 [GA]. EZSP: 13
βœ” Menu Get stack info
[2024-11-04 18:20:24.454] info:     cli: EmberZNet: 7.4.3 [GA]. EZSP: 13
βœ” Menu Get stack config (firmware defaults)
βœ” Save to file? (Only print if not) no
[2024-11-04 18:20:24.084] info:     cli: CONFIG.PACKET_BUFFER_HEAP_SIZE = 255.
[2024-11-04 18:20:24.085] info:     cli: CONFIG.NEIGHBOR_TABLE_SIZE = 16.
[2024-11-04 18:20:24.085] info:     cli: CONFIG.APS_UNICAST_MESSAGE_COUNT = 32.
[2024-11-04 18:20:24.085] info:     cli: CONFIG.BINDING_TABLE_SIZE = 32.
[2024-11-04 18:20:24.085] info:     cli: CONFIG.ADDRESS_TABLE_SIZE = 8.
[2024-11-04 18:20:24.085] info:     cli: CONFIG.MULTICAST_TABLE_SIZE = 8.
[2024-11-04 18:20:24.085] info:     cli: CONFIG.ROUTE_TABLE_SIZE = 16.
[2024-11-04 18:20:24.085] info:     cli: CONFIG.DISCOVERY_TABLE_SIZE = 8.
[2024-11-04 18:20:24.085] info:     cli: CONFIG.STACK_PROFILE = 0.
[2024-11-04 18:20:24.085] info:     cli: CONFIG.SECURITY_LEVEL = 5.
[2024-11-04 18:20:24.085] info:     cli: CONFIG.MAX_HOPS = 30.
[2024-11-04 18:20:24.086] info:     cli: CONFIG.MAX_END_DEVICE_CHILDREN = 32.
[2024-11-04 18:20:24.086] info:     cli: CONFIG.INDIRECT_TRANSMISSION_TIMEOUT = 3000.
[2024-11-04 18:20:24.086] info:     cli: CONFIG.END_DEVICE_POLL_TIMEOUT = 8.
[2024-11-04 18:20:24.086] info:     cli: CONFIG.TX_POWER_MODE = 0.
[2024-11-04 18:20:24.086] info:     cli: CONFIG.DISABLE_RELAY = 0.
[2024-11-04 18:20:24.086] info:     cli: CONFIG.TRUST_CENTER_ADDRESS_CACHE_SIZE = 0.
[2024-11-04 18:20:24.086] info:     cli: CONFIG.SOURCE_ROUTE_TABLE_SIZE = 200.
[2024-11-04 18:20:24.086] info:     cli: CONFIG.FRAGMENT_WINDOW_SIZE = 1.
[2024-11-04 18:20:24.086] info:     cli: CONFIG.FRAGMENT_DELAY_MS = 0.
[2024-11-04 18:20:24.086] info:     cli: CONFIG.KEY_TABLE_SIZE = 12.
[2024-11-04 18:20:24.086] info:     cli: CONFIG.APS_ACK_TIMEOUT = 1600.
[2024-11-04 18:20:24.086] info:     cli: CONFIG.BEACON_JITTER_DURATION = 3.
[2024-11-04 18:20:24.086] info:     cli: CONFIG.PAN_ID_CONFLICT_REPORT_THRESHOLD = 2.
[2024-11-04 18:20:24.086] info:     cli: CONFIG.REQUEST_KEY_TIMEOUT = 0.
[2024-11-04 18:20:24.086] info:     cli: CONFIG.CERTIFICATE_TABLE_SIZE = ZIGBEE_EZSP_ERROR.
[2024-11-04 18:20:24.086] info:     cli: CONFIG.APPLICATION_ZDO_FLAGS = 0.
[2024-11-04 18:20:24.086] info:     cli: CONFIG.BROADCAST_TABLE_SIZE = 64.
[2024-11-04 18:20:24.086] info:     cli: CONFIG.MAC_FILTER_TABLE_SIZE = 15.
[2024-11-04 18:20:24.087] info:     cli: CONFIG.SUPPORTED_NETWORKS = 1.
[2024-11-04 18:20:24.087] info:     cli: CONFIG.SEND_MULTICASTS_TO_SLEEPY_ADDRESS = 0.
[2024-11-04 18:20:24.087] info:     cli: CONFIG.ZLL_GROUP_ADDRESSES = 0.
[2024-11-04 18:20:24.087] info:     cli: CONFIG.ZLL_RSSI_THRESHOLD = 216.
[2024-11-04 18:20:24.087] info:     cli: CONFIG.MTORR_FLOW_CONTROL = 1.
[2024-11-04 18:20:24.087] info:     cli: CONFIG.RETRY_QUEUE_SIZE = 16.
[2024-11-04 18:20:24.087] info:     cli: CONFIG.NEW_BROADCAST_ENTRY_THRESHOLD = 58.
[2024-11-04 18:20:24.087] info:     cli: CONFIG.TRANSIENT_KEY_TIMEOUT_S = 300.
[2024-11-04 18:20:24.087] info:     cli: CONFIG.BROADCAST_MIN_ACKS_NEEDED = 255.
[2024-11-04 18:20:24.087] info:     cli: CONFIG.TC_REJOINS_USING_WELL_KNOWN_KEY_TIMEOUT_S = 300.
[2024-11-04 18:20:24.087] info:     cli: CONFIG.CTUNE_VALUE = 140.
[2024-11-04 18:20:24.087] info:     cli: CONFIG.ASSUME_TC_CONCENTRATOR_TYPE = 1.
[2024-11-04 18:20:24.087] info:     cli: CONFIG.GP_PROXY_TABLE_SIZE = 5.
[2024-11-04 18:20:24.087] info:     cli: CONFIG.GP_SINK_TABLE_SIZE = 0.
[2024-11-04 18:20:24.087] info:     cli: CONFIG.END_DEVICE_CONFIGURATION = ZIGBEE_EZSP_ERROR.
[2024-11-04 18:20:24.087] info:     cli: POLICY.TRUST_CENTER_POLICY = ALLOW_JOINS,ALLOW_UNSECURED_REJOINS.
[2024-11-04 18:20:24.087] info:     cli: POLICY.BINDING_MODIFICATION_POLICY = DISALLOW_BINDING_MODIFICATION.
[2024-11-04 18:20:24.087] info:     cli: POLICY.UNICAST_REPLIES_POLICY = HOST_WILL_NOT_SUPPLY_REPLY.
[2024-11-04 18:20:24.088] info:     cli: POLICY.POLL_HANDLER_POLICY = POLL_HANDLER_IGNORE.
[2024-11-04 18:20:24.088] info:     cli: POLICY.MESSAGE_CONTENTS_IN_CALLBACK_POLICY = MESSAGE_TAG_ONLY_IN_CALLBACK.
[2024-11-04 18:20:24.088] info:     cli: POLICY.TC_KEY_REQUEST_POLICY = DENY_TC_KEY_REQUESTS.
[2024-11-04 18:20:24.088] info:     cli: POLICY.APP_KEY_REQUEST_POLICY = DENY_APP_KEY_REQUESTS.
[2024-11-04 18:20:24.088] info:     cli: POLICY.PACKET_VALIDATE_LIBRARY_POLICY = PACKET_VALIDATE_LIBRARY_CHECKS_ENABLED.
[2024-11-04 18:20:24.088] info:     cli: POLICY.ZLL_POLICY = undefined.
[2024-11-04 18:20:24.088] info:     cli: POLICY.TC_REJOINS_USING_WELL_KNOWN_KEY_POLICY = undefined.
[2024-11-04 18:20:24.088] info:     cli: LIBRARY.ZIGBEE_PRO = PRESENT / ROUTER_CAPABILITY.
[2024-11-04 18:20:24.088] info:     cli: LIBRARY.BINDING = PRESENT.
[2024-11-04 18:20:24.088] info:     cli: LIBRARY.END_DEVICE_BIND = NOT_PRESENT.
[2024-11-04 18:20:24.088] info:     cli: LIBRARY.SECURITY_CORE = PRESENT / ROUTER_SUPPORT.
[2024-11-04 18:20:24.088] info:     cli: LIBRARY.SECURITY_LINK_KEYS = PRESENT.
[2024-11-04 18:20:24.088] info:     cli: LIBRARY.ALARM = NOT_PRESENT.
[2024-11-04 18:20:24.088] info:     cli: LIBRARY.CBKE = NOT_PRESENT.
[2024-11-04 18:20:24.088] info:     cli: LIBRARY.CBKE_DSA_SIGN = NOT_PRESENT.
[2024-11-04 18:20:24.088] info:     cli: LIBRARY.ECC = NOT_PRESENT.
[2024-11-04 18:20:24.088] info:     cli: LIBRARY.CBKE_DSA_VERIFY = NOT_PRESENT.
[2024-11-04 18:20:24.088] info:     cli: LIBRARY.PACKET_VALIDATE = PRESENT / ENABLED.
[2024-11-04 18:20:24.089] info:     cli: LIBRARY.INSTALL_CODE = PRESENT.
[2024-11-04 18:20:24.089] info:     cli: LIBRARY.ZLL = PRESENT.
[2024-11-04 18:20:24.089] info:     cli: LIBRARY.CBKE_283K1 = NOT_PRESENT.
[2024-11-04 18:20:24.089] info:     cli: LIBRARY.ECC_283K1 = NOT_PRESENT.
[2024-11-04 18:20:24.089] info:     cli: LIBRARY.CBKE_CORE = NOT_PRESENT.
[2024-11-04 18:20:24.089] info:     cli: LIBRARY.NCP = PRESENT.
[2024-11-04 18:20:24.089] info:     cli: LIBRARY.MULTI_NETWORK = NOT_PRESENT.
[2024-11-04 18:20:24.089] info:     cli: LIBRARY.ENHANCED_BEACON_REQUEST = PRESENT.
[2024-11-04 18:20:24.089] info:     cli: LIBRARY.CBKE_283K1_DSA_VERIFY = NOT_PRESENT.
[2024-11-04 18:20:24.089] info:     cli: LIBRARY.MULTI_PAN = NOT_PRESENT.
[2024-11-04 18:20:24.089] info:     cli: MFG_TOKEN.CUSTOM_VERSION = 255,255.
[2024-11-04 18:20:24.089] info:     cli: MFG_TOKEN.STRING = 78,97,98,117,32,67,97,115,97,0,255,255,255,255,255,255.
[2024-11-04 18:20:24.089] info:     cli: MFG_TOKEN.BOARD_NAME = 83,107,121,67,111,110,110,101,99,116,32,118,49,46,48,0.
[2024-11-04 18:20:24.089] info:     cli: MFG_TOKEN.MANUF_ID = 255,255.
[2024-11-04 18:20:24.089] info:     cli: MFG_TOKEN.PHY_CONFIG = 255,255.
[2024-11-04 18:20:24.089] info:     cli: MFG_TOKEN.BOOTLOAD_AES_KEY = 255,255,255,255,255,255,255,255,255,255,255,255,255,255,255,255.
[2024-11-04 18:20:24.089] info:     cli: MFG_TOKEN.ASH_CONFIG = 255,255,255,255,255,255,255,255,255,255,255,255,255,255,255,255,255,255,255,255,255,255,255,255,255,255,255,255,255,255,255,255,255,255,255,255,255,255,255,255.
[2024-11-04 18:20:24.089] info:     cli: MFG_TOKEN.EZSP_STORAGE = 255,255,255,255,255,255,255,255.
[2024-11-04 18:20:24.090] info:     cli: MFG_TOKEN.STACK_CAL_DATA = .
[2024-11-04 18:20:24.090] info:     cli: MFG_TOKEN.CBKE_DATA = 255,255,255,255,255,255,255,255,255,255,255,255,255,255,255,255,255,255,255,255,255,255,255,255,255,255,255,255,255,255,255,255,255,255,255,255,255,255,255,255,255,255,255,255,255,255,255,255,255,255,255,255,255,255,255,255,255,255,255,255,255,255,255,255,255,255,255,255,255,255,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,255.
[2024-11-04 18:20:24.090] info:     cli: MFG_TOKEN.INSTALLATION_CODE = 255,255,255,255,255,255,255,255,255,255,255,255,255,255,255,255,255,255,255,255.
[2024-11-04 18:20:24.090] info:     cli: MFG_TOKEN.STACK_CAL_FILTER = .
[2024-11-04 18:20:24.090] info:     cli: MFG_TOKEN.CUSTOM_EUI_64 = 255,255,255,255,255,255,255,255.
[2024-11-04 18:20:24.090] info:     cli: MFG_TOKEN.CTUNE = 255,255.
βœ” Menu Get network info
[2024-11-04 18:20:24.774] info:     cli: Node EUI64=0xe0798dfffe06a3c5 type=COORDINATOR.
[2024-11-04 18:20:24.774] info:     cli: Network parameters:
[2024-11-04 18:20:24.775] info:     cli:   - PAN ID: 59415 (0xE817)
[2024-11-04 18:20:24.775] info:     cli:   - Extended PAN ID: 202,74,231,39,106,233,255,50
[2024-11-04 18:20:24.775] info:     cli:   - Radio Channel: 11
[2024-11-04 18:20:24.775] info:     cli:   - Radio Power: 5 dBm
[2024-11-04 18:20:24.775] info:     cli:   - Preferred Channels: 11,12,13,14,15,16,17,18,19,20,21,22,23,24,25,26
[2024-11-04 18:20:24.775] info:     cli: Network key info:
[2024-11-04 18:20:24.775] info:     cli:   - Set? yes
[2024-11-04 18:20:24.775] info:     cli:   - Sequence Number: 0
[2024-11-04 18:20:24.775] info:     cli:   - Frame Counter: 2510849
[2024-11-04 18:20:24.775] info:     cli:   - Alt Set? no
[2024-11-04 18:20:24.775] info:     cli:   - Alt Sequence Number: 0
[2024-11-04 18:20:24.775] info:     cli: Trust Center link key info:
[2024-11-04 18:20:24.776] info:     cli:   - Properties: HAS_OUTGOING_FRAME_COUNTER|HAS_PARTNER_EUI64|IS_AUTHORIZED
[2024-11-04 18:20:24.776] info:     cli:   - Incoming Frame Counter: 0
[2024-11-04 18:20:24.776] info:     cli:   - Outgoing Frame Counter: 57344
βœ” Restart? (If no, exit) yes
[2024-11-04 18:20:24.332] info:     zh:ember:uart:ash: Port closed.
[2024-11-04 18:20:24.333] info:     zh:ember:uart:ash: ======== ASH stopped ========
[2024-11-04 18:20:24.333] info:     zh:ember:ezsp: ======== EZSP stopped ========
[2024-11-04 18:20:24.334] info:     zh:ember:ezsp: ======== EZSP starting ========
[2024-11-04 18:20:24.334] info:     zh:ember:uart:ash: ======== ASH Adapter reset ========
[2024-11-04 18:20:24.334] info:     zh:ember:uart:ash: RTS/CTS config is off, enabling software flow control.
[2024-11-04 18:20:24.336] info:     zh:ember:uart:ash: Serial port opened
[2024-11-04 18:20:24.337] info:     zh:ember:uart:ash: ======== ASH starting ========
[2024-11-04 18:20:24.429] info:     zh:ember:uart:ash: ======== ASH connected ========
[2024-11-04 18:20:24.444] info:     zh:ember:uart:ash: ======== ASH started ========
[2024-11-04 18:20:24.444] info:     zh:ember:ezsp: ======== EZSP started ========
[2024-11-04 18:20:24.458] info:     ember: NCP EZSP protocol version (13) lower than Host. Switched.
[2024-11-04 18:20:24.465] info:     ember: NCP version: {"ezsp":13,"revision":"7.4.3 [GA]","build":0,"major":7,"minor":4,"patch":3,"special":0,"type":170}
βœ” Menu Scan network
βœ” Radio transmit power [-128-127] 5
βœ” Type of scan Scan each channel for its RSSI value
βœ” Duration of scan per channel 998 msec
[2024-11-04 18:20:24.968] info:     cli: Channel 11: β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™ [-15 dBm]
[2024-11-04 18:20:24.968] info:     cli: Channel 12: β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™ [-52 dBm]
[2024-11-04 18:20:24.968] info:     cli: Channel 13: β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™ [-62 dBm]
[2024-11-04 18:20:24.968] info:     cli: Channel 14: β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™ [-27 dBm]
[2024-11-04 18:20:24.968] info:     cli: Channel 15: β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™ [-26 dBm]
[2024-11-04 18:20:24.968] info:     cli: Channel 16: β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™ [-28 dBm]
[2024-11-04 18:20:24.968] info:     cli: Channel 17: β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™ [-35 dBm]
[2024-11-04 18:20:24.968] info:     cli: Channel 18: β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™ [-64 dBm]
[2024-11-04 18:20:24.968] info:     cli: Channel 19: β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™ [-50 dBm]
[2024-11-04 18:20:24.968] info:     cli: Channel 20: β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™ [-49 dBm]
[2024-11-04 18:20:24.968] info:     cli: Channel 21: β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™ [-27 dBm]
[2024-11-04 18:20:24.968] info:     cli: Channel 22: β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™ [-27 dBm]
[2024-11-04 18:20:24.969] info:     cli: Channel 23: β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™ [-50 dBm]
[2024-11-04 18:20:24.969] info:     cli: Channel 24: β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™ [-63 dBm]
[2024-11-04 18:20:24.969] info:     cli: Channel 25: β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™ [-51 dBm]
[2024-11-04 18:20:24.969] info:     cli: Channel 26: β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’β€’βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™βˆ™ [-38 dBm]
βœ” Menu Scan network
βœ” Radio transmit power [-128-127] 5
βœ” Type of scan Scan each channel for existing networks
βœ” Duration of scan per channel 998 msec
[2024-11-04 18:20:24.815] error:    cli: Failed to scan 11 with status=OBJECT_READ.
[2024-11-04 18:20:24.815] error:    cli: Failed to scan 12 with status=OBJECT_READ.
[2024-11-04 18:20:24.815] error:    cli: Failed to scan 13 with status=OBJECT_READ.
[2024-11-04 18:20:24.816] error:    cli: Failed to scan 17 with status=OBJECT_READ.
[2024-11-04 18:20:24.816] error:    cli: Failed to scan 18 with status=OBJECT_READ.
[2024-11-04 18:20:24.824] error:    cli: Failed to scan 19 with status=OBJECT_READ.
[2024-11-04 18:20:24.824] error:    cli: Failed to scan 24 with status=OBJECT_READ.
[2024-11-04 18:20:24.824] error:    cli: Failed to scan 25 with status=OBJECT_READ.
[2024-11-04 18:20:24.824] error:    cli: Failed to scan 26 with status=OBJECT_READ.
βœ” Menu Backup network
βœ” Network backup save file Use default (/root/ember-zli/coordinator_backup.json)
[2024-11-04 18:20:24.673] info:     cli: Retrieved 0 link keys.
[2024-11-04 18:20:24.697] info:     cli: Network backup written to '/root/ember-zli/coordinator_backup.json'.
βœ” Restart? (If no, exit) yes
[2024-11-04 18:20:24.376] info:     zh:ember:uart:ash: Port closed.
[2024-11-04 18:20:24.376] info:     zh:ember:uart:ash: ======== ASH stopped ========
[2024-11-04 18:20:24.376] info:     zh:ember:ezsp: ======== EZSP stopped ========
[2024-11-04 18:20:24.377] info:     zh:ember:ezsp: ======== EZSP starting ========
[2024-11-04 18:20:24.377] info:     zh:ember:uart:ash: ======== ASH Adapter reset ========
[2024-11-04 18:20:24.377] info:     zh:ember:uart:ash: RTS/CTS config is off, enabling software flow control.
[2024-11-04 18:20:24.379] info:     zh:ember:uart:ash: Serial port opened
[2024-11-04 18:20:24.379] info:     zh:ember:uart:ash: ======== ASH starting ========
[2024-11-04 18:20:24.472] info:     zh:ember:uart:ash: ======== ASH connected ========
[2024-11-04 18:20:24.487] info:     zh:ember:uart:ash: ======== ASH started ========
[2024-11-04 18:20:24.488] info:     zh:ember:ezsp: ======== EZSP started ========
[2024-11-04 18:20:24.501] info:     ember: NCP EZSP protocol version (13) lower than Host. Switched.
[2024-11-04 18:20:24.509] info:     ember: NCP version: {"ezsp":13,"revision":"7.4.3 [GA]","build":0,"major":7,"minor":4,"patch":3,"special":0,"type":170}

I'm not totally sure how to interpret the channel scan. My coordinator is configured to use channel 25 in Z2M.

as you can see it failed to scan for existing networks. see errors.

Is there anything going wrong ?

As I do notice the dots are not easily readable in the logs, here is a screenshot for you :

image
Nerivec commented 1 week ago

Channel 25 is probably good for you indeed. Good balance between well-supported channel, and lower overall interference. Definitely avoid 11.

Not quite sure about that error. Is it persistent?

I do have several plugs connected behind that wall

You have good routers on both side of the wall, near the wall, correct? Large walls can sometimes be a problem, so having a router close-by with good signal on each side usually helps. (That's what I meant to say.)

Have you tried the higher configs 8.0.2 build?

silkyclouds commented 1 week ago

Channel 25 is probably good for you indeed. Good balance between well-supported channel, and lower overall interference. Definitely avoid 11.

Not quite sure about that error. Is it persistent?

I do have several plugs connected behind that wall

You have good routers on both side of the wall, near the wall, correct? Large walls can sometimes be a problem, so having a router close-by with good signal on each side usually helps. (That's what I meant to say.)

Have you tried the higher configs 8.0.2 build?

Now this is crazy, I am 100% confident I did pick channel 25 when I flashed and started to configure this all new skyconnect coordinator, but I double checked and can see channel 11 is indeed used in Z2M config.

What is best practice to change this again ? same as dongle P? removing the coordinator.backup file, changing the channel, and restart z2M ?

Nerivec commented 1 week ago

Hmm, strange indeed. You can just change the channel in configuration.yaml, restart Z2M, and it should broadcast a channel change to the network (most usually follow, might have to wake up a few end devices by triggering them). Should be the same for all adapters now that the ZDO is standard (though only really tested on z-stack and ember). https://www.zigbee2mqtt.io/guide/configuration/zigbee-network.html#changing-the-zigbee-channel

silkyclouds commented 1 week ago

Hmm, strange indeed. You can just change the channel in configuration.yaml, restart Z2M, and it should broadcast a channel change to the network (most usually follow, might have to wake up a few end devices by triggering them). Should be the same for all adapters now that the ZDO is standard (though only really tested on z-stack and ember). https://www.zigbee2mqtt.io/guide/configuration/zigbee-network.html#changing-the-zigbee-channel

yeah I did change the channel several times before (using the P-dongle) and I always did remove the coordinator.backup file. I'll do this in the afternoon and will see if all these routing errors keeps displaying.

silkyclouds commented 1 week ago

I've changed the channel without any issue.

But today I am pairing my moes devices and now this :

error 2024-11-05 12:11:19z2m: Publish 'set' 'state' to 'Salon - prise VARMBLIXT ' failed: 'Error: ZCL command 0xa4c1388b5595cf19/1 genOnOff.off({}, {"timeout":10000,"disableResponse":false,"disableRecovery":false,"disableDefaultResponse":false,"direction":0,"reservedBits":0,"writeUndiv":false}) failed ({"target":54201,"apsFrame":{"profileId":260,"clusterId":6,"sourceEndpoint":1,"destinationEndpoint":1,"options":4416,"groupId":0,"sequence":204},"zclSequence":191,"commandIdentifier":11} timed out after 10000ms)'
error 2024-11-05 12:47:33zh:ember:uart:ash: Received ERROR from adapter, with code=ERROR_EXCEEDED_MAXIMUM_ACK_TIMEOUT_COUNT.
error 2024-11-05 12:47:33zh:ember:uart:ash: ASH disconnected | Adapter status: ASH_NCP_FATAL_ERROR
error 2024-11-05 12:47:33zh:ember:uart:ash: Error while parsing received frame, status=ASH_NCP_FATAL_ERROR.
error 2024-11-05 12:47:33zh:ember: Adapter fatal error: HOST_FATAL_ERROR
error 2024-11-05 12:47:33z2m: Adapter disconnected, stopping
error 2024-11-05 12:48:55zh:ember:ezsp: ERROR Transaction failure; status=ERROR_WRONG_DIRECTION. Last Frame: [FRAME: ID=52:"SEND_UNICAST" Seq=115 Len=24].
error 2024-11-05 12:50:19zh:ember:uart:ash: Received ERROR from adapter, with code=ERROR_EXCEEDED_MAXIMUM_ACK_TIMEOUT_COUNT.
error 2024-11-05 12:50:19zh:ember:uart:ash: ASH disconnected | Adapter status: ASH_NCP_FATAL_ERROR
error 2024-11-05 12:50:19zh:ember:uart:ash: Error while parsing received frame, status=ASH_NCP_FATAL_ERROR.
error 2024-11-05 12:50:19zh:ember: Adapter fatal error: HOST_FATAL_ERROR
error 2024-11-05 12:50:19z2m: Adapter disconnected, stopping

So many errors...

Nerivec commented 1 week ago

Try updating to 7.4.4, some users were having weird issues like this with versions before, for some reason, 7.4.4 seemed to fix it. You can also try the firmware I mentioned above, 8.0.2 with higher configs. Something's definitely not very stable in your setup, but so many factors to take into account... πŸ˜…

silkyclouds commented 1 week ago

Trying updating to 7.4.4, some users were having weird issues like this with versions before, for some reason, 7.4.4 seemed to fix it. You can also try the firmware I mentioned above, 8.0.2 with higher configs. Something's definitely not very stable in your setup, but so many factors to take into account... πŸ˜…

Considering I’m constantly dealing with a barrage of errorsβ€”especially routing issuesβ€”I think it’s time to try some experimental firmware. If it could help resolve things, I’m all in. Right now, it’s like a daily ritual: some plug or another fails to start in the morning when triggered by my buttons (which are bound through Z2M).

And, every morning, I get the delightful experience of my wife saying, β€œOh, that light didn’t come on,” with an unmistakable tone of condescension.

Having things not work is one thing, but enduring that daily β€œI told you so” is a matter of honor. I need to put an end to it.

So, I started silicon labs flasher HA addon, as I believe 7.4.4 must be stable and pushed to the skyconnect but, I stop Z2M addon, start the flasher addon, and it looks like it keep grabbing 7.4.3 :

-----------------------------------------------------------

 Add-on: Silicon Labs Flasher
 Silicon Labs firmware flasher add-on
-----------------------------------------------------------
 Add-on version: 0.3.0
 You are running the latest version of this add-on.
 System: Home Assistant OS 13.2  (amd64 / qemux86-64)
 Home Assistant Core: 2024.10.4
 Home Assistant Supervisor: 2024.10.3
-----------------------------------------------------------
 Please, share the above information when looking for help
 or support in, e.g., GitHub, forums or the Discord chat.
-----------------------------------------------------------
s6-rc: info: service banner successfully started
s6-rc: info: service universal-silabs-flasher: starting
[09:24:24] INFO: Checking /dev/ttyUSB0 identifying SkyConnect v1.0 from Nabu Casa.
[09:24:24] INFO: Starting universal-silabs-flasher with /dev/ttyUSB0 (bootloader baudrate 115200)
2024-11-06 09:24:24.893 core-silabs-flasher universal_silabs_flasher.flash INFO Extracted GBL metadata: NabuCasaMetadata(metadata_version=1, sdk_version='4.4.3', ezsp_version='7.4.3.0', ot_rcp_version=None, cpc_version=None, fw_type=<FirmwareImageType.NCP_UART_HW: 'ncp-uart-hw'>, baudrate=115200)
2024-11-06 09:24:24.894 core-silabs-flasher universal_silabs_flasher.flasher INFO Probing ApplicationType.GECKO_BOOTLOADER at 115200 baud
2024-11-06 09:24:26.903 core-silabs-flasher universal_silabs_flasher.flasher INFO Probing ApplicationType.EZSP at 115200 baud
2024-11-06 09:24:28.148 core-silabs-flasher universal_silabs_flasher.flasher INFO Detected ApplicationType.EZSP, version '7.4.3.0 build 0' (7.4.3.0.0) at 115200 baudrate (bootloader baudrate None)
2024-11-06 09:24:34.370 core-silabs-flasher universal_silabs_flasher.flasher INFO Probing ApplicationType.GECKO_BOOTLOADER at 115200 baud
2024-11-06 09:24:35.389 core-silabs-flasher universal_silabs_flasher.flasher INFO Detected bootloader version '2.1.1'
2024-11-06 09:24:35.389 core-silabs-flasher universal_silabs_flasher.flasher INFO Detected ApplicationType.GECKO_BOOTLOADER, version '2.1.1' at 115200 baudrate (bootloader baudrate 115200)
skyconnect_ncp-uart-hw_7.4.3.0.gbl
[09:25:08] INFO: universal-silabs-flasher-up script exited with code 0
s6-rc: info: service universal-silabs-flasher successfully started
s6-rc: info: service legacy-services: starting
s6-rc: info: service legacy-services successfully started
s6-rc: info: service legacy-services: stopping
s6-rc: info: service legacy-services successfully stopped
s6-rc: info: service universal-silabs-flasher: stopping
s6-rc: info: service universal-silabs-flasher successfully stopped
s6-rc: info: service banner: stopping
s6-rc: info: service banner successfully stopped
s6-rc: info: service legacy-cont-init: stopping
s6-rc: info: service legacy-cont-init successfully stopped
s6-rc: info: service fix-attrs: stopping
s6-rc: info: service fix-attrs successfully stopped
s6-rc: info: service s6rc-oneshot-runner: stopping
s6-rc: info: service s6rc-oneshot-runner successfully stopped

Looking at ZLF changelog indeed displays it will only update the FW to 7.4.3. Can I put a gbl file somewhere to force it to update to 7.4.4 and above ?

Or should I use ember-zli ?

Nerivec commented 1 week ago

You can use ember-zli, but I believe there's a hidden field somewhere to put a custom URL in that flasher addon too? You can give it a link to github. https://github.com/NabuCasa/silabs-firmware-builder/releases/download/v2024.10.21/skyconnect_zigbee_ncp_7.4.4.0.gbl

silkyclouds commented 1 week ago

You can use ember-zli, but I believe there's a hidden field somewhere to put a custom URL in that flasher addon too? You can give it a link to github. https://github.com/NabuCasa/silabs-firmware-builder/releases/download/v2024.10.21/skyconnect_zigbee_ncp_7.4.4.0.gbl

There is indeed a FW url field in the advances options ! Well seen ! :)

BUUUUUUT, it's not working :

-----------------------------------------------------------
 Add-on: Silicon Labs Flasher
 Silicon Labs firmware flasher add-on
-----------------------------------------------------------
 Add-on version: 0.3.0
 You are running the latest version of this add-on.
 System: Home Assistant OS 13.2  (amd64 / qemux86-64)
 Home Assistant Core: 2024.10.4
 Home Assistant Supervisor: 2024.10.3
-----------------------------------------------------------
 Please, share the above information when looking for help
 or support in, e.g., GitHub, forums or the Discord chat.
-----------------------------------------------------------
s6-rc: info: service banner successfully started
s6-rc: info: service universal-silabs-flasher: starting
[13:49:52] INFO: Starting universal-silabs-flasher with /dev/ttyUSB0 (bootloader baudrate 115200)
Traceback (most recent call last):
  File "/usr/local/bin/universal-silabs-flasher", line 8, in <module>
    sys.exit(main())
             ^^^^^^
  File "/usr/local/lib/python3.11/site-packages/click/core.py", line 1157, in __call__
    return self.main(*args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/click/core.py", line 1078, in main
    rv = self.invoke(ctx)
         ^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/click/core.py", line 1688, in invoke
    return _process_result(sub_ctx.command.invoke(sub_ctx))
                           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/click/core.py", line 1434, in invoke
    return ctx.invoke(self.callback, **ctx.params)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/click/core.py", line 783, in invoke
    return __callback(*args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/click/decorators.py", line 33, in new_func
    return f(get_current_context(), *args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/universal_silabs_flasher/flash.py", line 40, in inner
    return asyncio.run(f(*args, **kwargs))
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/asyncio/runners.py", line 190, in run
    return runner.run(main)
           ^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/asyncio/runners.py", line 118, in run
    return self._loop.run_until_complete(task)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/asyncio/base_events.py", line 654, in run_until_complete
    return future.result()
           ^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/universal_silabs_flasher/flash.py", line 297, in flash
    metadata = fw_image.get_nabucasa_metadata()
               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/universal_silabs_flasher/firmware.py", line 178, in get_nabucasa_metadata
    return NabuCasaMetadata.from_json(json.loads(metadata))
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/universal_silabs_flasher/firmware.py", line 93, in from_json
    raise ValueError(
ValueError: Unknown metadata version: 2, expected 1
[13:49:54] INFO: universal-silabs-flasher-up script exited with code 1
s6-rc: warning: unable to start service universal-silabs-flasher: command exited 1
s6-rc: info: service banner: stopping
/run/s6/basedir/scripts/rc.init: warning: s6-rc failed to properly bring all the services up! Check your logs (in /run/uncaught-logs/current if you have in-container logging) for more information.
/run/s6/basedir/scripts/rc.init: fatal: stopping the container.
s6-rc: info: service banner successfully stopped
s6-rc: info: service legacy-cont-init: stopping
s6-rc: info: service legacy-cont-init successfully stopped
s6-rc: info: service fix-attrs: stopping
s6-rc: info: service fix-attrs successfully stopped
s6-rc: info: service s6rc-oneshot-runner: stopping
s6-rc: info: service s6rc-oneshot-runner successfully stopped

Would you recommend me to go for 8.0.2 though ? is there any risk ?

Nerivec commented 1 week ago

Looks like the add-on is outdated. Use universal-silabs-flasher directly (make sure it's up-to-date), or ember-zli. Try 7.4.4 first, see if it stabilizes a bit.

silkyclouds commented 1 week ago

Looks like the add-on is outdated. Use universal-silabs-flasher directly (make sure it's up-to-date), or ember-zli. Try 7.4.4 first, see if it stabilizes a bit.

nope, it's up-to-date: Current version: 0.3.0

I see no 0.3.1 at all, no way to use it to update to 7.4.4. :(

Nerivec commented 1 week ago

nope, it's up-to-date: Current version: 0.3.0

The actual flasher behind it is outdated. I've notified puddly.

silkyclouds commented 1 week ago

nope, it's up-to-date: Current version: 0.3.0

The actual flasher behind it is outdated. I've notified puddly.

I'll wait for the update then. I can do anything about it atm. Maybe would it be nice to query a repository and allow the user to pick the desired FW. (Eg: 7.4.4 stable vs. 8.0.2). But using the url is also fine. ;)

Nerivec commented 1 week ago

You can use ember-zli (it does what you mentioned πŸ˜‰) or universal-silabs-flasher from another machine to flash the firmware you want though.