Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Homeassistant Yellow Ember #22530

Closed
Mar1usW3 opened this issue May 7, 2024 · 8 comments
Closed

Homeassistant Yellow Ember #22530

Mar1usW3 opened this issue May 7, 2024 · 8 comments
Labels
ember Issues related to ember driver problem Something isn't working

Comments

@Mar1usW3
Copy link

Mar1usW3 commented May 7, 2024

What happened?

I recently switched to ember but every first start the following error occurs. Second start is fine.

What did you expect to happen?

No response

How to reproduce it (minimal and precise)

No response

Zigbee2MQTT version

1.37.0

Adapter firmware version

7.4.2

Adapter

HA Yellow

Setup

Addon in HA

Debug log

[2024-05-07 20:58:22] info: 	z2m: Logging to console, file (filename: log.log)
[2024-05-07 20:58:26] debug: 	z2m: Loaded state from file /config/zigbee2mqtt/state.json
[2024-05-07 20:58:26] info: 	z2m: Starting Zigbee2MQTT version 1.37.0 (commit #unknown)
[2024-05-07 20:58:26] info: 	z2m: Starting zigbee-herdsman (0.45.0)
[2024-05-07 20:58:26] debug: 	z2m: Using zigbee-herdsman with settings: '{"adapter":{"concurrent":null,"delay":null,"disableLED":false},"backupPath":"/config/zigbee2mqtt/coordinator_backup.json","databaseBackupPath":"/config/zigbee2mqtt/database.db.backup","databasePath":"/config/zigbee2mqtt/database.db","network":{"channelList":[15],"extendedPanID":[0,87,174,108,124,189,189,1],"networkKey":"HIDDEN","panID":20910},"serialPort":{"adapter":"ember","baudRate":115200,"path":"/dev/ttyAMA1","rtscts":true}}'
[2024-05-07 20:58:26] debug: 	zh:adapter: Failed to validate path: 'Error: spawn udevadm ENOENT'
[2024-05-07 20:58:26] debug: 	zh:ember: Using delay=5.
[2024-05-07 20:58:26] debug: 	zh:controller: Starting with options '{"network":{"networkKeyDistribute":false,"networkKey":[10,50,250,203,143,196,207,222,241,222,211,80,171,24,131,183],"panID":20910,"extendedPanID":[0,87,174,108,124,189,189,1],"channelList":[15]},"serialPort":{"baudRate":115200,"rtscts":true,"path":"/dev/ttyAMA1","adapter":"ember"},"databasePath":"/config/zigbee2mqtt/database.db","databaseBackupPath":"/config/zigbee2mqtt/database.db.backup","backupPath":"/config/zigbee2mqtt/coordinator_backup.json","adapter":{"disableLED":false,"concurrent":null,"delay":null}}'
[2024-05-07 20:58:26] info: 	zh:ember: ======== Ember Adapter Starting ========
[2024-05-07 20:58:26] debug: 	zh:ember: Starting EZSP with stack configuration: "default".
[2024-05-07 20:58:26] info: 	zh:ember:ezsp: ======== EZSP starting ========
[2024-05-07 20:58:26] info: 	zh:ember:uart:ash: ======== ASH NCP reset ========
[2024-05-07 20:58:26] debug: 	zh:ember:uart:ash: Opening serial port with {"path":"/dev/ttyAMA1","baudRate":115200,"rtscts":true,"autoOpen":false,"parity":"none","stopBits":1,"xon":false,"xoff":false}
[2024-05-07 20:58:26] info: 	zh:ember:uart:ash: Serial port opened
[2024-05-07 20:58:26] info: 	zh:ember:uart:ash: ======== ASH starting ========
[2024-05-07 20:58:26] debug: 	zh:ember:uart:ash: ---> [FRAME type=RST]
[2024-05-07 20:58:26] debug: 	zh:ember:uart:ash: Waiting for RSTACK... 0/2500
[2024-05-07 20:58:26] debug: 	zh:ember:uart:ash: <--- [FRAME type=ERROR]
[2024-05-07 20:58:26] error: 	zh:ember:uart:ash: Received ERROR from NCP while connecting, with code=RESET_WATCHDOG.
[2024-05-07 20:58:26] error: 	zh:ember:uart:ash: ASH disconnected | NCP status: ASH_NCP_FATAL_ERROR
[2024-05-07 20:58:26] debug: 	zh:ember:uart:ash: Error while parsing received frame in NOT_CONNECTED state (flags=0), status=ASH_NCP_FATAL_ERROR.
[2024-05-07 20:58:26] info: 	zh:ember:uart:ash: ======== ASH NCP reset ========
[2024-05-07 20:58:26] info: 	zh:ember:uart:ash: ======== ASH starting ========
[2024-05-07 20:58:26] debug: 	zh:ember:uart:ash: ---> [FRAME type=RST]
[2024-05-07 20:58:26] debug: 	zh:ember:uart:ash: Waiting for RSTACK... 0/2500
[2024-05-07 20:58:27] debug: 	zh:ember:uart:ash: Waiting for RSTACK... 100/2500
[2024-05-07 20:58:27] debug: 	zh:ember:uart:ash: Waiting for RSTACK... 200/2500
[2024-05-07 20:58:27] debug: 	zh:ember:uart:ash: Waiting for RSTACK... 300/2500
[2024-05-07 20:58:27] debug: 	zh:ember:uart:ash: Waiting for RSTACK... 400/2500
[2024-05-07 20:58:27] debug: 	zh:ember:uart:ash: Waiting for RSTACK... 500/2500
[2024-05-07 20:58:27] debug: 	zh:ember:uart:ash: Waiting for RSTACK... 600/2500
[2024-05-07 20:58:27] debug: 	zh:ember:uart:ash: Waiting for RSTACK... 700/2500
[2024-05-07 20:58:27] debug: 	zh:ember:uart:ash: Waiting for RSTACK... 800/2500
[2024-05-07 20:58:27] debug: 	zh:ember:uart:ash: Waiting for RSTACK... 900/2500
[2024-05-07 20:58:27] debug: 	zh:ember:uart:ash: <--- [FRAME type=RSTACK]
[2024-05-07 20:58:27] info: 	zh:ember:uart:ash: ======== ASH connected ========
[2024-05-07 20:58:27] info: 	zh:ember:uart:ash: ======== ASH started ========
[2024-05-07 20:58:27] info: 	zh:ember:ezsp: ======== EZSP started ========
[2024-05-07 20:58:27] debug: 	zh:ember:ezsp: ===> [FRAME: ID=0:"VERSION" Seq=0 Len=4]
[2024-05-07 20:58:27] debug: 	zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=0]
[2024-05-07 20:58:27] debug: 	zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=0 frmRx=0]
[2024-05-07 20:58:29] warning: 	zh:ember:uart:ash: Frame(s) in progress cancelled in [1ac1020b0a527e]
[2024-05-07 20:58:29] debug: 	zh:ember:uart:ash: <--- [FRAME type=RSTACK]
[2024-05-07 20:58:29] error: 	zh:ember:uart:ash: Received unexpected reset from NCP, with reason=RESET_SOFTWARE.
[2024-05-07 20:58:29] error: 	zh:ember:uart:ash: ASH disconnected: ASH_ERROR_NCP_RESET | NCP status: ASH_NCP_FATAL_ERROR
[2024-05-07 20:58:29] debug: 	zh:ember:uart:ash: Error while parsing received frame in NOT_CONNECTED state (flags=0), status=HOST_FATAL_ERROR.
[2024-05-07 20:58:29] debug: 	zh:ember:uart:ash: Error while parsing received frame in NOT_CONNECTED state (flags=0), status=HOST_FATAL_ERROR.
[2024-05-07 20:58:30] debug: 	zh:ember:uart:ash: Error while parsing received frame in NOT_CONNECTED state (flags=0), status=HOST_FATAL_ERROR.
[2024-05-07 20:58:33] debug: 	zh:ember:uart:ash: Error while parsing received frame in NOT_CONNECTED state (flags=0), status=HOST_FATAL_ERROR.
[2024-05-07 20:58:37] debug: 	zh:ember:uart:ash: Error while parsing received frame in NOT_CONNECTED state (flags=0), status=HOST_FATAL_ERROR.
[2024-05-07 20:58:40] debug: 	zh:ember:uart:ash: Error while parsing received frame in NOT_CONNECTED state (flags=0), status=HOST_FATAL_ERROR.
[2024-05-07 20:58:42] debug: 	zh:ember:ezsp: =x=> [FRAME: ID=0:"VERSION" Seq=0 Len=4] Error: Error: timed out after 14400ms
[2024-05-07 20:58:42] error: 	zh:ember:ezsp: ERROR Transaction failure; status=undefined. Last: [FRAME: ID=0:"VERSION" Seq=0 Len=4].
[2024-05-07 20:58:42] error: 	zh:ember: !!! NCP FATAL ERROR reason=undefined. ATTEMPTING RESET... !!!
[2024-05-07 20:58:42] debug: 	zh:ember:queue: Dispatching stopped; queue=0 priorityQueue=0
[2024-05-07 20:58:42] info: 	zh:ember:uart:ash: ASH COUNTERS since last clear:
[2024-05-07 20:58:42] info: 	zh:ember:uart:ash:   Total frames: RX=2, TX=3
[2024-05-07 20:58:42] info: 	zh:ember:uart:ash:   Cancelled   : RX=1, TX=0
[2024-05-07 20:58:42] info: 	zh:ember:uart:ash:   DATA frames : RX=0, TX=1
[2024-05-07 20:58:42] info: 	zh:ember:uart:ash:   DATA bytes  : RX=0, TX=4
[2024-05-07 20:58:42] info: 	zh:ember:uart:ash:   Retry frames: RX=0, TX=0
[2024-05-07 20:58:42] info: 	zh:ember:uart:ash:   ACK frames  : RX=0, TX=1
[2024-05-07 20:58:42] info: 	zh:ember:uart:ash:   NAK frames  : RX=0, TX=0
[2024-05-07 20:58:42] info: 	zh:ember:uart:ash:   nRdy frames : RX=0, TX=0
[2024-05-07 20:58:42] info: 	zh:ember:uart:ash:   CRC errors      : RX=0
[2024-05-07 20:58:42] info: 	zh:ember:uart:ash:   Comm errors     : RX=0
[2024-05-07 20:58:42] info: 	zh:ember:uart:ash:   Length < minimum: RX=0
[2024-05-07 20:58:42] info: 	zh:ember:uart:ash:   Length > maximum: RX=0
[2024-05-07 20:58:42] info: 	zh:ember:uart:ash:   Bad controls    : RX=0
[2024-05-07 20:58:42] info: 	zh:ember:uart:ash:   Bad lengths     : RX=0
[2024-05-07 20:58:42] info: 	zh:ember:uart:ash:   Bad ACK numbers : RX=0
[2024-05-07 20:58:42] info: 	zh:ember:uart:ash:   Out of buffers  : RX=0
[2024-05-07 20:58:42] info: 	zh:ember:uart:ash:   Retry dupes     : RX=0
[2024-05-07 20:58:42] info: 	zh:ember:uart:ash:   Out of sequence : RX=0
[2024-05-07 20:58:42] info: 	zh:ember:uart:ash:   ACK timeouts    : RX=0
[2024-05-07 20:58:42] error: 	z2m: Error while starting zigbee-herdsman
[2024-05-07 20:58:42] error: 	z2m: Failed to start zigbee
[2024-05-07 20:58:42] error: 	z2m: Check https://www.zigbee2mqtt.io/guide/installation/20_zigbee2mqtt-fails-to-start.html for possible solutions
[2024-05-07 20:58:42] error: 	z2m: Exiting...
[2024-05-07 20:58:42] error: 	z2m: Error: 
    at Ezsp.ezspVersion (/app/node_modules/zigbee-herdsman/src/adapter/ember/ezsp/ezsp.ts:1301:19)
    at EmberAdapter.emberVersion (/app/node_modules/zigbee-herdsman/src/adapter/ember/adapter/emberAdapter.ts:1642:66)
    at EmberAdapter.initEzsp (/app/node_modules/zigbee-herdsman/src/adapter/ember/adapter/emberAdapter.ts:802:9)
    at EmberAdapter.start (/app/node_modules/zigbee-herdsman/src/adapter/ember/adapter/emberAdapter.ts:2660:24)
    at Controller.start (/app/node_modules/zigbee-herdsman/src/controller/controller.ts:124:29)
    at Zigbee.start (/app/lib/zigbee.ts:62:27)
    at Controller.start (/app/lib/controller.ts:108:27)
    at start (/app/index.js:107:5)
@Mar1usW3 Mar1usW3 added the problem Something isn't working label May 7, 2024
@Koenkk Koenkk added the ember Issues related to ember driver label May 7, 2024
@Nerivec
Copy link
Collaborator

Nerivec commented May 7, 2024

Try the "no hardware flow control" firmware https://github.com/darkxst/silabs-firmware-builder/raw/ember-nohw/firmware_builds/yellow/ncp-uart-hw-v7.4.1.0-yellow-115200.gbl (make sure to set rtscts: false in your config)
It should solve some of these.
There is a potential fix for the rest in dev (it's linked to some virtualized envs, and got worse in last couple of months with HA in particular, might require a fix elsewhere than z2m too...). I'm keeping an eye on it.

@Jopinder
Copy link

Jopinder commented May 7, 2024

Same exact issue on a newly installed Yellow with no devices added.
No ZHA or multiprotocol running. If I change the adapter to "ezsp" z2m starts fine.

Flashed firmware mentioned above and set rtscts: false. z2m starts fine with adapter "ember" now :)

Before flash:

[22:52:31] INFO: Preparing to start...
[22:52:32] INFO: Socat not enabled
[22:52:34] INFO: Starting Zigbee2MQTT...
[2024-05-07 22:52:37] info: 	z2m: Logging to console, file (filename: log.log)
[2024-05-07 22:52:41] info: 	z2m: Starting Zigbee2MQTT version 1.37.0 (commit #unknown)
[2024-05-07 22:52:41] info: 	z2m: Starting zigbee-herdsman (0.45.0)
[2024-05-07 22:52:41] info: 	zh:ember: ======== Ember Adapter Starting ========
[2024-05-07 22:52:41] info: 	zh:ember:ezsp: ======== EZSP starting ========
[2024-05-07 22:52:41] info: 	zh:ember:uart:ash: ======== ASH NCP reset ========
[2024-05-07 22:52:41] info: 	zh:ember:uart:ash: Serial port opened
[2024-05-07 22:52:41] info: 	zh:ember:uart:ash: ======== ASH starting ========
[2024-05-07 22:52:41] error: 	zh:ember:uart:ash: Received ERROR from NCP while connecting, with code=RESET_WATCHDOG.
[2024-05-07 22:52:41] error: 	zh:ember:uart:ash: ASH disconnected | NCP status: ASH_NCP_FATAL_ERROR
[2024-05-07 22:52:41] info: 	zh:ember:uart:ash: ======== ASH NCP reset ========
[2024-05-07 22:52:41] info: 	zh:ember:uart:ash: ======== ASH starting ========
[2024-05-07 22:52:42] info: 	zh:ember:uart:ash: ======== ASH connected ========
[2024-05-07 22:52:42] info: 	zh:ember:uart:ash: ======== ASH started ========
[2024-05-07 22:52:42] info: 	zh:ember:ezsp: ======== EZSP started ========
[2024-05-07 22:52:43] warning: 	zh:ember:uart:ash: Frame(s) in progress cancelled in [1ac1020b0a527e]
[2024-05-07 22:52:43] error: 	zh:ember:uart:ash: Received unexpected reset from NCP, with reason=RESET_SOFTWARE.
[2024-05-07 22:52:43] error: 	zh:ember:uart:ash: ASH disconnected: ASH_ERROR_NCP_RESET | NCP status: ASH_NCP_FATAL_ERROR
[2024-05-07 22:52:57] error: 	zh:ember:ezsp: ERROR Transaction failure; status=undefined. Last: [FRAME: ID=0:"VERSION" Seq=0 Len=4].
[2024-05-07 22:52:57] error: 	zh:ember: !!! NCP FATAL ERROR reason=undefined. ATTEMPTING RESET... !!!
[2024-05-07 22:52:57] info: 	zh:ember:uart:ash: ASH COUNTERS since last clear:
[2024-05-07 22:52:57] info: 	zh:ember:uart:ash:   Total frames: RX=2, TX=3
[2024-05-07 22:52:57] info: 	zh:ember:uart:ash:   Cancelled   : RX=1, TX=0
[2024-05-07 22:52:57] info: 	zh:ember:uart:ash:   DATA frames : RX=0, TX=1
[2024-05-07 22:52:57] info: 	zh:ember:uart:ash:   DATA bytes  : RX=0, TX=4
[2024-05-07 22:52:57] info: 	zh:ember:uart:ash:   Retry frames: RX=0, TX=0
[2024-05-07 22:52:57] info: 	zh:ember:uart:ash:   ACK frames  : RX=0, TX=1
[2024-05-07 22:52:57] info: 	zh:ember:uart:ash:   NAK frames  : RX=0, TX=0
[2024-05-07 22:52:57] info: 	zh:ember:uart:ash:   nRdy frames : RX=0, TX=0
[2024-05-07 22:52:57] info: 	zh:ember:uart:ash:   CRC errors      : RX=0
[2024-05-07 22:52:57] info: 	zh:ember:uart:ash:   Comm errors     : RX=0
[2024-05-07 22:52:57] info: 	zh:ember:uart:ash:   Length < minimum: RX=0
[2024-05-07 22:52:57] info: 	zh:ember:uart:ash:   Length > maximum: RX=0
[2024-05-07 22:52:57] info: 	zh:ember:uart:ash:   Bad controls    : RX=0
[2024-05-07 22:52:57] info: 	zh:ember:uart:ash:   Bad lengths     : RX=0
[2024-05-07 22:52:57] info: 	zh:ember:uart:ash:   Bad ACK numbers : RX=0
[2024-05-07 22:52:57] info: 	zh:ember:uart:ash:   Out of buffers  : RX=0
[2024-05-07 22:52:57] info: 	zh:ember:uart:ash:   Retry dupes     : RX=0
[2024-05-07 22:52:57] info: 	zh:ember:uart:ash:   Out of sequence : RX=0
[2024-05-07 22:52:57] info: 	zh:ember:uart:ash:   ACK timeouts    : RX=0
[2024-05-07 22:52:57] error: 	z2m: Error while starting zigbee-herdsman
[2024-05-07 22:52:57] error: 	z2m: Failed to start zigbee
[2024-05-07 22:52:57] error: 	z2m: Check https://www.zigbee2mqtt.io/guide/installation/20_zigbee2mqtt-fails-to-start.html for possible solutions
[2024-05-07 22:52:57] error: 	z2m: Exiting...
[2024-05-07 22:52:57] error: 	z2m: Error: 
    at Ezsp.ezspVersion (/app/node_modules/zigbee-herdsman/src/adapter/ember/ezsp/ezsp.ts:1301:19)
    at EmberAdapter.emberVersion (/app/node_modules/zigbee-herdsman/src/adapter/ember/adapter/emberAdapter.ts:1642:66)
    at EmberAdapter.initEzsp (/app/node_modules/zigbee-herdsman/src/adapter/ember/adapter/emberAdapter.ts:802:9)
    at EmberAdapter.start (/app/node_modules/zigbee-herdsman/src/adapter/ember/adapter/emberAdapter.ts:2660:24)
    at Controller.start (/app/node_modules/zigbee-herdsman/src/controller/controller.ts:124:29)
    at Zigbee.start (/app/lib/zigbee.ts:62:27)
    at Controller.start (/app/lib/controller.ts:108:27)
    at start (/app/index.js:107:5)

After flash:

[23:01:44] INFO: Preparing to start...
[23:01:45] INFO: Socat not enabled
[23:01:47] INFO: Starting Zigbee2MQTT...
[2024-05-07 23:01:50] info: 	z2m: Logging to console, file (filename: log.log)
[2024-05-07 23:01:54] info: 	z2m: Starting Zigbee2MQTT version 1.37.0 (commit #unknown)
[2024-05-07 23:01:54] info: 	z2m: Starting zigbee-herdsman (0.45.0)
[2024-05-07 23:01:54] info: 	zh:ember: ======== Ember Adapter Starting ========
[2024-05-07 23:01:54] info: 	zh:ember:ezsp: ======== EZSP starting ========
[2024-05-07 23:01:54] info: 	zh:ember:uart:ash: ======== ASH NCP reset ========
[2024-05-07 23:01:54] info: 	zh:ember:uart:ash: RTS/CTS config is off, enabling software flow control.
[2024-05-07 23:01:54] info: 	zh:ember:uart:ash: Serial port opened
[2024-05-07 23:01:54] info: 	zh:ember:uart:ash: ======== ASH starting ========
[2024-05-07 23:01:55] info: 	zh:ember:uart:ash: ======== ASH connected ========
[2024-05-07 23:01:55] info: 	zh:ember:uart:ash: ======== ASH started ========
[2024-05-07 23:01:55] info: 	zh:ember:ezsp: ======== EZSP started ========
[2024-05-07 23:01:55] warning: 	zh:ember: [EzspConfigId] Failed to SET "APS_UNICAST_MESSAGE_COUNT" TO "32" with status=ERROR_OUT_OF_MEMORY. Firmware value will be used instead.
[2024-05-07 23:01:55] info: 	zh:ember: [STACK STATUS] Network up.
[2024-05-07 23:01:56] info: 	zh:ember: [INIT TC] NCP network matches config.
[2024-05-07 23:01:56] info: 	zh:ember: [CONCENTRATOR] Started source route discovery. 1248ms until next broadcast.
[2024-05-07 23:01:56] info: 	z2m: zigbee-herdsman started (resumed)
[2024-05-07 23:01:56] 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-05-07 23:01:56] info: 	z2m: Currently 0 devices are joined:
[2024-05-07 23:01:56] info: 	z2m: Zigbee: disabling joining new devices.
[2024-05-07 23:01:56] info: 	z2m: Connecting to MQTT server at mqtt://core-mosquitto:1883
[2024-05-07 23:01:56] info: 	z2m: Connected to MQTT server
[2024-05-07 23:01:56] info: 	z2m: Started frontend on port 8099
[2024-05-07 23:01:56] info: 	z2m: Zigbee2MQTT started!

@Mar1usW3
Copy link
Author

Mar1usW3 commented May 8, 2024 •
edited

Try the "no hardware flow control" firmware https://github.com/darkxst/silabs-firmware-builder/raw/ember-nohw/firmware_builds/yellow/ncp-uart-hw-v7.4.1.0-yellow-115200.gbl (make sure to set rtscts: false in your config) It should solve some of these. There is a potential fix for the rest in dev (it's linked to some virtualized envs, and got worse in last couple of months with HA in particular, might require a fix elsewhere than z2m too...). I'm keeping an eye on it.

flashed the "no hardware flow control" firmware but 7.4.2.0 version and set rtscts to flase and looking good now!

Thank You!

@Mar1usW3 Mar1usW3 closed this as completed May 8, 2024
@Nerivec Nerivec mentioned this issue May 9, 2024
Open
@Nerivec
Copy link
Collaborator

Nerivec commented May 9, 2024

@Mar1usW3 Do you mind testing a firmware with hardware flow control on your Yellow with 1.37.1 and provide a debug log of the startup sequence?
Make sure to adjust the rtscts setting accordingly.

@Mar1usW3
Copy link
Author

Mar1usW3 commented May 10, 2024 •
edited

@Mar1usW3 Do you mind testing a firmware with hardware flow control on your Yellow with 1.37.1 and provide a debug log of the startup sequence?

Make sure to adjust the rtscts setting accordingly.

Can do it. So rtscts needs to be true after flashing?

@Nerivec
Copy link
Collaborator

Nerivec commented May 10, 2024

Yes, with hardware flow control, true, without, false.

@Mar1usW3
Copy link
Author

so i flashed the yellow with https://github.com/darkxst/silabs-firmware-builder/raw/main/firmware_builds/yellow/ncp-uart-hw-v7.4.2.0-yellow-115200.gbl and rtscts to true. It is now starting but with some errors.
I only copied the logfile till MQTT connect. If you need more let me know

[2024-05-10 13:04:13] info: 	z2m: Logging to console, file (filename: log.log)
[2024-05-10 13:04:13] debug: 	z2m: Loaded state from file /config/zigbee2mqtt/state.json
[2024-05-10 13:04:13] info: 	z2m: Starting Zigbee2MQTT version 1.37.1 (commit #unknown)
[2024-05-10 13:04:13] info: 	z2m: Starting zigbee-herdsman (0.46.6)
[2024-05-10 13:04:13] debug: 	z2m: Using zigbee-herdsman with settings: '{"adapter":{"concurrent":null,"delay":null,"disableLED":false},"backupPath":"/config/zigbee2mqtt/coordinator_backup.json","databaseBackupPath":"/config/zigbee2mqtt/database.db.backup","databasePath":"/config/zigbee2mqtt/database.db","network":{"channelList":[15],"extendedPanID":[xXx],"networkKey":"HIDDEN","panID":20910},"serialPort":{"adapter":"ember","baudRate":115200,"path":"/dev/ttyAMA1","rtscts":true}}'
[2024-05-10 13:04:13] debug: 	zh:adapter: Failed to validate path: 'Error: spawn udevadm ENOENT'
[2024-05-10 13:04:13] debug: 	zh:ember: Using delay=5.
[2024-05-10 13:04:13] debug: 	zh:controller: Starting with options '{"network":{"networkKeyDistribute":false,"networkKey":[10,50,250,203,143,196,207,222,241,222,211,80,171,24,131,183],"panID":20910,"extendedPanID":[xXx],"channelList":[15]},"serialPort":{"baudRate":115200,"rtscts":true,"path":"/dev/ttyAMA1","adapter":"ember"},"databasePath":"/config/zigbee2mqtt/database.db","databaseBackupPath":"/config/zigbee2mqtt/database.db.backup","backupPath":"/config/zigbee2mqtt/coordinator_backup.json","adapter":{"disableLED":false,"concurrent":null,"delay":null}}'
[2024-05-10 13:04:13] info: 	zh:ember: ======== Ember Adapter Starting ========
[2024-05-10 13:04:13] debug: 	zh:ember: Starting EZSP with stack configuration: "default".
[2024-05-10 13:04:13] info: 	zh:ember:ezsp: ======== EZSP starting ========
[2024-05-10 13:04:13] info: 	zh:ember:uart:ash: ======== ASH NCP reset ========
[2024-05-10 13:04:13] debug: 	zh:ember:uart:ash: Opening serial port with {"path":"/dev/ttyAMA1","baudRate":115200,"rtscts":true,"autoOpen":false,"parity":"none","stopBits":1,"xon":false,"xoff":false}
[2024-05-10 13:04:13] info: 	zh:ember:uart:ash: Serial port opened
[2024-05-10 13:04:13] info: 	zh:ember:uart:ash: ======== ASH starting ========
[2024-05-10 13:04:13] debug: 	zh:ember:uart:ash: ---> [FRAME type=RST]
[2024-05-10 13:04:13] debug: 	zh:ember:uart:ash: Waiting for RSTACK... 0/2500
[2024-05-10 13:04:13] debug: 	zh:ember:uart:ash: Waiting for RSTACK... 100/2500
[2024-05-10 13:04:13] debug: 	zh:ember:uart:ash: Waiting for RSTACK... 200/2500
[2024-05-10 13:04:13] debug: 	zh:ember:uart:ash: Waiting for RSTACK... 300/2500
[2024-05-10 13:04:14] debug: 	zh:ember:uart:ash: Waiting for RSTACK... 400/2500
[2024-05-10 13:04:14] debug: 	zh:ember:uart:ash: Waiting for RSTACK... 500/2500
[2024-05-10 13:04:14] debug: 	zh:ember:uart:ash: <--- [FRAME type=ERROR]
[2024-05-10 13:04:14] error: 	zh:ember:uart:ash: Received ERROR from NCP while connecting, with code=RESET_WATCHDOG.
[2024-05-10 13:04:14] error: 	zh:ember:uart:ash: ASH disconnected | NCP status: ASH_NCP_FATAL_ERROR
[2024-05-10 13:04:14] error: 	zh:ember:uart:ash: Error while parsing received frame, status=ASH_NCP_FATAL_ERROR.
[2024-05-10 13:04:14] info: 	zh:ember:uart:ash: ======== ASH NCP reset ========
[2024-05-10 13:04:14] info: 	zh:ember:uart:ash: ======== ASH starting ========
[2024-05-10 13:04:14] debug: 	zh:ember:uart:ash: ---> [FRAME type=RST]
[2024-05-10 13:04:14] debug: 	zh:ember:uart:ash: Waiting for RSTACK... 0/2500
[2024-05-10 13:04:14] debug: 	zh:ember:uart:ash: Waiting for RSTACK... 100/2500
[2024-05-10 13:04:14] debug: 	zh:ember:uart:ash: Waiting for RSTACK... 200/2500
[2024-05-10 13:04:14] debug: 	zh:ember:uart:ash: Waiting for RSTACK... 300/2500
[2024-05-10 13:04:14] debug: 	zh:ember:uart:ash: Waiting for RSTACK... 400/2500
[2024-05-10 13:04:14] debug: 	zh:ember:uart:ash: Waiting for RSTACK... 500/2500
[2024-05-10 13:04:14] debug: 	zh:ember:uart:ash: Waiting for RSTACK... 600/2500
[2024-05-10 13:04:14] debug: 	zh:ember:uart:ash: Waiting for RSTACK... 700/2500
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: Waiting for RSTACK... 800/2500
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: Waiting for RSTACK... 900/2500
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: Waiting for RSTACK... 1000/2500
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=RSTACK]
[2024-05-10 13:04:15] info: 	zh:ember:uart:ash: ======== ASH connected ========
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=NAK]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=NAK ackNum=0]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=0]
[2024-05-10 13:04:15] info: 	zh:ember:uart:ash: ======== ASH started ========
[2024-05-10 13:04:15] info: 	zh:ember:ezsp: ======== EZSP started ========
[2024-05-10 13:04:15] debug: 	zh:ember:ezsp: ===> [FRAME: ID=0:"VERSION" Seq=0 Len=4]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=0 frmRx=0]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=1]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=1 frmNum=0] Added to rxQueue
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=1]
[2024-05-10 13:04:15] debug: 	zh:ember:ezsp: <=== [FRAME: ID=0:"VERSION" Seq=0 Len=7]
[2024-05-10 13:04:15] debug: 	zh:ember: NCP info: EZSPVersion=13 StackType=2 StackVersion=29728
[2024-05-10 13:04:15] debug: 	zh:ember:ezsp: ===> [FRAME: ID=170:"GET_VALUE" Seq=1 Len=6]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=1 frmRx=1]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=2]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=2 frmNum=1] Added to rxQueue
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=2]
[2024-05-10 13:04:15] debug: 	zh:ember:ezsp: <=== [FRAME: ID=170:"GET_VALUE" Seq=1 Len=14]
[2024-05-10 13:04:15] debug: 	zh:ember: NCP version info: {"ezsp":13,"revision":"7.4.2 [GA]","build":0,"major":7,"minor":4,"patch":2,"special":0,"type":170}
[2024-05-10 13:04:15] debug: 	zh:ember:ezsp: ===> [FRAME: ID=83:"SET_CONFIGURATION_VALUE" Seq=2 Len=8]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=2 frmRx=2]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=3]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=3 frmNum=2] Added to rxQueue
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=3]
[2024-05-10 13:04:15] debug: 	zh:ember:ezsp: <=== [FRAME: ID=83:"SET_CONFIGURATION_VALUE" Seq=2 Len=6]
[2024-05-10 13:04:15] debug: 	zh:ember: [EzspConfigId] SET "ADDRESS_TABLE_SIZE" TO "16" with status=SUCCESS.
[2024-05-10 13:04:15] debug: 	zh:ember:ezsp: ===> [FRAME: ID=83:"SET_CONFIGURATION_VALUE" Seq=3 Len=8]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=3 frmRx=3]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=4]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=4 frmNum=3] Added to rxQueue
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=4]
[2024-05-10 13:04:15] debug: 	zh:ember:ezsp: <=== [FRAME: ID=83:"SET_CONFIGURATION_VALUE" Seq=3 Len=6]
[2024-05-10 13:04:15] debug: 	zh:ember: [EzspConfigId] SET "TRUST_CENTER_ADDRESS_CACHE_SIZE" TO "2" with status=SUCCESS.
[2024-05-10 13:04:15] debug: 	zh:ember:ezsp: ===> [FRAME: ID=83:"SET_CONFIGURATION_VALUE" Seq=4 Len=8]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=4 frmRx=4]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=5]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=5 frmNum=4] Added to rxQueue
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=5]
[2024-05-10 13:04:15] debug: 	zh:ember:ezsp: <=== [FRAME: ID=83:"SET_CONFIGURATION_VALUE" Seq=4 Len=6]
[2024-05-10 13:04:15] debug: 	zh:ember: [EzspConfigId] SET "INDIRECT_TRANSMISSION_TIMEOUT" TO "7680" with status=SUCCESS.
[2024-05-10 13:04:15] debug: 	zh:ember:ezsp: ===> [FRAME: ID=83:"SET_CONFIGURATION_VALUE" Seq=5 Len=8]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=5 frmRx=5]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=6]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=6 frmNum=5] Added to rxQueue
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=6]
[2024-05-10 13:04:15] debug: 	zh:ember:ezsp: <=== [FRAME: ID=83:"SET_CONFIGURATION_VALUE" Seq=5 Len=6]
[2024-05-10 13:04:15] debug: 	zh:ember: [EzspConfigId] SET "MAX_HOPS" TO "30" with status=SUCCESS.
[2024-05-10 13:04:15] debug: 	zh:ember:ezsp: ===> [FRAME: ID=83:"SET_CONFIGURATION_VALUE" Seq=6 Len=8]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=6 frmRx=6]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=7]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=7 frmNum=6] Added to rxQueue
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=7]
[2024-05-10 13:04:15] debug: 	zh:ember:ezsp: <=== [FRAME: ID=83:"SET_CONFIGURATION_VALUE" Seq=6 Len=6]
[2024-05-10 13:04:15] debug: 	zh:ember: [EzspConfigId] SET "TX_POWER_MODE" TO "32768" with status=SUCCESS.
[2024-05-10 13:04:15] debug: 	zh:ember:ezsp: ===> [FRAME: ID=83:"SET_CONFIGURATION_VALUE" Seq=7 Len=8]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=7 frmRx=7]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=0]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=0 frmNum=7] Added to rxQueue
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=0]
[2024-05-10 13:04:15] debug: 	zh:ember:ezsp: <=== [FRAME: ID=83:"SET_CONFIGURATION_VALUE" Seq=7 Len=6]
[2024-05-10 13:04:15] debug: 	zh:ember: [EzspConfigId] SET "SUPPORTED_NETWORKS" TO "1" with status=SUCCESS.
[2024-05-10 13:04:15] debug: 	zh:ember:ezsp: ===> [FRAME: ID=171:"SET_VALUE" Seq=8 Len=8]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=0 frmRx=0]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=1]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=1 frmNum=0] Added to rxQueue
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=1]
[2024-05-10 13:04:15] debug: 	zh:ember:ezsp: <=== [FRAME: ID=171:"SET_VALUE" Seq=8 Len=6]
[2024-05-10 13:04:15] debug: 	zh:ember: [EzspValueId] SET "END_DEVICE_KEEP_ALIVE_SUPPORT_MODE" TO "3" with status=SUCCESS.
[2024-05-10 13:04:15] debug: 	zh:ember:ezsp: ===> [FRAME: ID=85:"SET_POLICY" Seq=9 Len=7]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=1 frmRx=1]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=2]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=2 frmNum=1] Added to rxQueue
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=2]
[2024-05-10 13:04:15] debug: 	zh:ember:ezsp: <=== [FRAME: ID=85:"SET_POLICY" Seq=9 Len=6]
[2024-05-10 13:04:15] debug: 	zh:ember: [EzspPolicyId] SET "BINDING_MODIFICATION_POLICY" TO "18" with status=SUCCESS.
[2024-05-10 13:04:15] debug: 	zh:ember:ezsp: ===> [FRAME: ID=85:"SET_POLICY" Seq=10 Len=7]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=2 frmRx=2]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=3]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=3 frmNum=2] Added to rxQueue
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=3]
[2024-05-10 13:04:15] debug: 	zh:ember:ezsp: <=== [FRAME: ID=85:"SET_POLICY" Seq=10 Len=6]
[2024-05-10 13:04:15] debug: 	zh:ember: [EzspPolicyId] SET "MESSAGE_CONTENTS_IN_CALLBACK_POLICY" TO "65" with status=SUCCESS.
[2024-05-10 13:04:15] debug: 	zh:ember:ezsp: ===> [FRAME: ID=171:"SET_VALUE" Seq=11 Len=9]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=3 frmRx=3]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=4]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=4 frmNum=3] Added to rxQueue
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=4]
[2024-05-10 13:04:15] debug: 	zh:ember:ezsp: <=== [FRAME: ID=171:"SET_VALUE" Seq=11 Len=6]
[2024-05-10 13:04:15] debug: 	zh:ember: [EzspValueId] SET "MAXIMUM_INCOMING_TRANSFER_SIZE" TO "82,0" with status=SUCCESS.
[2024-05-10 13:04:15] debug: 	zh:ember:ezsp: ===> [FRAME: ID=171:"SET_VALUE" Seq=12 Len=9]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=4 frmRx=4]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=5]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=5 frmNum=4] Added to rxQueue
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=5]
[2024-05-10 13:04:15] debug: 	zh:ember:ezsp: <=== [FRAME: ID=171:"SET_VALUE" Seq=12 Len=6]
[2024-05-10 13:04:15] debug: 	zh:ember: [EzspValueId] SET "MAXIMUM_OUTGOING_TRANSFER_SIZE" TO "82,0" with status=SUCCESS.
[2024-05-10 13:04:15] debug: 	zh:ember:ezsp: ===> [FRAME: ID=171:"SET_VALUE" Seq=13 Len=9]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=5 frmRx=5]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=6]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=6 frmNum=5] Added to rxQueue
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=6]
[2024-05-10 13:04:15] debug: 	zh:ember:ezsp: <=== [FRAME: ID=171:"SET_VALUE" Seq=13 Len=6]
[2024-05-10 13:04:15] debug: 	zh:ember: [EzspValueId] SET "TRANSIENT_DEVICE_TIMEOUT" TO "16,39" with status=SUCCESS.
[2024-05-10 13:04:15] debug: 	zh:ember:ezsp: ===> [FRAME: ID=21:"SET_MANUFACTURER_CODE" Seq=14 Len=7]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=6 frmRx=6]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=7]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=7 frmNum=6] Added to rxQueue
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=7]
[2024-05-10 13:04:15] debug: 	zh:ember:ezsp: <=== [FRAME: ID=21:"SET_MANUFACTURER_CODE" Seq=14 Len=5]
[2024-05-10 13:04:15] debug: 	zh:ember:ezsp: ===> [FRAME: ID=83:"SET_CONFIGURATION_VALUE" Seq=15 Len=8]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=7 frmRx=7]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=0]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=0 frmNum=7] Added to rxQueue
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=0]
[2024-05-10 13:04:15] debug: 	zh:ember:ezsp: <=== [FRAME: ID=83:"SET_CONFIGURATION_VALUE" Seq=15 Len=6]
[2024-05-10 13:04:15] debug: 	zh:ember: [EzspConfigId] SET "STACK_PROFILE" TO "2" with status=SUCCESS.
[2024-05-10 13:04:15] debug: 	zh:ember:ezsp: ===> [FRAME: ID=83:"SET_CONFIGURATION_VALUE" Seq=16 Len=8]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=0 frmRx=0]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=1]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=1 frmNum=0] Added to rxQueue
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=1]
[2024-05-10 13:04:15] debug: 	zh:ember:ezsp: <=== [FRAME: ID=83:"SET_CONFIGURATION_VALUE" Seq=16 Len=6]
[2024-05-10 13:04:15] debug: 	zh:ember: [EzspConfigId] SET "SECURITY_LEVEL" TO "5" with status=SUCCESS.
[2024-05-10 13:04:15] debug: 	zh:ember:ezsp: ===> [FRAME: ID=82:"GET_CONFIGURATION_VALUE" Seq=17 Len=6]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=1 frmRx=1]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=2]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=2 frmNum=1] Added to rxQueue
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=2]
[2024-05-10 13:04:15] debug: 	zh:ember:ezsp: <=== [FRAME: ID=82:"GET_CONFIGURATION_VALUE" Seq=17 Len=8]
[2024-05-10 13:04:15] debug: 	zh:ember:ezsp: ===> [FRAME: ID=83:"SET_CONFIGURATION_VALUE" Seq=18 Len=8]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=2 frmRx=2]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=3]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=3 frmNum=2] Added to rxQueue
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=3]
[2024-05-10 13:04:15] debug: 	zh:ember:ezsp: <=== [FRAME: ID=83:"SET_CONFIGURATION_VALUE" Seq=18 Len=6]
[2024-05-10 13:04:15] debug: 	zh:ember: [EzspConfigId] SET "BINDING_TABLE_SIZE" TO "32" with status=SUCCESS.
[2024-05-10 13:04:15] debug: 	zh:ember:ezsp: ===> [FRAME: ID=83:"SET_CONFIGURATION_VALUE" Seq=19 Len=8]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=3 frmRx=3]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=4]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=4 frmNum=3] Added to rxQueue
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=4]
[2024-05-10 13:04:15] debug: 	zh:ember:ezsp: <=== [FRAME: ID=83:"SET_CONFIGURATION_VALUE" Seq=19 Len=6]
[2024-05-10 13:04:15] debug: 	zh:ember: [EzspConfigId] SET "KEY_TABLE_SIZE" TO "0" with status=SUCCESS.
[2024-05-10 13:04:15] debug: 	zh:ember:ezsp: ===> [FRAME: ID=83:"SET_CONFIGURATION_VALUE" Seq=20 Len=8]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=4 frmRx=4]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=5]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=5 frmNum=4] Added to rxQueue
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=5]
[2024-05-10 13:04:15] debug: 	zh:ember:ezsp: <=== [FRAME: ID=83:"SET_CONFIGURATION_VALUE" Seq=20 Len=6]
[2024-05-10 13:04:15] debug: 	zh:ember: [EzspConfigId] SET "MAX_END_DEVICE_CHILDREN" TO "32" with status=SUCCESS.
[2024-05-10 13:04:15] debug: 	zh:ember:ezsp: ===> [FRAME: ID=83:"SET_CONFIGURATION_VALUE" Seq=21 Len=8]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=5 frmRx=5]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=6]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=6 frmNum=5] Added to rxQueue
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=6]
[2024-05-10 13:04:15] debug: 	zh:ember:ezsp: <=== [FRAME: ID=83:"SET_CONFIGURATION_VALUE" Seq=21 Len=6]
[2024-05-10 13:04:15] debug: 	zh:ember: [EzspConfigId] SET "APS_UNICAST_MESSAGE_COUNT" TO "32" with status=ERROR_OUT_OF_MEMORY.
[2024-05-10 13:04:15] warning: 	zh:ember: [EzspConfigId] Failed to SET "APS_UNICAST_MESSAGE_COUNT" TO "32" with status=ERROR_OUT_OF_MEMORY. Firmware value will be used instead.
[2024-05-10 13:04:15] debug: 	zh:ember:ezsp: ===> [FRAME: ID=83:"SET_CONFIGURATION_VALUE" Seq=22 Len=8]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=6 frmRx=6]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=7]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=7 frmNum=6] Added to rxQueue
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=7]
[2024-05-10 13:04:15] debug: 	zh:ember:ezsp: <=== [FRAME: ID=83:"SET_CONFIGURATION_VALUE" Seq=22 Len=6]
[2024-05-10 13:04:15] debug: 	zh:ember: [EzspConfigId] SET "BROADCAST_TABLE_SIZE" TO "15" with status=SUCCESS.
[2024-05-10 13:04:15] debug: 	zh:ember:ezsp: ===> [FRAME: ID=83:"SET_CONFIGURATION_VALUE" Seq=23 Len=8]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=7 frmRx=7]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=0]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=0 frmNum=7] Added to rxQueue
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=0]
[2024-05-10 13:04:15] debug: 	zh:ember:ezsp: <=== [FRAME: ID=83:"SET_CONFIGURATION_VALUE" Seq=23 Len=6]
[2024-05-10 13:04:15] debug: 	zh:ember: [EzspConfigId] SET "NEIGHBOR_TABLE_SIZE" TO "26" with status=SUCCESS.
[2024-05-10 13:04:15] debug: 	zh:ember:ezsp: ===> [FRAME: ID=83:"SET_CONFIGURATION_VALUE" Seq=24 Len=8]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=0 frmRx=0]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=1]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=1 frmNum=0] Added to rxQueue
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=1]
[2024-05-10 13:04:15] debug: 	zh:ember:ezsp: <=== [FRAME: ID=83:"SET_CONFIGURATION_VALUE" Seq=24 Len=6]
[2024-05-10 13:04:15] debug: 	zh:ember: [EzspConfigId] SET "END_DEVICE_POLL_TIMEOUT" TO "8" with status=SUCCESS.
[2024-05-10 13:04:15] debug: 	zh:ember:ezsp: ===> [FRAME: ID=83:"SET_CONFIGURATION_VALUE" Seq=25 Len=8]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=1 frmRx=1]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=2]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=2 frmNum=1] Added to rxQueue
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=2]
[2024-05-10 13:04:15] debug: 	zh:ember:ezsp: <=== [FRAME: ID=83:"SET_CONFIGURATION_VALUE" Seq=25 Len=6]
[2024-05-10 13:04:15] debug: 	zh:ember: [EzspConfigId] SET "TRANSIENT_KEY_TIMEOUT_S" TO "300" with status=SUCCESS.
[2024-05-10 13:04:15] debug: 	zh:ember:ezsp: ===> [FRAME: ID=83:"SET_CONFIGURATION_VALUE" Seq=26 Len=8]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=2 frmRx=2]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=3]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=3 frmNum=2] Added to rxQueue
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=3]
[2024-05-10 13:04:15] debug: 	zh:ember:ezsp: <=== [FRAME: ID=83:"SET_CONFIGURATION_VALUE" Seq=26 Len=6]
[2024-05-10 13:04:15] debug: 	zh:ember: [EzspConfigId] SET "RETRY_QUEUE_SIZE" TO "16" with status=SUCCESS.
[2024-05-10 13:04:15] debug: 	zh:ember:ezsp: ===> [FRAME: ID=83:"SET_CONFIGURATION_VALUE" Seq=27 Len=8]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=3 frmRx=3]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=4]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=4 frmNum=3] Added to rxQueue
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=4]
[2024-05-10 13:04:15] debug: 	zh:ember:ezsp: <=== [FRAME: ID=83:"SET_CONFIGURATION_VALUE" Seq=27 Len=6]
[2024-05-10 13:04:15] debug: 	zh:ember: [EzspConfigId] SET "SOURCE_ROUTE_TABLE_SIZE" TO "200" with status=SUCCESS.
[2024-05-10 13:04:15] debug: 	zh:ember:ezsp: ===> [FRAME: ID=83:"SET_CONFIGURATION_VALUE" Seq=28 Len=8]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=4 frmRx=4]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=5]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=5 frmNum=4] Added to rxQueue
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=5]
[2024-05-10 13:04:15] debug: 	zh:ember:ezsp: <=== [FRAME: ID=83:"SET_CONFIGURATION_VALUE" Seq=28 Len=6]
[2024-05-10 13:04:15] debug: 	zh:ember: [EzspConfigId] SET "MULTICAST_TABLE_SIZE" TO "16" with status=SUCCESS.
[2024-05-10 13:04:15] debug: 	zh:ember:ezsp: ===> [FRAME: ID=3:"GET_EXTENDED_VALUE" Seq=29 Len=10]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=5 frmRx=5]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=6]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=6 frmNum=5] Added to rxQueue
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=6]
[2024-05-10 13:04:15] debug: 	zh:ember:ezsp: <=== [FRAME: ID=3:"GET_EXTENDED_VALUE" Seq=29 Len=9]
[2024-05-10 13:04:15] debug: 	zh:ember:ezsp: ===> [FRAME: ID=2:"ADD_ENDPOINT" Seq=30 Len=63]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=6 frmRx=6]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=7]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=7 frmNum=6] Added to rxQueue
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=7]
[2024-05-10 13:04:15] debug: 	zh:ember:ezsp: <=== [FRAME: ID=2:"ADD_ENDPOINT" Seq=30 Len=6]
[2024-05-10 13:04:15] debug: 	zh:ember: Registered endpoint "1" with status=SUCCESS.
[2024-05-10 13:04:15] debug: 	zh:ember:ezsp: ===> [FRAME: ID=100:"SET_MULTICAST_TABLE_ENTRY" Seq=31 Len=10]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=7 frmRx=7]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=0]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=0 frmNum=7] Added to rxQueue
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=0]
[2024-05-10 13:04:15] debug: 	zh:ember:ezsp: <=== [FRAME: ID=100:"SET_MULTICAST_TABLE_ENTRY" Seq=31 Len=6]
[2024-05-10 13:04:15] debug: 	zh:ember: Registered multicast table entry: {"multicastId":0,"endpoint":1,"networkIndex":0}.
[2024-05-10 13:04:15] debug: 	zh:ember:ezsp: ===> [FRAME: ID=100:"SET_MULTICAST_TABLE_ENTRY" Seq=32 Len=10]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=0 frmRx=0]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=1]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=1 frmNum=0] Added to rxQueue
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=1]
[2024-05-10 13:04:15] debug: 	zh:ember:ezsp: <=== [FRAME: ID=100:"SET_MULTICAST_TABLE_ENTRY" Seq=32 Len=6]
[2024-05-10 13:04:15] debug: 	zh:ember: Registered multicast table entry: {"multicastId":901,"endpoint":1,"networkIndex":0}.
[2024-05-10 13:04:15] debug: 	zh:ember:ezsp: ===> [FRAME: ID=3:"GET_EXTENDED_VALUE" Seq=33 Len=10]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=1 frmRx=1]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=2]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=2 frmNum=1] Added to rxQueue
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=2]
[2024-05-10 13:04:15] debug: 	zh:ember:ezsp: <=== [FRAME: ID=3:"GET_EXTENDED_VALUE" Seq=33 Len=9]
[2024-05-10 13:04:15] debug: 	zh:ember:ezsp: ===> [FRAME: ID=2:"ADD_ENDPOINT" Seq=34 Len=17]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=2 frmRx=2]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=3]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=3 frmNum=2] Added to rxQueue
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=3]
[2024-05-10 13:04:15] debug: 	zh:ember:ezsp: <=== [FRAME: ID=2:"ADD_ENDPOINT" Seq=34 Len=6]
[2024-05-10 13:04:15] debug: 	zh:ember: Registered endpoint "242" with status=SUCCESS.
[2024-05-10 13:04:15] debug: 	zh:ember:ezsp: ===> [FRAME: ID=100:"SET_MULTICAST_TABLE_ENTRY" Seq=35 Len=10]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=3 frmRx=3]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=4]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=4 frmNum=3] Added to rxQueue
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=4]
[2024-05-10 13:04:15] debug: 	zh:ember:ezsp: <=== [FRAME: ID=100:"SET_MULTICAST_TABLE_ENTRY" Seq=35 Len=6]
[2024-05-10 13:04:15] debug: 	zh:ember: Registered multicast table entry: {"multicastId":2948,"endpoint":242,"networkIndex":0}.
[2024-05-10 13:04:15] debug: 	zh:ember:ezsp: ===> [FRAME: ID=85:"SET_POLICY" Seq=36 Len=7]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=4 frmRx=4]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=5]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=5 frmNum=4] Added to rxQueue
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=5]
[2024-05-10 13:04:15] debug: 	zh:ember:ezsp: <=== [FRAME: ID=85:"SET_POLICY" Seq=36 Len=6]
[2024-05-10 13:04:15] debug: 	zh:ember: [EzspPolicyId] SET "TC_KEY_REQUEST_POLICY" TO "81" with status=SUCCESS.
[2024-05-10 13:04:15] debug: 	zh:ember:ezsp: ===> [FRAME: ID=85:"SET_POLICY" Seq=37 Len=7]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=5 frmRx=5]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=6]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=6 frmNum=5] Added to rxQueue
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=6]
[2024-05-10 13:04:15] debug: 	zh:ember:ezsp: <=== [FRAME: ID=85:"SET_POLICY" Seq=37 Len=6]
[2024-05-10 13:04:15] debug: 	zh:ember: [EzspPolicyId] SET "APP_KEY_REQUEST_POLICY" TO "96" with status=SUCCESS.
[2024-05-10 13:04:15] debug: 	zh:ember:ezsp: ===> [FRAME: ID=85:"SET_POLICY" Seq=38 Len=7]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=6 frmRx=6]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=7]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=7 frmNum=6] Added to rxQueue
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=7]
[2024-05-10 13:04:15] debug: 	zh:ember:ezsp: <=== [FRAME: ID=85:"SET_POLICY" Seq=38 Len=6]
[2024-05-10 13:04:15] debug: 	zh:ember: [EzspPolicyId] SET "TRUST_CENTER_POLICY" TO "3" with status=SUCCESS.
[2024-05-10 13:04:15] debug: 	zh:ember:ezsp: ===> [FRAME: ID=23:"NETWORK_INIT" Seq=39 Len=7]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=7 frmRx=7]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=0]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=0 frmNum=7] Added to rxQueue
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=0]
[2024-05-10 13:04:15] debug: 	zh:ember:ezsp: <=== [FRAME: ID=23:"NETWORK_INIT" Seq=39 Len=6]
[2024-05-10 13:04:15] debug: 	zh:ember: [INIT TC] Network init status=SUCCESS.
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=0]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=0 frmNum=0] Added to rxQueue
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=1]
[2024-05-10 13:04:15] debug: 	zh:ember:ezsp: <=== [FRAME: ID=25:"STACK_STATUS_HANDLER" Seq=39 Len=6]
[2024-05-10 13:04:15] debug: 	zh:ember:ezsp: ezspStackStatusHandler(): callback called with: [status=NETWORK_UP]
[2024-05-10 13:04:15] info: 	zh:ember: [STACK STATUS] Network up.
[2024-05-10 13:04:15] debug: 	zh:ember:ezsp: ===> [FRAME: ID=40:"GET_NETWORK_PARAMETERS" Seq=40 Len=5]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=0 frmRx=1]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=1]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=1 frmNum=1] Added to rxQueue
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=2]
[2024-05-10 13:04:15] debug: 	zh:ember:ezsp: <=== [FRAME: ID=40:"GET_NETWORK_PARAMETERS" Seq=40 Len=27]
[2024-05-10 13:04:15] debug: 	zh:ember: [INIT TC] Current network config={"networkKeyDistribute":false,"networkKey":[10,50,250,203,143,196,207,222,241,222,211,80,171,24,131,183],"panID":20910,"extendedPanID":[xXx],"channelList":[15]}
[2024-05-10 13:04:15] debug: 	zh:ember: [INIT TC] Current NCP network: nodeType=COORDINATOR params={"extendedPanId":[xXx],"panId":20910,"radioTxPower":5,"radioChannel":15,"joinMethod":0,"nwkManagerId":0,"nwkUpdateId":0,"channels":134215680}
[2024-05-10 13:04:15] debug: 	zh:ember:ezsp: ===> [FRAME: ID=276:"EXPORT_KEY" Seq=41 Len=23]
[2024-05-10 13:04:15] debug: 	zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=1 frmRx=2]
[2024-05-10 13:04:16] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-05-10 13:04:16] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=2]
[2024-05-10 13:04:16] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=2 frmNum=2] Added to rxQueue
[2024-05-10 13:04:16] debug: 	zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=3]
[2024-05-10 13:04:16] debug: 	zh:ember:ezsp: <=== [FRAME: ID=276:"EXPORT_KEY" Seq=41 Len=25]
[2024-05-10 13:04:16] debug: 	zh:ember: [INIT TC] Current NCP network: networkKey=0a32facb8fc4cfdef1ded350ab1883b7
[2024-05-10 13:04:16] info: 	zh:ember: [INIT TC] NCP network matches config.
[2024-05-10 13:04:16] debug: 	zh:ember:ezsp: ===> [FRAME: ID=16:"SET_CONCENTRATOR" Seq=42 Len=15]
[2024-05-10 13:04:16] debug: 	zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=2 frmRx=3]
[2024-05-10 13:04:16] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-05-10 13:04:16] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=3]
[2024-05-10 13:04:16] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=3 frmNum=3] Added to rxQueue
[2024-05-10 13:04:16] debug: 	zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=4]
[2024-05-10 13:04:16] debug: 	zh:ember:ezsp: <=== [FRAME: ID=16:"SET_CONCENTRATOR" Seq=42 Len=6]
[2024-05-10 13:04:16] debug: 	zh:ember:ezsp: ===> [FRAME: ID=90:"SET_SOURCE_ROUTE_DISCOVERY_MODE" Seq=43 Len=6]
[2024-05-10 13:04:16] debug: 	zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=3 frmRx=4]
[2024-05-10 13:04:16] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-05-10 13:04:16] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=4]
[2024-05-10 13:04:16] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=4 frmNum=4] Added to rxQueue
[2024-05-10 13:04:16] debug: 	zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=5]
[2024-05-10 13:04:16] debug: 	zh:ember:ezsp: <=== [FRAME: ID=90:"SET_SOURCE_ROUTE_DISCOVERY_MODE" Seq=43 Len=9]
[2024-05-10 13:04:16] info: 	zh:ember: [CONCENTRATOR] Started source route discovery. 1247ms until next broadcast.
[2024-05-10 13:04:16] debug: 	zh:ember:ezsp: ===> [FRAME: ID=40:"GET_NETWORK_PARAMETERS" Seq=44 Len=5]
[2024-05-10 13:04:16] debug: 	zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=4 frmRx=5]
[2024-05-10 13:04:16] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-05-10 13:04:16] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=5]
[2024-05-10 13:04:16] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=5 frmNum=5] Added to rxQueue
[2024-05-10 13:04:16] debug: 	zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=6]
[2024-05-10 13:04:16] debug: 	zh:ember:ezsp: <=== [FRAME: ID=40:"GET_NETWORK_PARAMETERS" Seq=44 Len=27]
[2024-05-10 13:04:16] debug: 	zh:ember:ezsp: ===> [FRAME: ID=24:"NETWORK_STATE" Seq=45 Len=5]
[2024-05-10 13:04:16] debug: 	zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=5 frmRx=6]
[2024-05-10 13:04:16] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-05-10 13:04:16] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=6]
[2024-05-10 13:04:16] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=6 frmNum=6] Added to rxQueue
[2024-05-10 13:04:16] debug: 	zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=7]
[2024-05-10 13:04:16] debug: 	zh:ember:ezsp: <=== [FRAME: ID=24:"NETWORK_STATE" Seq=45 Len=6]
[2024-05-10 13:04:16] debug: 	zh:ember:ezsp: ===> [FRAME: ID=38:"GET_EUI64" Seq=46 Len=5]
[2024-05-10 13:04:16] debug: 	zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=6 frmRx=7]
[2024-05-10 13:04:16] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-05-10 13:04:16] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=7]
[2024-05-10 13:04:16] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=7 frmNum=7] Added to rxQueue
[2024-05-10 13:04:16] debug: 	zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=0]
[2024-05-10 13:04:16] debug: 	zh:ember:ezsp: <=== [FRAME: ID=38:"GET_EUI64" Seq=46 Len=13]
[2024-05-10 13:04:16] debug: 	zh:ember: [INIT] Network Ready! {"eui64":"0x040d84fffe2ba4ab","parameters":{"extendedPanId":[xXx],"panId":20910,"radioTxPower":5,"radioChannel":15,"joinMethod":0,"nwkManagerId":0,"nwkUpdateId":0,"channels":134215680},"status":2}
[2024-05-10 13:04:16] debug: 	zh:ember:queue: Dispatching started.
[2024-05-10 13:04:16] debug: 	zh:controller: Started with result 'resumed'
[2024-05-10 13:04:16] debug: 	zh:ember:queue: Status queue=0 priorityQueue=0.
[2024-05-10 13:04:16] debug: 	zh:controller: Injected database: true, adapter: true
[2024-05-10 13:04:16] debug: 	zh:ember:queue: Status queue=0 priorityQueue=0.
[2024-05-10 13:04:16] debug: 	zh:controller:device: Request Queue (0x040d84fffe2ba4ab): default expiration timeout set to 0
[2024-05-10 13:04:16] debug: 	zh:controller:device: Request Queue (0x18fc2600000e6f0d): default expiration timeout set to 1620000
[2024-05-10 13:04:16] debug: 	zh:controller:device: Request Queue (0x00158d00090d9814): default expiration timeout set to 0
[2024-05-10 13:04:16] debug: 	zh:controller:device: Request Queue (0x54ef4410004453bd): default expiration timeout set to 0
[2024-05-10 13:04:16] debug: 	zh:controller:device: Request Queue (0x0017880103f90135): default expiration timeout set to 0
[2024-05-10 13:04:16] debug: 	zh:controller:device: Request Queue (0x54ef44100070633b): default expiration timeout set to 0
[2024-05-10 13:04:16] debug: 	zh:controller:device: Request Queue (0x00158d00090d67b6): default expiration timeout set to 0
[2024-05-10 13:04:16] debug: 	zh:controller:device: Request Queue (0x0ceff6fffedbf989): default expiration timeout set to 3600000
[2024-05-10 13:04:16] debug: 	zh:controller:device: Request Queue (0x881a14fffef0a845): default expiration timeout set to 43200000
[2024-05-10 13:04:16] debug: 	zh:controller:device: Request Queue (0x0017880106401e6d): default expiration timeout set to 0
[2024-05-10 13:04:16] debug: 	zh:controller:device: Request Queue (0x001788010643c84b): default expiration timeout set to 0
[2024-05-10 13:04:16] debug: 	zh:controller:device: Request Queue (0x0017880109a2780e): default expiration timeout set to 0
[2024-05-10 13:04:16] debug: 	zh:controller:device: Request Queue (0x00178801011a6cbe): default expiration timeout set to 0
[2024-05-10 13:04:16] debug: 	zh:controller:device: Request Queue (0xa4c13800ab371bc0): default expiration timeout set to 0
[2024-05-10 13:04:16] debug: 	zh:controller:device: Request Queue (0xa4c13800ab391bfa): default expiration timeout set to 0
[2024-05-10 13:04:16] debug: 	zh:controller:device: Request Queue (0x00178801020a4f0c): default expiration timeout set to 0
[2024-05-10 13:04:16] debug: 	zh:controller:device: Request Queue (0x001788010207b558): default expiration timeout set to 0
[2024-05-10 13:04:16] debug: 	zh:controller:device: Request Queue (0x001788010207b4ff): default expiration timeout set to 0
[2024-05-10 13:04:16] debug: 	zh:controller:device: Request Queue (0x04cd15fffe6bdd8d): default expiration timeout set to 0
[2024-05-10 13:04:16] debug: 	zh:controller:device: Request Queue (0x00158d00090d6177): default expiration timeout set to 0
[2024-05-10 13:04:16] debug: 	zh:controller:device: Request Queue (0x54ef44100060bb86): default expiration timeout set to 0
[2024-05-10 13:04:16] debug: 	zh:controller:device: Request Queue (0x00158d000913d446): default expiration timeout set to 0
[2024-05-10 13:04:16] debug: 	zh:controller:device: Request Queue (0xf082c0fffeb1fc72): default expiration timeout set to 0
[2024-05-10 13:04:16] debug: 	zh:controller:device: Request Queue (0x00158d00090d5551): default expiration timeout set to 0
[2024-05-10 13:04:16] debug: 	zh:controller:device: Request Queue (0x54ef4410006d2f33): default expiration timeout set to 0
[2024-05-10 13:04:16] debug: 	zh:controller:device: Request Queue (0x54ef4410006ff583): default expiration timeout set to 0
[2024-05-10 13:04:16] debug: 	zh:controller:device: Request Queue (0x54ef441000851522): default expiration timeout set to 0
[2024-05-10 13:04:16] debug: 	zh:controller:device: Request Queue (0x38398ffffe0ab418): default expiration timeout set to 43200000
[2024-05-10 13:04:16] debug: 	zh:controller:device: Request Queue (0x00158d00094146d9): default expiration timeout set to 0
[2024-05-10 13:04:16] debug: 	zh:controller:device: Request Queue (0xa4c13877fabfb696): default expiration timeout set to 0
[2024-05-10 13:04:16] debug: 	zh:controller:device: Request Queue (0x54ef441000777164): default expiration timeout set to 0
[2024-05-10 13:04:16] debug: 	zh:controller:device: Request Queue (0x00158d0009173f7d): default expiration timeout set to 0
[2024-05-10 13:04:16] debug: 	zh:controller:device: Request Queue (0x00178801105f9808): default expiration timeout set to 0
[2024-05-10 13:04:16] debug: 	zh:controller:device: Request Queue (0x18fc2600000d4d05): default expiration timeout set to 1620000
[2024-05-10 13:04:16] debug: 	zh:controller:device: Request Queue (0x5cc7c1fffe3fcea4): default expiration timeout set to 43200000
[2024-05-10 13:04:16] debug: 	zh:controller:device: Request Queue (0x00158d0009d39bbf): default expiration timeout set to 0
[2024-05-10 13:04:16] debug: 	zh:controller:device: Request Queue (0x00158d000945c6d5): default expiration timeout set to 0
[2024-05-10 13:04:16] debug: 	zh:controller:device: Request Queue (0xa4c1385c0b457d5f): default expiration timeout set to 0
[2024-05-10 13:04:16] info: 	z2m: zigbee-herdsman started (resumed)
[2024-05-10 13:04:16] info: 	z2m: Coordinator firmware version: '{"meta":{"build":0,"ezsp":13,"major":7,"minor":4,"patch":2,"revision":"7.4.2 [GA]","special":0,"type":170},"type":"EmberZNet"}'
[2024-05-10 13:04:16] debug: 	z2m: Zigbee network parameters: {"channel":15,"extendedPanID":xXx,"panID":20910}
[2024-05-10 13:04:16] info: 	z2m: Currently 37 devices are joined:
[2024-05-10 13:04:16] info: 	z2m: Kinderzimmer Thermostat (0x18fc2600000e6f0d): BTH-RA - Bosch Radiator thermostat II (EndDevice)
[2024-05-10 13:04:16] info: 	z2m: Kinderzimmer Balkontür (0x00158d00090d9814): MCCGQ11LM - Aqara Door and window sensor (EndDevice)
[2024-05-10 13:04:16] info: 	z2m: Kinderzimmer Raumthermostat (0x54ef4410004453bd): VOCKQJK11LM - Aqara TVOC air quality monitor (EndDevice)
[2024-05-10 13:04:16] info: 	z2m: Kinderzimmer Fensterbank (0x0017880103f90135): 8718696695203 - Philips Hue white ambiance E14 (Router)
[2024-05-10 13:04:16] info: 	z2m: Bad Thermostat (0x54ef44100070633b): SRTS-A01 - Aqara Smart radiator thermostat E1 (EndDevice)
[2024-05-10 13:04:16] info: 	z2m: Bad Fenster (0x00158d00090d67b6): MCCGQ11LM - Aqara Door and window sensor (EndDevice)
[2024-05-10 13:04:16] info: 	z2m: Bad Raumthermostat (0x0ceff6fffedbf989): SNZB-02D - SONOFF Temperature and humidity sensor with screen (EndDevice)
[2024-05-10 13:04:16] info: 	z2m: Ikea Bewegungsmelder (0x881a14fffef0a845): E2134 - IKEA VALLHORN wireless motion sensor (EndDevice)
[2024-05-10 13:04:16] info: 	z2m: Wohnzimmer TV Links (0x0017880106401e6d): 915005733701 - Philips Hue White and color ambiance Play Lightbar (Router)
[2024-05-10 13:04:16] info: 	z2m: Wohnzimmer TV Rechts (0x001788010643c84b): 915005733701 - Philips Hue White and color ambiance Play Lightbar (Router)
[2024-05-10 13:04:16] info: 	z2m: Wohnzimmer Schrank (0x0017880109a2780e): 9290024406 - Philips Hue P45 light bulb (Router)
[2024-05-10 13:04:16] info: 	z2m: Wohnzimmer Bild (0x00178801011a6cbe): 915005106701 - Philips Hue white and color ambiance LightStrip plus (Router)
[2024-05-10 13:04:16] info: 	z2m: Schlafzimmer Marius (0xa4c13800ab371bc0): 50064 - Paulmann SmartHome led spot (Router)
[2024-05-10 13:04:16] info: 	z2m: Schlafzimmer Nathalie (0xa4c13800ab391bfa): 50064 - Paulmann SmartHome led spot (Router)
[2024-05-10 13:04:16] info: 	z2m: Esstisch Links (0x00178801020a4f0c): 9290012573A - Philips Hue white and color ambiance E26/E27/E14 (Router)
[2024-05-10 13:04:16] info: 	z2m: Esstisch Mitte (0x001788010207b558): 9290012573A - Philips Hue white and color ambiance E26/E27/E14 (Router)
[2024-05-10 13:04:16] info: 	z2m: Esstisch Rechts (0x001788010207b4ff): 9290012573A - Philips Hue white and color ambiance E26/E27/E14 (Router)
[2024-05-10 13:04:16] info: 	z2m: Schlafzimmer Luftreiniger (0x04cd15fffe6bdd8d): E2007 - IKEA STARKVIND air purifier (Router)
[2024-05-10 13:04:16] info: 	z2m: Wohnzimmer Balkontür (0x00158d00090d6177): MCCGQ11LM - Aqara Door and window sensor (EndDevice)
[2024-05-10 13:04:16] info: 	z2m: Wohnzimmer Thermostat (0x54ef44100060bb86): SRTS-A01 - Aqara Smart radiator thermostat E1 (EndDevice)
[2024-05-10 13:04:16] info: 	z2m: Balkon Straße Wetter (0x00158d000913d446): WSDCGQ11LM - Aqara Temperature and humidity sensor (EndDevice)
[2024-05-10 13:04:16] info: 	z2m: Flur Schalter (0xf082c0fffeb1fc72): TS0044 - TuYa Wireless switch with 4 buttons (EndDevice)
[2024-05-10 13:04:16] info: 	z2m: Schlafzimmer Fenster (0x00158d00090d5551): MCCGQ11LM - Aqara Door and window sensor (EndDevice)
[2024-05-10 13:04:16] info: 	z2m: Schlafzimmer Raumthermostat (0x54ef4410006d2f33): VOCKQJK11LM - Aqara TVOC air quality monitor (EndDevice)
[2024-05-10 13:04:16] info: 	z2m: Schlafzimmer Thermostat (0x54ef4410006ff583): SRTS-A01 - Aqara Smart radiator thermostat E1 (EndDevice)
[2024-05-10 13:04:16] info: 	z2m: Wohnzimmer Raumthermostat (0x54ef441000851522): VOCKQJK11LM - Aqara TVOC air quality monitor (EndDevice)
[2024-05-10 13:04:16] info: 	z2m: Bad Wassersensor (0x38398ffffe0ab418): E2202 - IKEA BADRING water leakage sensor (EndDevice)
[2024-05-10 13:04:16] info: 	z2m: Balkon Wetter (0x00158d00094146d9): WSDCGQ11LM - Aqara Temperature and humidity sensor (EndDevice)
[2024-05-10 13:04:16] info: 	z2m: Küche Kühlschrank (0xa4c13877fabfb696): HG08673 - Lidl Silvercrest smart plug with power monitoring (EU, FR) (Router)
[2024-05-10 13:04:16] info: 	z2m: Kinderzimmer Bewegungsmelder (0x54ef441000777164): RTCGQ14LM - Aqara Motion sensor P1 (EndDevice)
[2024-05-10 13:04:16] info: 	z2m: Küche Wassersensor (0x00158d0009173f7d): SJCGQ11LM - Aqara Water leak sensor (EndDevice)
[2024-05-10 13:04:16] info: 	z2m: Esszimmer Schalter (0x00178801105f9808): 324131092621 - Philips Hue dimmer switch (EndDevice)
[2024-05-10 13:04:16] info: 	z2m: Esszimmer Thermostat (0x18fc2600000d4d05): BTH-RA - Bosch Radiator thermostat II (EndDevice)
[2024-05-10 13:04:16] info: 	z2m: Ikea Schalter (0x5cc7c1fffe3fcea4): E2213 - IKEA SOMRIG shortcut button (EndDevice)
[2024-05-10 13:04:16] info: 	z2m: Balkon Regensensor (0x00158d0009d39bbf): MCCGQ11LM - Aqara Door and window sensor (EndDevice)
[2024-05-10 13:04:16] info: 	z2m: Wohnzimmer Fenster (0x00158d000945c6d5): MCCGQ11LM - Aqara Door and window sensor (EndDevice)
[2024-05-10 13:04:16] info: 	z2m: Flur - Sideboard (0xa4c1385c0b457d5f): TS0501B - TuYa Zigbee light (Router)
[2024-05-10 13:04:16] info: 	z2m: Zigbee: disabling joining new devices.
[2024-05-10 13:04:16] debug: 	zh:controller: Disable joining
[2024-05-10 13:04:16] debug: 	zh:ember:queue: Status queue=0 priorityQueue=0.
[2024-05-10 13:04:16] debug: 	zh:ember: ~~~> [ZCL BROADCAST apsFrame={"profileId":41440,"clusterId":33,"sourceEndpoint":242,"destinationEndpoint":242,"options":4416,"groupId":65533,"sequence":0} header={"frameControl":{"reservedBits":0,"frameType":1,"direction":1,"disableDefaultResponse":true,"manufacturerSpecific":false},"manufacturerCode":null,"transactionSequenceNumber":2,"commandIdentifier":2}]
[2024-05-10 13:04:16] debug: 	zh:ember:ezsp: ===> [FRAME: ID=54:"SEND_BROADCAST" Seq=47 Len=27]
[2024-05-10 13:04:16] debug: 	zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=7 frmRx=0]
[2024-05-10 13:04:16] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-05-10 13:04:16] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=0]
[2024-05-10 13:04:16] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=0 frmNum=0] Added to rxQueue
[2024-05-10 13:04:16] debug: 	zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=1]
[2024-05-10 13:04:16] debug: 	zh:ember:ezsp: <=== [FRAME: ID=54:"SEND_BROADCAST" Seq=47 Len=7]
[2024-05-10 13:04:16] debug: 	zh:ember:ezsp: ~~~> [SENT type=BROADCAST apsSequence=238 messageTag=1 status=SUCCESS]
[2024-05-10 13:04:16] debug: 	zh:ember:queue: Status queue=0 priorityQueue=0.
[2024-05-10 13:04:16] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-05-10 13:04:16] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=0]
[2024-05-10 13:04:16] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=0 frmNum=1] Added to rxQueue
[2024-05-10 13:04:16] debug: 	zh:ember:ezsp: ===> [FRAME: ID=107:"CLEAR_TRANSIENT_LINK_KEYS" Seq=48 Len=5]
[2024-05-10 13:04:16] debug: 	zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=2]
[2024-05-10 13:04:16] debug: 	zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=0 frmRx=2]
[2024-05-10 13:04:16] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-05-10 13:04:16] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=1]
[2024-05-10 13:04:16] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=1 frmNum=2] Added to rxQueue
[2024-05-10 13:04:16] debug: 	zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=3]
[2024-05-10 13:04:16] debug: 	zh:ember:ezsp: Skipping async callback while waiting for response to command.
[2024-05-10 13:04:16] debug: 	zh:ember:ezsp: <=== [FRAME: ID=107:"CLEAR_TRANSIENT_LINK_KEYS" Seq=48 Len=5]
[2024-05-10 13:04:16] debug: 	zh:ember:ezsp: ===> [FRAME: ID=85:"SET_POLICY" Seq=49 Len=7]
[2024-05-10 13:04:16] debug: 	zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=1 frmRx=3]
[2024-05-10 13:04:16] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-05-10 13:04:16] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=2]
[2024-05-10 13:04:16] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=2 frmNum=3] Added to rxQueue
[2024-05-10 13:04:16] debug: 	zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=4]
[2024-05-10 13:04:16] debug: 	zh:ember:ezsp: Skipping async callback while waiting for response to command.
[2024-05-10 13:04:16] debug: 	zh:ember:ezsp: <=== [FRAME: ID=85:"SET_POLICY" Seq=49 Len=6]
[2024-05-10 13:04:16] debug: 	zh:ember: [EzspPolicyId] SET "TRUST_CENTER_POLICY" TO "2" with status=SUCCESS.
[2024-05-10 13:04:16] debug: 	zh:ember:ezsp: ===> [FRAME: ID=34:"PERMIT_JOINING" Seq=50 Len=6]
[2024-05-10 13:04:16] debug: 	zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=2 frmRx=4]
[2024-05-10 13:04:16] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-05-10 13:04:16] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=3]
[2024-05-10 13:04:16] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=3 frmNum=4] Added to rxQueue
[2024-05-10 13:04:16] debug: 	zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=5]
[2024-05-10 13:04:16] debug: 	zh:ember:ezsp: Skipping async callback while waiting for response to command.
[2024-05-10 13:04:16] debug: 	zh:ember:ezsp: <=== [FRAME: ID=34:"PERMIT_JOINING" Seq=50 Len=6]
[2024-05-10 13:04:16] debug: 	zh:ember: Permit joining for 0 sec. status=0
[2024-05-10 13:04:16] debug: 	zh:ember: ~~~> [ZDO PERMIT_JOINING_REQUEST target=65532 duration=0 authentication=1]
[2024-05-10 13:04:16] debug: 	zh:ember: ~~~> [ZDO BROADCAST apsFrame={"profileId":0,"clusterId":54,"sourceEndpoint":0,"destinationEndpoint":0,"options":4416,"groupId":0,"sequence":0} messageTag=1]
[2024-05-10 13:04:16] debug: 	zh:ember:ezsp: ===> [FRAME: ID=54:"SEND_BROADCAST" Seq=51 Len=24]
[2024-05-10 13:04:16] debug: 	zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=3 frmRx=5]
[2024-05-10 13:04:16] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-05-10 13:04:16] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=4]
[2024-05-10 13:04:16] debug: 	zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=4 frmNum=5] Added to rxQueue
[2024-05-10 13:04:16] debug: 	zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=6]
[2024-05-10 13:04:16] debug: 	zh:ember:ezsp: Skipping async callback while waiting for response to command.
[2024-05-10 13:04:16] debug: 	zh:ember:ezsp: <=== [FRAME: ID=54:"SEND_BROADCAST" Seq=51 Len=7]
[2024-05-10 13:04:16] debug: 	zh:ember: ~~~> [SENT ZDO type=BROADCAST apsFrame={"profileId":0,"clusterId":54,"sourceEndpoint":0,"destinationEndpoint":0,"options":4416,"groupId":0,"sequence":239} messageTag=1 status=SUCCESS]
[2024-05-10 13:04:16] info: 	z2m: Connecting to MQTT server at mqtt://core-mosquitto:1883
[2024-05-10 13:04:16] debug: 	z2m: Using MQTT login with username: addons
[2024-05-10 13:04:16] debug: 	zh:ember:ezsp: <=== [FRAME: ID=69:"INCOMING_MESSAGE_HANDLER" Seq=47 Len=30]
[2024-05-10 13:04:16] debug: 	zh:ember:ezsp: ezspIncomingMessageHandler(): callback called with: [type=BROADCAST_LOOPBACK], [apsFrame={"profileId":41440,"clusterId":33,"sourceEndpoint":242,"destinationEndpoint":242,"options":256,"groupId":0,"sequence":238}], [lastHopLqi=255], [lastHopRssi=0], [sender=0], [bindingIndex=255], [addressIndex=255], [messageContents=1902020a0000]
[2024-05-10 13:04:16] info: 	z2m: Connected to MQTT server
[2024-05-10 13:04:16] debug: 	z2m: MQTT publish: topic 'zigbee2mqtt/bridge/state', payload '{"state":"online"}'

@Nerivec
Copy link
Collaborator

Nerivec commented May 10, 2024

Thanks, that's just what I need. Appreciated!
The hardware flow control firmware has a messier start than the software flow control one at the moment, so the errors at the top are expected; I wanted to make sure that with the new fixes it started nonetheless. You can revert to no hardware flow control if you want to get rid of those startup errors entirely 😉

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
ember Issues related to ember driver problem Something isn't working
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
4 participants
@Koenkk @Jopinder @Nerivec @Mar1usW3