Finalisation config Z2M sous proxmox

[bemo47]

Bonjour,

J’ai migré mon HA sous proxmox sur un minipc, la migration s’est bien passé, depuis une VM sous virtualbox vers Proxmox.

Maintenant je veux activer MQTT et Z2M. j’ai choisi l’option de les mettre dans 2 vm proxmox séparées.

J’ai installé MQTT, puis Z2M et j’ai pu activer Z2M et obtenir la web interface de Z2M mais avec une config vide, ce qui valide au moins le fonctionnement des 2 vm proxmox, et du dongle zigbee, c’est le Sonoff USB3 Dongle Plus V2 qui est maintenant sous ember au lieu de EZSP. Et qui fonctionnait dans la config précédente.

Précision : dans la config précédente MQTT était dans HA, et Z2M était sur un Pi4 avec le dongle.

Ensuite j’ai modifié le yaml de Z2M pour tenter de réintégrer la confil zigbee précédente, j’ai donc récupéré le yaml sur la carte SD qui était dans le Pi4 et je l’ai mise à la place du YAML de Z2M, en gardant les paramètres IP, user, pwd etc de MQTT qui n’est plus dans HA maintenant.

Mais lorsque je veux démarrer Z2M la config zigbee n’est pas reconnue, l’interface web de Z2M reste vide, ci-dessous la log du démarrage de Z2M suivi du yaml :

root@zigbee2mqtt:/opt/zigbee2mqtt# cd /opt/zigbee2mqtt && npm start

> zigbee2mqtt@1.40.2 start
> node index.js

Starting Zigbee2MQTT without watchdog.
[2024-10-20 20:04:44] info:     z2m: Logging to console, file (filename: log.log)
[2024-10-20 20:04:44] debug:    z2m: Loaded state from file /opt/zigbee2mqtt/data/state.json
[2024-10-20 20:04:44] info:     z2m: Starting Zigbee2MQTT version 1.40.2 (commit #e06848d)
[2024-10-20 20:04:44] debug:    z2m: sd-notify loaded
[2024-10-20 20:04:44] info:     z2m: Starting zigbee-herdsman (2.1.3)
[2024-10-20 20:04:44] debug:    z2m: Using zigbee-herdsman with settings: '"{\"network\":{\"panID\":22371,\"extendedPanID\":[81,25,81,199,220,210,40,221],\"channelList\":[25],\"networkKey\":\"HIDDEN\"},\"databasePath\":\"/opt/zigbee2mqtt/data/database.db\",\"databaseBackupPath\":\"/opt/zigbee2mqtt/data/database.db.backup\",\"backupPath\":\"/opt/zigbee2mqtt/data/coordinator_backup.json\",\"serialPort\":{\"path\":\"/dev/serial/by-id/usb-ITEAD_SONOFF_Zigbee_3.0_USB_Dongle_Plus_V2_20231102142912-if00\",\"adapter\":\"ember\"},\"adapter\":{\"disableLED\":false}}"'
[2024-10-20 20:04:44] info:     zh:ember: Using default stack config.
[2024-10-20 20:04:44] debug:    zh:controller: Starting with options '{"network":{"networkKeyDistribute":false,"networkKey":"HIDDEN","panID":22371,"extendedPanID":[81,25,81,199,220,210,40,221],"channelList":[25]},"serialPort":{"path":"/dev/serial/by-id/usb-ITEAD_SONOFF_Zigbee_3.0_USB_Dongle_Plus_V2_20231102142912-if00","adapter":"ember"},"adapter":{"disableLED":false},"databasePath":"/opt/zigbee2mqtt/data/database.db","databaseBackupPath":"/opt/zigbee2mqtt/data/database.db.backup","backupPath":"/opt/zigbee2mqtt/data/coordinator_backup.json"}'
[2024-10-20 20:04:44] info:     zh:ember: ======== Ember Adapter Starting ========
[2024-10-20 20:04:44] info:     zh:ember:ezsp: ======== EZSP starting ========
[2024-10-20 20:04:44] info:     zh:ember:uart:ash: ======== ASH Adapter reset ========
[2024-10-20 20:04:44] info:     zh:ember:uart:ash: RTS/CTS config is off, enabling software flow control.
[2024-10-20 20:04:44] debug:    zh:ember:uart:ash: Opening serial port with {"path":"/dev/serial/by-id/usb-ITEAD_SONOFF_Zigbee_3.0_USB_Dongle_Plus_V2_20231102142912-if00","baudRate":115200,"rtscts":false,"autoOpen":false,"parity":"none","stopBits":1,"xon":true,"xoff":true}
[2024-10-20 20:04:44] info:     zh:ember:uart:ash: Serial port opened
[2024-10-20 20:04:44] info:     zh:ember:uart:ash: ======== ASH starting ========
[2024-10-20 20:04:44] error:    zh:ember:uart:ash: Received frame with CRC error
[2024-10-20 20:04:44] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-10-20 20:04:44] debug:    zh:ember:uart:ash: <--- [FRAME type=ERROR]
[2024-10-20 20:04:44] error:    zh:ember:uart:ash: Received ERROR from adapter while connecting, with code=ERROR_EXCEEDED_MAXIMUM_ACK_TIMEOUT_COUNT.
[2024-10-20 20:04:44] debug:    zh:ember:uart:ash: ---> [FRAME type=RST]
[2024-10-20 20:04:44] debug:    zh:ember:uart:ash: Waiting for RSTACK... 0/2500
[2024-10-20 20:04:44] debug:    zh:ember:uart:ash: Waiting for RSTACK... 100/2500
[2024-10-20 20:04:44] debug:    zh:ember:uart:ash: Waiting for RSTACK... 200/2500
[2024-10-20 20:04:44] debug:    zh:ember:uart:ash: Waiting for RSTACK... 300/2500
[2024-10-20 20:04:44] debug:    zh:ember:uart:ash: Waiting for RSTACK... 400/2500
[2024-10-20 20:04:44] debug:    zh:ember:uart:ash: Waiting for RSTACK... 500/2500
[2024-10-20 20:04:44] debug:    zh:ember:uart:ash: Waiting for RSTACK... 600/2500
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: Waiting for RSTACK... 700/2500
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: Waiting for RSTACK... 800/2500
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: Waiting for RSTACK... 900/2500
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: Waiting for RSTACK... 1000/2500
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=RSTACK]
[2024-10-20 20:04:45] info:     zh:ember:uart:ash: ======== ASH connected ========
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=0](ackRx=0)
[2024-10-20 20:04:45] info:     zh:ember:uart:ash: ======== ASH started ========
[2024-10-20 20:04:45] info:     zh:ember:ezsp: ======== EZSP started ========
[2024-10-20 20:04:45] debug:    zh:ember:ezsp: ===> [FRAME: ID=0:"VERSION" Seq=0 Len=4]
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=0 frmRx=0](ackRx=0)
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=1](ackRx=0 frmTx=1)
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=1 frmNum=0](frmRx=0) Added to rxQueue
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=1](ackRx=1)
[2024-10-20 20:04:45] debug:    zh:ember:ezsp: <=== [FRAME: ID=0:"VERSION" Seq=0 Len=7]
[2024-10-20 20:04:45] debug:    zh:ember:ezsp: ===> [FRAME: ID=0:"VERSION" Seq=1 Len=6]
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=1 frmRx=1](ackRx=1)
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=2](ackRx=1 frmTx=2)
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=2 frmNum=1](frmRx=1) Added to rxQueue
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=2](ackRx=2)
[2024-10-20 20:04:45] debug:    zh:ember:ezsp: <=== [FRAME: ID=0:"VERSION" Seq=1 Len=9]
[2024-10-20 20:04:45] info:     zh:ember: Adapter EZSP protocol version (13) lower than Host. Switched.
[2024-10-20 20:04:45] debug:    zh:ember: Adapter info: EZSPVersion=13 StackType=2 StackVersion=29744
[2024-10-20 20:04:45] debug:    zh:ember:ezsp: ===> [FRAME: ID=170:"GET_VALUE" Seq=2 Len=6]
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=2 frmRx=2](ackRx=2)
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=3](ackRx=2 frmTx=3)
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=3 frmNum=2](frmRx=2) Added to rxQueue
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=3](ackRx=3)
[2024-10-20 20:04:45] debug:    zh:ember:ezsp: <=== [FRAME: ID=170:"GET_VALUE" Seq=2 Len=14]
[2024-10-20 20:04:45] info:     zh:ember: Adapter version info: {"ezsp":13,"revision":"7.4.3 [GA]","build":0,"major":7,"minor":4,"patch":3,"special":0,"type":170}
[2024-10-20 20:04:45] debug:    zh:ember:ezsp: ===> [FRAME: ID=83:"SET_CONFIGURATION_VALUE" Seq=3 Len=8]
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=3 frmRx=3](ackRx=3)
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=4](ackRx=3 frmTx=4)
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=4 frmNum=3](frmRx=3) Added to rxQueue
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=4](ackRx=4)
[2024-10-20 20:04:45] debug:    zh:ember:ezsp: <=== [FRAME: ID=83:"SET_CONFIGURATION_VALUE" Seq=3 Len=6]
[2024-10-20 20:04:45] debug:    zh:ember: [EzspConfigId] SET 'TRUST_CENTER_ADDRESS_CACHE_SIZE' TO '2' with status=OK.
[2024-10-20 20:04:45] debug:    zh:ember:ezsp: ===> [FRAME: ID=83:"SET_CONFIGURATION_VALUE" Seq=4 Len=8]
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=4 frmRx=4](ackRx=4)
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=5](ackRx=4 frmTx=5)
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=5 frmNum=4](frmRx=4) Added to rxQueue
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=5](ackRx=5)
[2024-10-20 20:04:45] debug:    zh:ember:ezsp: <=== [FRAME: ID=83:"SET_CONFIGURATION_VALUE" Seq=4 Len=6]
[2024-10-20 20:04:45] debug:    zh:ember: [EzspConfigId] SET 'INDIRECT_TRANSMISSION_TIMEOUT' TO '7680' with status=OK.
[2024-10-20 20:04:45] debug:    zh:ember:ezsp: ===> [FRAME: ID=83:"SET_CONFIGURATION_VALUE" Seq=5 Len=8]
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=5 frmRx=5](ackRx=5)
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=6](ackRx=5 frmTx=6)
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=6 frmNum=5](frmRx=5) Added to rxQueue
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=6](ackRx=6)
[2024-10-20 20:04:45] debug:    zh:ember:ezsp: <=== [FRAME: ID=83:"SET_CONFIGURATION_VALUE" Seq=5 Len=6]
[2024-10-20 20:04:45] debug:    zh:ember: [EzspConfigId] SET 'MAX_HOPS' TO '30' with status=OK.
[2024-10-20 20:04:45] debug:    zh:ember:ezsp: ===> [FRAME: ID=83:"SET_CONFIGURATION_VALUE" Seq=6 Len=8]
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=6 frmRx=6](ackRx=6)
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=7](ackRx=6 frmTx=7)
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=7 frmNum=6](frmRx=6) Added to rxQueue
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=7](ackRx=7)
[2024-10-20 20:04:45] debug:    zh:ember:ezsp: <=== [FRAME: ID=83:"SET_CONFIGURATION_VALUE" Seq=6 Len=6]
[2024-10-20 20:04:45] debug:    zh:ember: [EzspConfigId] SET 'SUPPORTED_NETWORKS' TO '1' with status=OK.
[2024-10-20 20:04:45] debug:    zh:ember:ezsp: ===> [FRAME: ID=85:"SET_POLICY" Seq=7 Len=7]
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=7 frmRx=7](ackRx=7)
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=0](ackRx=7 frmTx=0)
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=0 frmNum=7](frmRx=7) Added to rxQueue
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=0](ackRx=0)
[2024-10-20 20:04:45] debug:    zh:ember:ezsp: <=== [FRAME: ID=85:"SET_POLICY" Seq=7 Len=6]
[2024-10-20 20:04:45] debug:    zh:ember: [EzspPolicyId] SET 'BINDING_MODIFICATION_POLICY' TO '18' with status=OK.
[2024-10-20 20:04:45] debug:    zh:ember:ezsp: ===> [FRAME: ID=85:"SET_POLICY" Seq=8 Len=7]
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=0 frmRx=0](ackRx=0)
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=1](ackRx=0 frmTx=1)
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=1 frmNum=0](frmRx=0) Added to rxQueue
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=1](ackRx=1)
[2024-10-20 20:04:45] debug:    zh:ember:ezsp: <=== [FRAME: ID=85:"SET_POLICY" Seq=8 Len=6]
[2024-10-20 20:04:45] debug:    zh:ember: [EzspPolicyId] SET 'MESSAGE_CONTENTS_IN_CALLBACK_POLICY' TO '64' with status=OK.
[2024-10-20 20:04:45] debug:    zh:ember:ezsp: ===> [FRAME: ID=171:"SET_VALUE" Seq=9 Len=9]
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=1 frmRx=1](ackRx=1)
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=2](ackRx=1 frmTx=2)
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=2 frmNum=1](frmRx=1) Added to rxQueue
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=2](ackRx=2)
[2024-10-20 20:04:45] debug:    zh:ember:ezsp: <=== [FRAME: ID=171:"SET_VALUE" Seq=9 Len=6]
[2024-10-20 20:04:45] debug:    zh:ember: [EzspValueId] SET 'TRANSIENT_DEVICE_TIMEOUT' TO '16,39' with status=OK.
[2024-10-20 20:04:45] debug:    zh:ember:ezsp: ===> [FRAME: ID=21:"SET_MANUFACTURER_CODE" Seq=10 Len=7]
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=2 frmRx=2](ackRx=2)
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=3](ackRx=2 frmTx=3)
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=3 frmNum=2](frmRx=2) Added to rxQueue
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=3](ackRx=3)
[2024-10-20 20:04:45] debug:    zh:ember:ezsp: <=== [FRAME: ID=21:"SET_MANUFACTURER_CODE" Seq=10 Len=5]
[2024-10-20 20:04:45] debug:    zh:ember:ezsp: ===> [FRAME: ID=83:"SET_CONFIGURATION_VALUE" Seq=11 Len=8]
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=3 frmRx=3](ackRx=3)
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=4](ackRx=3 frmTx=4)
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=4 frmNum=3](frmRx=3) Added to rxQueue
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=4](ackRx=4)
[2024-10-20 20:04:45] debug:    zh:ember:ezsp: <=== [FRAME: ID=83:"SET_CONFIGURATION_VALUE" Seq=11 Len=6]
[2024-10-20 20:04:45] debug:    zh:ember: [EzspConfigId] SET 'STACK_PROFILE' TO '2' with status=OK.
[2024-10-20 20:04:45] debug:    zh:ember:ezsp: ===> [FRAME: ID=83:"SET_CONFIGURATION_VALUE" Seq=12 Len=8]
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=4 frmRx=4](ackRx=4)
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=5](ackRx=4 frmTx=5)
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=5 frmNum=4](frmRx=4) Added to rxQueue
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=5](ackRx=5)
[2024-10-20 20:04:45] debug:    zh:ember:ezsp: <=== [FRAME: ID=83:"SET_CONFIGURATION_VALUE" Seq=12 Len=6]
[2024-10-20 20:04:45] debug:    zh:ember: [EzspConfigId] SET 'SECURITY_LEVEL' TO '5' with status=OK.
[2024-10-20 20:04:45] debug:    zh:ember:ezsp: ===> [FRAME: ID=83:"SET_CONFIGURATION_VALUE" Seq=13 Len=8]
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=5 frmRx=5](ackRx=5)
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=6](ackRx=5 frmTx=6)
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=6 frmNum=5](frmRx=5) Added to rxQueue
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=6](ackRx=6)
[2024-10-20 20:04:45] debug:    zh:ember:ezsp: <=== [FRAME: ID=83:"SET_CONFIGURATION_VALUE" Seq=13 Len=6]
[2024-10-20 20:04:45] debug:    zh:ember: [EzspConfigId] SET 'MAX_END_DEVICE_CHILDREN' TO '32' with status=OK.
[2024-10-20 20:04:45] debug:    zh:ember:ezsp: ===> [FRAME: ID=83:"SET_CONFIGURATION_VALUE" Seq=14 Len=8]
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=6 frmRx=6](ackRx=6)
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=7](ackRx=6 frmTx=7)
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=7 frmNum=6](frmRx=6) Added to rxQueue
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=7](ackRx=7)
[2024-10-20 20:04:45] debug:    zh:ember:ezsp: <=== [FRAME: ID=83:"SET_CONFIGURATION_VALUE" Seq=14 Len=6]
[2024-10-20 20:04:45] debug:    zh:ember: [EzspConfigId] SET 'END_DEVICE_POLL_TIMEOUT' TO '8' with status=OK.
[2024-10-20 20:04:45] debug:    zh:ember:ezsp: ===> [FRAME: ID=83:"SET_CONFIGURATION_VALUE" Seq=15 Len=8]
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=7 frmRx=7](ackRx=7)
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=0](ackRx=7 frmTx=0)
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=0 frmNum=7](frmRx=7) Added to rxQueue
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=0](ackRx=0)
[2024-10-20 20:04:45] debug:    zh:ember:ezsp: <=== [FRAME: ID=83:"SET_CONFIGURATION_VALUE" Seq=15 Len=6]
[2024-10-20 20:04:45] debug:    zh:ember: [EzspConfigId] SET 'TRANSIENT_KEY_TIMEOUT_S' TO '300' with status=OK.
[2024-10-20 20:04:45] debug:    zh:ember:ezsp: ===> [FRAME: ID=171:"SET_VALUE" Seq=16 Len=8]
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=0 frmRx=0](ackRx=0)
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=1](ackRx=0 frmTx=1)
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=1 frmNum=0](frmRx=0) Added to rxQueue
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=1](ackRx=1)
[2024-10-20 20:04:45] debug:    zh:ember:ezsp: <=== [FRAME: ID=171:"SET_VALUE" Seq=16 Len=6]
[2024-10-20 20:04:45] debug:    zh:ember: [EzspValueId] SET 'CCA_THRESHOLD' TO '0' with status=OK.
[2024-10-20 20:04:45] debug:    zh:ember:ezsp: ===> [FRAME: ID=3:"GET_EXTENDED_VALUE" Seq=17 Len=10]
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=1 frmRx=1](ackRx=1)
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=2](ackRx=1 frmTx=2)
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=2 frmNum=1](frmRx=1) Added to rxQueue
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=2](ackRx=2)
[2024-10-20 20:04:45] debug:    zh:ember:ezsp: <=== [FRAME: ID=3:"GET_EXTENDED_VALUE" Seq=17 Len=9]
[2024-10-20 20:04:45] debug:    zh:ember:ezsp: ===> [FRAME: ID=2:"ADD_ENDPOINT" Seq=18 Len=63]
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=2 frmRx=2](ackRx=2)
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=3](ackRx=2 frmTx=3)
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=3 frmNum=2](frmRx=2) Added to rxQueue
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=3](ackRx=3)
[2024-10-20 20:04:45] debug:    zh:ember:ezsp: <=== [FRAME: ID=2:"ADD_ENDPOINT" Seq=18 Len=6]
[2024-10-20 20:04:45] debug:    zh:ember: Registered endpoint '1'.
[2024-10-20 20:04:45] debug:    zh:ember:ezsp: ===> [FRAME: ID=100:"SET_MULTICAST_TABLE_ENTRY" Seq=19 Len=10]
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=3 frmRx=3](ackRx=3)
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=4](ackRx=3 frmTx=4)
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=4 frmNum=3](frmRx=3) Added to rxQueue
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=4](ackRx=4)
[2024-10-20 20:04:45] debug:    zh:ember:ezsp: <=== [FRAME: ID=100:"SET_MULTICAST_TABLE_ENTRY" Seq=19 Len=6]
[2024-10-20 20:04:45] debug:    zh:ember: Registered multicast table entry (0): {"multicastId":0,"endpoint":1,"networkIndex":0}.
[2024-10-20 20:04:45] debug:    zh:ember:ezsp: ===> [FRAME: ID=100:"SET_MULTICAST_TABLE_ENTRY" Seq=20 Len=10]
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=4 frmRx=4](ackRx=4)
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=5](ackRx=4 frmTx=5)
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=5 frmNum=4](frmRx=4) Added to rxQueue
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=5](ackRx=5)
[2024-10-20 20:04:45] debug:    zh:ember:ezsp: <=== [FRAME: ID=100:"SET_MULTICAST_TABLE_ENTRY" Seq=20 Len=6]
[2024-10-20 20:04:45] debug:    zh:ember: Registered multicast table entry (1): {"multicastId":901,"endpoint":1,"networkIndex":0}.
[2024-10-20 20:04:45] debug:    zh:ember:ezsp: ===> [FRAME: ID=3:"GET_EXTENDED_VALUE" Seq=21 Len=10]
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=5 frmRx=5](ackRx=5)
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=6](ackRx=5 frmTx=6)
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=6 frmNum=5](frmRx=5) Added to rxQueue
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=6](ackRx=6)
[2024-10-20 20:04:45] debug:    zh:ember:ezsp: <=== [FRAME: ID=3:"GET_EXTENDED_VALUE" Seq=21 Len=9]
[2024-10-20 20:04:45] debug:    zh:ember:ezsp: ===> [FRAME: ID=2:"ADD_ENDPOINT" Seq=22 Len=17]
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=6 frmRx=6](ackRx=6)
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=7](ackRx=6 frmTx=7)
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=7 frmNum=6](frmRx=6) Added to rxQueue
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=7](ackRx=7)
[2024-10-20 20:04:45] debug:    zh:ember:ezsp: <=== [FRAME: ID=2:"ADD_ENDPOINT" Seq=22 Len=6]
[2024-10-20 20:04:45] debug:    zh:ember: Registered endpoint '242'.
[2024-10-20 20:04:45] debug:    zh:ember:ezsp: ===> [FRAME: ID=100:"SET_MULTICAST_TABLE_ENTRY" Seq=23 Len=10]
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=7 frmRx=7](ackRx=7)
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=0](ackRx=7 frmTx=0)
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=0 frmNum=7](frmRx=7) Added to rxQueue
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=0](ackRx=0)
[2024-10-20 20:04:45] debug:    zh:ember:ezsp: <=== [FRAME: ID=100:"SET_MULTICAST_TABLE_ENTRY" Seq=23 Len=6]
[2024-10-20 20:04:45] debug:    zh:ember: Registered multicast table entry (2): {"multicastId":2948,"endpoint":242,"networkIndex":0}.
[2024-10-20 20:04:45] debug:    zh:ember:ezsp: ===> [FRAME: ID=85:"SET_POLICY" Seq=24 Len=7]
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=0 frmRx=0](ackRx=0)
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=1](ackRx=0 frmTx=1)
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=1 frmNum=0](frmRx=0) Added to rxQueue
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=1](ackRx=1)
[2024-10-20 20:04:45] debug:    zh:ember:ezsp: <=== [FRAME: ID=85:"SET_POLICY" Seq=24 Len=6]
[2024-10-20 20:04:45] debug:    zh:ember: [EzspPolicyId] SET 'TC_KEY_REQUEST_POLICY' TO '81' with status=OK.
[2024-10-20 20:04:45] debug:    zh:ember:ezsp: ===> [FRAME: ID=85:"SET_POLICY" Seq=25 Len=7]
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=1 frmRx=1](ackRx=1)
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=2](ackRx=1 frmTx=2)
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=2 frmNum=1](frmRx=1) Added to rxQueue
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=2](ackRx=2)
[2024-10-20 20:04:45] debug:    zh:ember:ezsp: <=== [FRAME: ID=85:"SET_POLICY" Seq=25 Len=6]
[2024-10-20 20:04:45] debug:    zh:ember: [EzspPolicyId] SET 'APP_KEY_REQUEST_POLICY' TO '96' with status=OK.
[2024-10-20 20:04:45] debug:    zh:ember:ezsp: ===> [FRAME: ID=85:"SET_POLICY" Seq=26 Len=7]
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=2 frmRx=2](ackRx=2)
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=3](ackRx=2 frmTx=3)
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=3 frmNum=2](frmRx=2) Added to rxQueue
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=3](ackRx=3)
[2024-10-20 20:04:45] debug:    zh:ember:ezsp: <=== [FRAME: ID=85:"SET_POLICY" Seq=26 Len=6]
[2024-10-20 20:04:45] debug:    zh:ember: [EzspPolicyId] SET 'TRUST_CENTER_POLICY' TO '3' with status=OK.
[2024-10-20 20:04:45] debug:    zh:ember:ezsp: ===> [FRAME: ID=23:"NETWORK_INIT" Seq=27 Len=7]
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=3 frmRx=3](ackRx=3)
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=4](ackRx=3 frmTx=4)
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=4 frmNum=3](frmRx=3) Added to rxQueue
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=4](ackRx=4)
[2024-10-20 20:04:45] debug:    zh:ember:ezsp: <=== [FRAME: ID=23:"NETWORK_INIT" Seq=27 Len=6]
[2024-10-20 20:04:45] debug:    zh:ember: [INIT TC] Network init status=OK.
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=4](ackRx=4 frmTx=4)
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=4 frmNum=4](frmRx=4) Added to rxQueue
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=5](ackRx=4)
[2024-10-20 20:04:45] debug:    zh:ember:ezsp: <=== [CBFRAME: ID=25:"STACK_STATUS_HANDLER" Seq=27 Len=6]
[2024-10-20 20:04:45] debug:    zh:ember:ezsp: ezspStackStatusHandler(): callback called with: [status=NETWORK_UP]
[2024-10-20 20:04:45] info:     zh:ember: [STACK STATUS] Network up.
[2024-10-20 20:04:45] debug:    zh:ember:ezsp: ===> [FRAME: ID=40:"GET_NETWORK_PARAMETERS" Seq=28 Len=5]
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=4 frmRx=5](ackRx=4)
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=5](ackRx=4 frmTx=5)
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=5 frmNum=5](frmRx=5) Added to rxQueue
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=6](ackRx=5)
[2024-10-20 20:04:45] debug:    zh:ember:ezsp: <=== [FRAME: ID=40:"GET_NETWORK_PARAMETERS" Seq=28 Len=27]
[2024-10-20 20:04:45] debug:    zh:ember: [INIT TC] Current adapter network: nodeType=COORDINATOR params={"extendedPanId":[81,25,81,199,220,210,40,221],"panId":22371,"radioTxPower":5,"radioChannel":25,"joinMethod":0,"nwkManagerId":0,"nwkUpdateId":0,"channels":134215680}
[2024-10-20 20:04:45] debug:    zh:ember:ezsp: ===> [FRAME: ID=276:"EXPORT_KEY" Seq=29 Len=23]
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=5 frmRx=6](ackRx=5)
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=6](ackRx=5 frmTx=6)
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=6 frmNum=6](frmRx=6) Added to rxQueue
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=7](ackRx=6)
[2024-10-20 20:04:45] debug:    zh:ember:ezsp: <=== [FRAME: ID=276:"EXPORT_KEY" Seq=29 Len=25]
[2024-10-20 20:04:45] info:     zh:ember: [INIT TC] Adapter network matches config.
[2024-10-20 20:04:45] debug:    zh:ember:ezsp: ===> [FRAME: ID=16:"SET_CONCENTRATOR" Seq=30 Len=15]
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=6 frmRx=7](ackRx=6)
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=7](ackRx=6 frmTx=7)
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=7 frmNum=7](frmRx=7) Added to rxQueue
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=0](ackRx=7)
[2024-10-20 20:04:45] debug:    zh:ember:ezsp: <=== [FRAME: ID=16:"SET_CONCENTRATOR" Seq=30 Len=6]
[2024-10-20 20:04:45] debug:    zh:ember:ezsp: ===> [FRAME: ID=90:"SET_SOURCE_ROUTE_DISCOVERY_MODE" Seq=31 Len=6]
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=7 frmRx=0](ackRx=7)
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=0](ackRx=7 frmTx=0)
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=0 frmNum=0](frmRx=0) Added to rxQueue
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=1](ackRx=0)
[2024-10-20 20:04:45] debug:    zh:ember:ezsp: <=== [FRAME: ID=90:"SET_SOURCE_ROUTE_DISCOVERY_MODE" Seq=31 Len=9]
[2024-10-20 20:04:45] info:     zh:ember: [CONCENTRATOR] Started source route discovery. 1248ms until next broadcast.
[2024-10-20 20:04:45] debug:    zh:ember:ezsp: ===> [FRAME: ID=40:"GET_NETWORK_PARAMETERS" Seq=32 Len=5]
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=0 frmRx=1](ackRx=0)
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=1](ackRx=0 frmTx=1)
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=1 frmNum=1](frmRx=1) Added to rxQueue
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=2](ackRx=1)
[2024-10-20 20:04:45] debug:    zh:ember:ezsp: <=== [FRAME: ID=40:"GET_NETWORK_PARAMETERS" Seq=32 Len=27]
[2024-10-20 20:04:45] debug:    zh:ember:ezsp: ===> [FRAME: ID=38:"GET_EUI64" Seq=33 Len=5]
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=1 frmRx=2](ackRx=1)
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=2](ackRx=1 frmTx=2)
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=2 frmNum=2](frmRx=2) Added to rxQueue
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=3](ackRx=2)
[2024-10-20 20:04:45] debug:    zh:ember:ezsp: <=== [FRAME: ID=38:"GET_EUI64" Seq=33 Len=13]
[2024-10-20 20:04:45] debug:    zh:ember: [INIT] Network Ready! {"eui64":"0xe0798dfffee24538","parameters":{"extendedPanId":[81,25,81,199,220,210,40,221],"panId":22371,"radioTxPower":5,"radioChannel":25,"joinMethod":0,"nwkManagerId":0,"nwkUpdateId":0,"channels":134215680}}
[2024-10-20 20:04:45] debug:    zh:controller: Started with result 'resumed'
[2024-10-20 20:04:45] debug:    zh:controller: Injected database: true, adapter: true
[2024-10-20 20:04:45] debug:    zh:controller:device: Request Queue (0xe0798dfffee24538): default expiration timeout set to 0
[2024-10-20 20:04:45] info:     z2m: zigbee-herdsman started (resumed)
[2024-10-20 20:04:45] info:     z2m: Coordinator firmware version: '{"meta":{"build":0,"ezsp":13,"major":7,"minor":4,"patch":3,"revision":"7.4.3 [GA]","special":0,"type":170},"type":"EmberZNet"}'
[2024-10-20 20:04:45] debug:    z2m: Zigbee network parameters: {"channel":25,"extendedPanID":5843791910335031000,"panID":22371}
[2024-10-20 20:04:45] info:     z2m: Currently 0 devices are joined.
[2024-10-20 20:04:45] warning:  z2m: `permit_join` set to  `true` in configuration.yaml.
[2024-10-20 20:04:45] warning:  z2m: Allowing new devices to join.
[2024-10-20 20:04:45] warning:  z2m: Set `permit_join` to `false` once you joined all devices.
[2024-10-20 20:04:45] info:     z2m: Zigbee: allowing new devices to join.
[2024-10-20 20:04:45] debug:    zh:ember:ezsp: ===> [FRAME: ID=273:"IMPORT_TRANSIENT_KEY" Seq=34 Len=30]
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=2 frmRx=3](ackRx=2)
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=3](ackRx=2 frmTx=3)
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=3 frmNum=3](frmRx=3) Added to rxQueue
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=4](ackRx=3)
[2024-10-20 20:04:45] debug:    zh:ember:ezsp: <=== [FRAME: ID=273:"IMPORT_TRANSIENT_KEY" Seq=34 Len=9]
[2024-10-20 20:04:45] debug:    zh:ember:ezsp: ===> [FRAME: ID=85:"SET_POLICY" Seq=35 Len=7]
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=3 frmRx=4](ackRx=3)
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=4](ackRx=3 frmTx=4)
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=4 frmNum=4](frmRx=4) Added to rxQueue
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=5](ackRx=4)
[2024-10-20 20:04:45] debug:    zh:ember:ezsp: <=== [FRAME: ID=85:"SET_POLICY" Seq=35 Len=6]
[2024-10-20 20:04:45] debug:    zh:ember: [EzspPolicyId] SET 'TRUST_CENTER_POLICY' TO '3' with status=OK.
[2024-10-20 20:04:45] debug:    zh:ember:ezsp: ===> [FRAME: ID=34:"PERMIT_JOINING" Seq=36 Len=6]
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=4 frmRx=5](ackRx=4)
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=5](ackRx=4 frmTx=5)
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=5 frmNum=5](frmRx=5) Added to rxQueue
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=6](ackRx=5)
[2024-10-20 20:04:45] debug:    zh:ember:ezsp: <=== [FRAME: ID=34:"PERMIT_JOINING" Seq=36 Len=6]
[2024-10-20 20:04:45] debug:    zh:ember: Permit joining on coordinator for 254 sec.
[2024-10-20 20:04:45] debug:    zh:ember: ~~~> [ZDO PERMIT_JOINING_REQUEST BROADCAST to=65532 messageTag=1 payload=01fe01]
[2024-10-20 20:04:45] debug:    zh:ember:ezsp: ===> [FRAME: ID=54:"SEND_BROADCAST" Seq=37 Len=24]
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=5 frmRx=6](ackRx=5)
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=5](ackRx=5 frmTx=6)
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=5 frmNum=6](frmRx=6) Added to rxQueue
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=7](ackRx=5)
[2024-10-20 20:04:45] debug:    zh:ember:ezsp: <=== [CBFRAME: ID=25:"STACK_STATUS_HANDLER" Seq=36 Len=6]
[2024-10-20 20:04:45] debug:    zh:ember:ezsp: ezspStackStatusHandler(): callback called with: [status=ZIGBEE_NETWORK_OPENED]
[2024-10-20 20:04:45] info:     zh:ember: [STACK STATUS] Network opened.
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=6](ackRx=5 frmTx=6)
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=6 frmNum=7](frmRx=7) Added to rxQueue
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=0](ackRx=6)
[2024-10-20 20:04:45] debug:    zh:ember:ezsp: <=== [FRAME: ID=54:"SEND_BROADCAST" Seq=37 Len=7]
[2024-10-20 20:04:45] debug:    zh:ember: ~~~> [SENT ZDO BROADCAST messageTag=1 apsSequence=151 status=OK]
[2024-10-20 20:04:45] 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},"transactionSequenceNumber":2,"commandIdentifier":2}]
[2024-10-20 20:04:45] debug:    zh:ember:ezsp: ===> [FRAME: ID=54:"SEND_BROADCAST" Seq=38 Len=27]
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=6 frmRx=0](ackRx=6)
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=7](ackRx=6 frmTx=7)
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=7 frmNum=0](frmRx=0) Added to rxQueue
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=1](ackRx=7)
[2024-10-20 20:04:45] debug:    zh:ember:ezsp: <=== [FRAME: ID=54:"SEND_BROADCAST" Seq=38 Len=7]
[2024-10-20 20:04:45] debug:    zh:ember:ezsp: ~~~> [SENT type=BROADCAST apsSequence=152 messageTag=1 status=OK]
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=7](ackRx=7 frmTx=7)
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=7 frmNum=1](frmRx=1) Added to rxQueue
[2024-10-20 20:04:45] debug:    zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=2](ackRx=7)
[2024-10-20 20:04:45] debug:    zh:ember:ezsp: <=== [CBFRAME: ID=69:"INCOMING_MESSAGE_HANDLER" Seq=38 Len=30]
[2024-10-20 20:04:45] 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":152}], [packetInfo:{"senderShortId":0,"senderLongId":"0xFFFFFFFFFFFFFFFF","bindingIndex":255,"addressIndex":255,"lastHopLqi":255,"lastHopRssi":0,"lastHopTimestamp":0}], [messageContents=1902020bfe00]
[2024-10-20 20:04:46] info:     z2m: Connecting to MQTT server at mqtt://192.168.2.107:1883
[2024-10-20 20:04:46] debug:    z2m: Using MQTT keepalive: 60
[2024-10-20 20:04:46] debug:    z2m: Using MQTT login with username: bemo47
[2024-10-20 20:04:46] info:     z2m: Connected to MQTT server
[2024-10-20 20:04:46] info:     z2m:mqtt: MQTT publish: topic 'zigbee2mqtt/bridge/state', payload '{"state":"online"}'
[2024-10-20 20:04:46] info:     z2m: Started frontend on port 8080
[2024-10-20 20:04:46] debug:    z2m: Discovering entities to Home Assistant in 5s
[2024-10-20 20:04:46] info:     z2m:mqtt: MQTT publish: topic 'zigbee2mqtt/bridge/state', payload '{"state":"online"}'
[2024-10-20 20:04:46] info:     z2m: Zigbee2MQTT started!
[2024-10-20 20:04:46] debug:    z2m:mqtt: Received MQTT message on 'homeassistant/binary_sensor/1221051039810110150109113116116_0xe0798dfffee24538/connection_state/config' with data '{"device":{"hw_version":"EmberZNet 7.4.3 [GA]","identifiers":["zigbee2mqtt_bridge_0xe0798dfffee24538"],"manufacturer":"Zigbee2MQTT","model":"Bridge","name":"Zigbee2MQTT Bridge","sw_version":"1.40.2"},"device_class":"connectivity","entity_category":"diagnostic","name":"Connection state","object_id":"zigbee2mqtt_bridge_connection_state","origin":{"name":"Zigbee2MQTT","sw":"1.40.2","url":"https://www.zigbee2mqtt.io"},"payload_off":"offline","payload_on":"online","state_topic":"zigbee2mqtt/bridge/state","unique_id":"bridge_0xe0798dfffee24538_connection_state_zigbee2mqtt","value_template":"{{ value_json.state }}"}'
[2024-10-20 20:04:46] debug:    z2m:mqtt: Received MQTT message on 'homeassistant/binary_sensor/1221051039810110150109113116116_0xe0798dfffee24538/restart_required/config' with data '{"availability":[{"topic":"zigbee2mqtt/bridge/state","value_template":"{{ value_json.state }}"}],"availability_mode":"all","device":{"hw_version":"EmberZNet 7.4.3 [GA]","identifiers":["zigbee2mqtt_bridge_0xe0798dfffee24538"],"manufacturer":"Zigbee2MQTT","model":"Bridge","name":"Zigbee2MQTT Bridge","sw_version":"1.40.2"},"device_class":"problem","enabled_by_default":false,"entity_category":"diagnostic","name":"Restart required","object_id":"zigbee2mqtt_bridge_restart_required","origin":{"name":"Zigbee2MQTT","sw":"1.40.2","url":"https://www.zigbee2mqtt.io"},"payload_off":false,"payload_on":true,"state_topic":"zigbee2mqtt/bridge/info","unique_id":"bridge_0xe0798dfffee24538_restart_required_zigbee2mqtt","value_template":"{{ value_json.restart_required }}"}'
[2024-10-20 20:04:46] debug:    z2m:mqtt: Received MQTT message on 'homeassistant/button/1221051039810110150109113116116_0xe0798dfffee24538/restart/config' with data '{"availability":[{"topic":"zigbee2mqtt/bridge/state","value_template":"{{ value_json.state }}"}],"availability_mode":"all","command_topic":"zigbee2mqtt/bridge/request/restart","device":{"hw_version":"EmberZNet 7.4.3 [GA]","identifiers":["zigbee2mqtt_bridge_0xe0798dfffee24538"],"manufacturer":"Zigbee2MQTT","model":"Bridge","name":"Zigbee2MQTT Bridge","sw_version":"1.40.2"},"device_class":"restart","name":"Restart","object_id":"zigbee2mqtt_bridge_restart","origin":{"name":"Zigbee2MQTT","sw":"1.40.2","url":"https://www.zigbee2mqtt.io"},"payload_press":"","unique_id":"bridge_0xe0798dfffee24538_restart_zigbee2mqtt"}'
[2024-10-20 20:04:46] debug:    z2m:mqtt: Received MQTT message on 'homeassistant/select/1221051039810110150109113116116_0xe0798dfffee24538/log_level/config' with data '{"availability":[{"topic":"zigbee2mqtt/bridge/state","value_template":"{{ value_json.state }}"}],"availability_mode":"all","command_template":"{\"options\": {\"advanced\": {\"log_level\": \"{{ value }}\" } } }","command_topic":"zigbee2mqtt/bridge/request/options","device":{"hw_version":"EmberZNet 7.4.3 [GA]","identifiers":["zigbee2mqtt_bridge_0xe0798dfffee24538"],"manufacturer":"Zigbee2MQTT","model":"Bridge","name":"Zigbee2MQTT Bridge","sw_version":"1.40.2"},"entity_category":"config","name":"Log level","object_id":"zigbee2mqtt_bridge_log_level","options":["error","warning","info","debug"],"origin":{"name":"Zigbee2MQTT","sw":"1.40.2","url":"https://www.zigbee2mqtt.io"},"state_topic":"zigbee2mqtt/bridge/info","unique_id":"bridge_0xe0798dfffee24538_log_level_zigbee2mqtt","value_template":"{{ value_json.log_level | lower }}"}'
[2024-10-20 20:04:46] debug:    z2m:mqtt: Received MQTT message on 'homeassistant/sensor/1221051039810110150109113116116_0xe0798dfffee24538/version/config' with data '{"availability":[{"topic":"zigbee2mqtt/bridge/state","value_template":"{{ value_json.state }}"}],"availability_mode":"all","device":{"hw_version":"EmberZNet 7.4.3 [GA]","identifiers":["zigbee2mqtt_bridge_0xe0798dfffee24538"],"manufacturer":"Zigbee2MQTT","model":"Bridge","name":"Zigbee2MQTT Bridge","sw_version":"1.40.2"},"entity_category":"diagnostic","icon":"mdi:zigbee","name":"Version","object_id":"zigbee2mqtt_bridge_version","origin":{"name":"Zigbee2MQTT","sw":"1.40.2","url":"https://www.zigbee2mqtt.io"},"state_topic":"zigbee2mqtt/bridge/info","unique_id":"bridge_0xe0798dfffee24538_version_zigbee2mqtt","value_template":"{{ value_json.version }}"}'
[2024-10-20 20:04:46] debug:    z2m:mqtt: Received MQTT message on 'homeassistant/sensor/1221051039810110150109113116116_0xe0798dfffee24538/coordinator_version/config' with data '{"availability":[{"topic":"zigbee2mqtt/bridge/state","value_template":"{{ value_json.state }}"}],"availability_mode":"all","device":{"hw_version":"EmberZNet 7.4.3 [GA]","identifiers":["zigbee2mqtt_bridge_0xe0798dfffee24538"],"manufacturer":"Zigbee2MQTT","model":"Bridge","name":"Zigbee2MQTT Bridge","sw_version":"1.40.2"},"enabled_by_default":false,"entity_category":"diagnostic","icon":"mdi:chip","name":"Coordinator version","object_id":"zigbee2mqtt_bridge_coordinator_version","origin":{"name":"Zigbee2MQTT","sw":"1.40.2","url":"https://www.zigbee2mqtt.io"},"state_topic":"zigbee2mqtt/bridge/info","unique_id":"bridge_0xe0798dfffee24538_coordinator_version_zigbee2mqtt","value_template":"{{ value_json.coordinator.meta.revision }}"}'
[2024-10-20 20:04:46] debug:    z2m:mqtt: Received MQTT message on 'homeassistant/sensor/1221051039810110150109113116116_0xe0798dfffee24538/network_map/config' with data '{"availability":[{"topic":"zigbee2mqtt/bridge/state","value_template":"{{ value_json.state }}"}],"availability_mode":"all","device":{"hw_version":"EmberZNet 7.4.3 [GA]","identifiers":["zigbee2mqtt_bridge_0xe0798dfffee24538"],"manufacturer":"Zigbee2MQTT","model":"Bridge","name":"Zigbee2MQTT Bridge","sw_version":"1.40.2"},"enabled_by_default":false,"entity_category":"diagnostic","json_attributes_template":"{{ value_json.data.value | tojson }}","json_attributes_topic":"zigbee2mqtt/bridge/response/networkmap","name":"Network map","object_id":"zigbee2mqtt_bridge_network_map","origin":{"name":"Zigbee2MQTT","sw":"1.40.2","url":"https://www.zigbee2mqtt.io"},"state_topic":"zigbee2mqtt/bridge/response/networkmap","unique_id":"bridge_0xe0798dfffee24538_network_map_zigbee2mqtt","value_template":"{{ now().strftime('%Y-%m-%d %H:%M:%S') }}"}'
[2024-10-20 20:04:46] debug:    z2m:mqtt: Received MQTT message on 'homeassistant/sensor/1221051039810110150109113116116_0xe0798dfffee24538/permit_join_timeout/config' with data '{"availability":[{"topic":"zigbee2mqtt/bridge/state","value_template":"{{ value_json.state }}"}],"availability_mode":"all","device":{"hw_version":"EmberZNet 7.4.3 [GA]","identifiers":["zigbee2mqtt_bridge_0xe0798dfffee24538"],"manufacturer":"Zigbee2MQTT","model":"Bridge","name":"Zigbee2MQTT Bridge","sw_version":"1.40.2"},"device_class":"duration","entity_category":"diagnostic","name":"Permit join timeout","object_id":"zigbee2mqtt_bridge_permit_join_timeout","origin":{"name":"Zigbee2MQTT","sw":"1.40.2","url":"https://www.zigbee2mqtt.io"},"state_topic":"zigbee2mqtt/bridge/info","unique_id":"bridge_0xe0798dfffee24538_permit_join_timeout_zigbee2mqtt","unit_of_measurement":"s","value_template":"{{ iif(value_json.permit_join_timeout is defined, value_json.permit_join_timeout, None) }}"}'
[2024-10-20 20:04:46] debug:    z2m:mqtt: Received MQTT message on 'homeassistant/switch/1221051039810110150109113116116_0xe0798dfffee24538/permit_join/config' with data '{"availability":[{"topic":"zigbee2mqtt/bridge/state","value_template":"{{ value_json.state }}"}],"availability_mode":"all","command_topic":"zigbee2mqtt/bridge/request/permit_join","device":{"hw_version":"EmberZNet 7.4.3 [GA]","identifiers":["zigbee2mqtt_bridge_0xe0798dfffee24538"],"manufacturer":"Zigbee2MQTT","model":"Bridge","name":"Zigbee2MQTT Bridge","sw_version":"1.40.2"},"icon":"mdi:human-greeting-proximity","name":"Permit join","object_id":"zigbee2mqtt_bridge_permit_join","origin":{"name":"Zigbee2MQTT","sw":"1.40.2","url":"https://www.zigbee2mqtt.io"},"payload_off":"false","payload_on":"true","state_topic":"zigbee2mqtt/bridge/info","unique_id":"bridge_0xe0798dfffee24538_permit_join_zigbee2mqtt","value_template":"{{ value_json.permit_join | lower }}"}'
[2024-10-20 20:04:46] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-10-20 20:04:46] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=7](ackRx=7 frmTx=7)
[2024-10-20 20:04:46] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=7 frmNum=2](frmRx=2) Added to rxQueue
[2024-10-20 20:04:46] debug:    zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=3](ackRx=7)
[2024-10-20 20:04:46] debug:    zh:ember:ezsp: <=== [CBFRAME: ID=63:"MESSAGE_SENT_HANDLER" Seq=38 Len=22]
[2024-10-20 20:04:46] debug:    zh:ember:ezsp: ezspMessageSentHandler(): callback called with: [status=OK], [type=BROADCAST], [indexOrDestination=65533], [apsFrame={"profileId":41440,"clusterId":33,"sourceEndpoint":242,"destinationEndpoint":242,"options":256,"groupId":0,"sequence":152}], [messageTag=1]
[2024-10-20 20:04:46] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-10-20 20:04:46] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=7](ackRx=7 frmTx=7)
[2024-10-20 20:04:46] debug:    zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=7 frmNum=3](frmRx=3) Added to rxQueue
[2024-10-20 20:04:46] debug:    zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=4](ackRx=7)
[2024-10-20 20:04:46] debug:    zh:ember:ezsp: <=== [CBFRAME: ID=63:"MESSAGE_SENT_HANDLER" Seq=38 Len=22]
[2024-10-20 20:04:46] debug:    zh:ember:ezsp: ezspMessageSentHandler(): callback called with: [status=OK], [type=BROADCAST], [indexOrDestination=65532], [apsFrame={"profileId":0,"clusterId":54,"sourceEndpoint":0,"destinationEndpoint":0,"options":256,"groupId":0,"sequence":151}], [messageTag=255]
[2024-10-20 20:04:51] debug:    z2m: Discovering entities to Home Assistant
[2024-10-20 20:04:51] info:     z2m:mqtt: MQTT publish: topic 'homeassistant/binary_sensor/1221051039810110150109113116116_0xe0798dfffee24538/connection_state/config', payload '{"device":{"hw_version":"EmberZNet 7.4.3 [GA]","identifiers":["zigbee2mqtt_bridge_0xe0798dfffee24538"],"manufacturer":"Zigbee2MQTT","model":"Bridge","name":"Zigbee2MQTT Bridge","sw_version":"1.40.2"},"device_class":"connectivity","entity_category":"diagnostic","name":"Connection state","object_id":"zigbee2mqtt_bridge_connection_state","origin":{"name":"Zigbee2MQTT","sw":"1.40.2","url":"https://www.zigbee2mqtt.io"},"payload_off":"offline","payload_on":"online","state_topic":"zigbee2mqtt/bridge/state","unique_id":"bridge_0xe0798dfffee24538_connection_state_zigbee2mqtt","value_template":"{{ value_json.state }}"}'
[2024-10-20 20:04:51] debug:    z2m: Skipping discovery of 'binary_sensor/1221051039810110150109113116116_0xe0798dfffee24538/restart_required/config', already discovered
[2024-10-20 20:04:51] debug:    z2m: Skipping discovery of 'button/1221051039810110150109113116116_0xe0798dfffee24538/restart/config', already discovered
[2024-10-20 20:04:51] debug:    z2m: Skipping discovery of 'select/1221051039810110150109113116116_0xe0798dfffee24538/log_level/config', already discovered
[2024-10-20 20:04:51] debug:    z2m: Skipping discovery of 'sensor/1221051039810110150109113116116_0xe0798dfffee24538/version/config', already discovered
[2024-10-20 20:04:51] debug:    z2m: Skipping discovery of 'sensor/1221051039810110150109113116116_0xe0798dfffee24538/coordinator_version/config', already discovered
[2024-10-20 20:04:51] debug:    z2m: Skipping discovery of 'sensor/1221051039810110150109113116116_0xe0798dfffee24538/network_map/config', already discovered
[2024-10-20 20:04:51] debug:    z2m: Skipping discovery of 'sensor/1221051039810110150109113116116_0xe0798dfffee24538/permit_join_timeout/config', already discovered
[2024-10-20 20:04:51] debug:    z2m: Skipping discovery of 'switch/1221051039810110150109113116116_0xe0798dfffee24538/permit_join/config', already discovered 

je mets ici la config yaml de mon nouveau Z2M :

homeassistant: true
advanced:
  network_key:
    - 19
    - 95
    - 92
    - 236
    - 138
    - 204
    - 188
    - 161
    - 178
    - 142
    - 177
    - 148
    - 191
    - 70
    - 6
    - 66
  pan_id: 22371
  ext_pan_id:
    - 81
    - 25
    - 81
    - 199
    - 220
    - 210
    - 40
    - 221
  homeassistant_legacy_entity_attributes: false
  legacy_api: false
  legacy_availability_payload: false
  log_level: debug
  channel: 25
mqtt:
  base_topic: zigbee2mqtt
  server: mqtt://192.168.2.107:1883
  user: xxxxxx
  password: xxxxxxxxx
  keepalive: 60
  reject_unauthorized: true
  version: 4
serial:
  port: >-
    /dev/serial/by-id/usb-ITEAD_SONOFF_Zigbee_3.0_USB_Dongle_Plus_V2_20231102142912-if00
  adapter: ember
frontend:
  port: 8080
device_options:
  legacy: false
devices:
  '0x6c5cb1fffe9868b8':
    friendly_name: 'Extender Cuisine'
  '0xec1bbdfffe32fe29':
    friendly_name: 'Interrupteur livarno salon'
  '0x588e81fffefb208e':
    friendly_name: 'Plaff Salon'
  '0xbc026efffe239340':
    friendly_name: 'Ext Tour'
  '0xb43522fffe03e207':
    friendly_name: 'Ext Gde Chambre '
  '0xb43522fffe03f5cd':
    friendly_name: 'Ext Buanderie '
  '0xa4c13895dd877109':
    friendly_name: 'Prise LIDL'
  '0x00124b00292f5dbf':
    friendly_name: 'Sonoff Salon'
  '0x00124b00292f818d':
    friendly_name: 'Sonoff ch bm'
  '0x00124b00292f617f':
    friendly_name: 'Sonoff Cuisine'
  '0x00124b00292fbd98':
    friendly_name: 'Sonoff Tour Haut'
  '0x00124b002fac2612':
    friendly_name: 'Sonoff CH Facade'
  '0x00124b002fac1c85':
    friendly_name: 'Sonoff Gde Chambre '
  '0x00124b002fac2e4e':
    friendly_name: 'Sonoff Tour Bas'
  '0x70b3d52b600aee67':
    friendly_name: 'Prise tableau'
  '0x70b3d52b600aeca8':
    friendly_name: 'Prise tour'
  '0x70b3d52b6009d327':
    friendly_name: 'Prise Salle Sport'
  '0x70b3d52b6009e785':
    friendly_name: 'Prise Pi4'
availability: true
permit_join: true

[bemo47]

J’ai progressé, j’ai aussi ajouté les 3 autres fichiers de l’ancienne config :

• database.db
• state.json
• coordinator_backup.json

ça a redémarré, je vois mes appareils dans Z2M web et ils semblent se remettre en ligne progressivement…

à suivre…

[bemo47]

Alors, j’ai fait un arrêt / relance de HA, MQTT et Z2M, mais Z2M ne semble pas pouvoir ouvrir le port USB du dongle, il doit manquer une autorisation pour que la VM prenne ce port ?
Pourtant j’ai fait une install avec privilèges suivant un tuto qui semblait vouloir dire que la VM pouvait s’attribuer ce port.

La console du démarrage :

root@zigbee2mqtt:/opt/zigbee2mqtt# cd /opt/zigbee2mqtt && npm start

> zigbee2mqtt@1.40.2 start
> node index.js

Starting Zigbee2MQTT without watchdog.
[2024-10-20 21:11:33] info:     z2m: Logging to console, file (filename: log.log)
[2024-10-20 21:11:33] debug:    z2m: Loaded state from file /opt/zigbee2mqtt/data/state.json
[2024-10-20 21:11:33] info:     z2m: Starting Zigbee2MQTT version 1.40.2 (commit #e06848d)
[2024-10-20 21:11:33] debug:    z2m: sd-notify loaded
[2024-10-20 21:11:33] info:     z2m: Starting zigbee-herdsman (2.1.3)
[2024-10-20 21:11:33] debug:    z2m: Using zigbee-herdsman with settings: '"{\"network\":{\"panID\":22371,\"extendedPanID\":[81,25,81,199,220,210,40,221],\"channelList\":[25],\"networkKey\":\"HIDDEN\"},\"databasePath\":\"/opt/zigbee2mqtt/data/database.db\",\"databaseBackupPath\":\"/opt/zigbee2mqtt/data/database.db.backup\",\"backupPath\":\"/opt/zigbee2mqtt/data/coordinator_backup.json\",\"serialPort\":{\"path\":\"/dev/serial/by-id/usb-ITEAD_SONOFF_Zigbee_3.0_USB_Dongle_Plus_V2_20231102142912-if00\",\"adapter\":\"ember\"},\"adapter\":{\"disableLED\":false}}"'
[2024-10-20 21:11:33] info:     zh:ember: Using default stack config.
[2024-10-20 21:11:33] debug:    zh:controller: Starting with options '{"network":{"networkKeyDistribute":false,"networkKey":"HIDDEN","panID":22371,"extendedPanID":[81,25,81,199,220,210,40,221],"channelList":[25]},"serialPort":{"path":"/dev/serial/by-id/usb-ITEAD_SONOFF_Zigbee_3.0_USB_Dongle_Plus_V2_20231102142912-if00","adapter":"ember"},"adapter":{"disableLED":false},"databasePath":"/opt/zigbee2mqtt/data/database.db","databaseBackupPath":"/opt/zigbee2mqtt/data/database.db.backup","backupPath":"/opt/zigbee2mqtt/data/coordinator_backup.json"}'
[2024-10-20 21:11:33] info:     zh:ember: ======== Ember Adapter Starting ========
[2024-10-20 21:11:33] info:     zh:ember:ezsp: ======== EZSP starting ========
[2024-10-20 21:11:33] info:     zh:ember:uart:ash: ======== ASH Adapter reset ========
[2024-10-20 21:11:33] info:     zh:ember:uart:ash: RTS/CTS config is off, enabling software flow control.
[2024-10-20 21:11:33] debug:    zh:ember:uart:ash: Opening serial port with {"path":"/dev/serial/by-id/usb-ITEAD_SONOFF_Zigbee_3.0_USB_Dongle_Plus_V2_20231102142912-if00","baudRate":115200,"rtscts":false,"autoOpen":false,"parity":"none","stopBits":1,"xon":true,"xoff":true}
[2024-10-20 21:11:33] info:     zh:ember:uart:ash: ASH COUNTERS since last clear:
[2024-10-20 21:11:33] info:     zh:ember:uart:ash:   Total frames: RX=0, TX=0
[2024-10-20 21:11:33] info:     zh:ember:uart:ash:   Cancelled   : RX=0, TX=0
[2024-10-20 21:11:33] info:     zh:ember:uart:ash:   DATA frames : RX=0, TX=0
[2024-10-20 21:11:33] info:     zh:ember:uart:ash:   DATA bytes  : RX=0, TX=0
[2024-10-20 21:11:33] info:     zh:ember:uart:ash:   Retry frames: RX=0, TX=0
[2024-10-20 21:11:33] info:     zh:ember:uart:ash:   ACK frames  : RX=0, TX=0
[2024-10-20 21:11:33] info:     zh:ember:uart:ash:   NAK frames  : RX=0, TX=0
[2024-10-20 21:11:33] info:     zh:ember:uart:ash:   nRdy frames : RX=0, TX=0
[2024-10-20 21:11:33] info:     zh:ember:uart:ash:   CRC errors      : RX=0
[2024-10-20 21:11:33] info:     zh:ember:uart:ash:   Comm errors     : RX=0
[2024-10-20 21:11:33] info:     zh:ember:uart:ash:   Length < minimum: RX=0
[2024-10-20 21:11:33] info:     zh:ember:uart:ash:   Length > maximum: RX=0
[2024-10-20 21:11:33] info:     zh:ember:uart:ash:   Bad controls    : RX=0
[2024-10-20 21:11:33] info:     zh:ember:uart:ash:   Bad lengths     : RX=0
[2024-10-20 21:11:33] info:     zh:ember:uart:ash:   Bad ACK numbers : RX=0
[2024-10-20 21:11:33] info:     zh:ember:uart:ash:   Out of buffers  : RX=0
[2024-10-20 21:11:33] info:     zh:ember:uart:ash:   Retry dupes     : RX=0
[2024-10-20 21:11:33] info:     zh:ember:uart:ash:   Out of sequence : RX=0
[2024-10-20 21:11:33] info:     zh:ember:uart:ash:   ACK timeouts    : RX=0
[2024-10-20 21:11:33] info:     zh:ember:uart:ash: ======== ASH stopped ========
[2024-10-20 21:11:33] error:    zh:ember:uart:ash: Failed to init port with error Error: Error Resource temporarily unavailable Cannot lock port
[2024-10-20 21:11:34] error:    z2m: Error while starting zigbee-herdsman
[2024-10-20 21:11:34] error:    z2m: Failed to start zigbee
[2024-10-20 21:11:34] error:    z2m: Check https://www.zigbee2mqtt.io/guide/installation/20_zigbee2mqtt-fails-to-start.html for possible solutions
[2024-10-20 21:11:34] error:    z2m: Exiting...
[2024-10-20 21:11:34] error:    z2m: Error: Failed to start EZSP layer with status=HOST_FATAL_ERROR.
    at EmberAdapter.initEzsp (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/src/adapter/ember/adapter/emberAdapter.ts:684:19)
    at EmberAdapter.start (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/src/adapter/ember/adapter/emberAdapter.ts:1583:24)
    at Controller.start (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/src/controller/controller.ts:137:29)
    at Zigbee.start (/opt/zigbee2mqtt/lib/zigbee.ts:69:27)
    at Controller.start (/opt/zigbee2mqtt/lib/controller.ts:161:27)
    at start (/opt/zigbee2mqtt/index.js:154:5)
root@zigbee2mqtt:/opt/zigbee2mqtt# 

[ddfdom]

Tu as gardé le drivers ezsp
Pourquoi faire compliqué quand tout est simple
Pourquoi gâcher autant de ressources ? 2 VM pour 2 services très légers
Pourquoi ne pas utiliser docker dans une VM avec z2m et mosquitto qui te faciliterai grandement la vie

[bemo47]

ah j’avoue que c’est certainement luxueux mais je me disais que si je voulais compléter l’utilisation de ce minipc , avec proxmox ce serait sympa
et honnêtement je voulais aussi tester ce système de virtualisation dont on me parle dans les forums à chaque fois que je parle de ma config

donc j’y suis allé franco et finalement je suis pas loin d’être au bout je crois, et ça tout seul, avec quand même l’aide de pas mal de pages de forums divers et autres tutos… mais pour un noobs de linux comme moi c’est pas mal…

sinon là tu dis que j’ai gardé ezsp, mais justement ma config n’a plus ezsp mais ember, enfin j’ai bien mis adpater : ember dans le yaml

y aurait il un autre endroit ou on spécifie ember ou ezsp ?

notes que j’ai pu démarrer cette config, j’ai vu certains de mes appareils se reconnecter, donc ça semblait fonctionner, puis j’ai tout arrêté et redémarré, et c’est là que Z2M ne redémarre plus

edit :
je vois effectivement du ezsp dans le coordinator_backup.json

{
  "metadata": {
    "format": "zigpy/open-coordinator-backup",
    "version": 1,
    "source": "zigbee-herdsman@2.1.3",
    "internal": {
      "date": "2024-10-20T19:09:37.889Z",
      "ezspVersion": 13
    }
  },
  "stack_specific": {
    "ezsp": {
      "hashed_tclk": "e4a7f55ff3207d0ed64c67e7960b7d1e"
    }
  },
  "coordinator_ieee": "3845e2feff8d79e0",
  "pan_id": "5763",
  "extended_pan_id": "511951c7dcd228dd",
  "nwk_update_id": 0,
  "security_level": 5,
  "channel": 25,
  "channel_mask": [
    11,
    12,
    13,
    14,
    15,
    16,
    17,
    18,
    19,
    20,
    21,
    22,
    23,
    24,
    25,
    26
  ],
  "network_key": {
    "key": "135f5cec8accbca1b28eb194bf460642",
    "sequence_number": 0,
    "frame_counter": 16657
  },
  "devices": []
}

[ddfdom]

@bemo47

je vois effectivement du ezsp dans le coordinator_backup.json

Renommé ce fichier lors du passage a ember si tu as le backup en ezsp ça fait merder le démarrage renomme ce fichier ou supprime le en le sauvegardant

[bemo47]

idem après suppression, enfin il me semble bien l’avoir supprimé cf commande ls en fin de console

[2024-10-20 21:48:21] info:     zh:ember:uart:ash:   Out of buffers  : RX=0
[2024-10-20 21:48:21] info:     zh:ember:uart:ash:   Retry dupes     : RX=0
[2024-10-20 21:48:21] info:     zh:ember:uart:ash:   Out of sequence : RX=0
[2024-10-20 21:48:21] info:     zh:ember:uart:ash:   ACK timeouts    : RX=0
[2024-10-20 21:48:21] info:     zh:ember:uart:ash: ======== ASH stopped ========
[2024-10-20 21:48:21] error:    zh:ember:uart:ash: Failed to init port with error Error: Error Resource temporarily unavailable Cannot lock port
[2024-10-20 21:48:21] error:    z2m: Error while starting zigbee-herdsman
[2024-10-20 21:48:21] error:    z2m: Failed to start zigbee
[2024-10-20 21:48:21] error:    z2m: Check https://www.zigbee2mqtt.io/guide/installation/20_zigbee2mqtt-fails-to-start.html for possible solutions
[2024-10-20 21:48:21] error:    z2m: Exiting...
[2024-10-20 21:48:21] error:    z2m: Error: Failed to start EZSP layer with status=HOST_FATAL_ERROR.
    at EmberAdapter.initEzsp (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/src/adapter/ember/adapter/emberAdapter.ts:684:19)
    at EmberAdapter.start (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/src/adapter/ember/adapter/emberAdapter.ts:1583:24)
    at Controller.start (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/src/controller/controller.ts:137:29)
    at Zigbee.start (/opt/zigbee2mqtt/lib/zigbee.ts:69:27)
    at Controller.start (/opt/zigbee2mqtt/lib/controller.ts:161:27)
    at start (/opt/zigbee2mqtt/index.js:154:5)
root@zigbee2mqtt:/opt/zigbee2mqtt# cd data
root@zigbee2mqtt:/opt/zigbee2mqtt/data# ls
configuration.example.yaml  configuration.yaml  configuration.yaml.old  coordinator_backup.json.old  database.db  database.db.backup  log  state.json
root@zigbee2mqtt:/opt/zigbee2mqtt/data# 

dois je virer aussi database.db et state.json ?

[ddfdom]

Il n’arrive pas à se connecter au port du dongle

Dans le configuration.yml me chemin est-il bon
Vu que tu as récupéré une configuration du rpi l’a tu changé ?

[bemo47]

je l’avais récupéré avec une commande dans la vm, honnêtement je ne sais plus quelle commande, mais c’était exactement le même qu’avant

et en plus il a fonctionné avec ce yaml et donc ce chemin du port, ce n’est qu’après arrêt/relance de la vm Z2M que ça n’a plus voulu marcher

ou alors faut il que j’affecte ce port à la VM dans Proxmox ?

ici les ports vus de proxmox

Debian GNU/Linux comes with ABSOLUTELY NO WARRANTY, to the extent
permitted by applicable law.
Last login: Sun Oct 20 21:55:59 CEST 2024 on pts/0
root@mini:~# lsusb
Bus 002 Device 001: ID 1d6b:0003 Linux Foundation 3.0 root hub
Bus 001 Device 004: ID 0573:1573 Zoran Co. Personal Media Division (Nogatech) USB Audio and HID
Bus 001 Device 003: ID 0bda:c821 Realtek Semiconductor Corp. Bluetooth Radio 
Bus 001 Device 002: ID 1a86:55d4 QinHeng Electronics SONOFF Zigbee 3.0 USB Dongle Plus V2
Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
root@mini:~# 

[ddfdom]

Franchement cette installation c’est surtout une grosse galère pour toi
Bon tapes la commande ls -l /dev/serial/by-id

[bemo47]

aqhhh je crains que tu aies raison !

je constate aussi que la machine HA est bien une VM alors que les 2 autres mqtt et Z2M ce sont des containers, ça doit faire une différence je pense, notamment je ne peux pas leur affecter des usb !

ls -l /dev/serial/by-id

Last login: Sun Oct 20 21:10:40 CEST 2024 on tty1
root@zigbee2mqtt:~# ls -l /dev/serial/by-id
total 0
lrwxrwxrwx 1 root root 13 Oct 19 22:18 usb-ITEAD_SONOFF_Zigbee_3.0_USB_Dongle_Plus_V2_20231102142912-if00 -> ../../ttyACM0
root@zigbee2mqtt:~# 

[ddfdom]

Bon et bien tu vois bien ton périphérique

Maintenant il faut t’assurer que la configuration correspond bien à ce chemin

Aah encore un débutant qui a utilisé les scripts de tteck et qui du coup ne comprends pas ce qu’il a fait

Bin au moins ça gâche moins de ressources

[bemo47]

ah tu as raison je pense, c’était tteck

mais quand même ça a fonctionné une fois et après reboot ça ne fonctionne plus… donc le chemin semble bon non ?

le yaml

homeassistant: true
advanced:
  network_key:
    - 174
    - 53
    - 181
    - 56
    - 70
    - 111
    - 27
    - 45
    - 190
    - 236
    - 68
    - 33
    - 66
    - 248
    - 174
    - 67
  pan_id: 48935
  ext_pan_id:
    - 57
    - 139
    - 53
    - 21
    - 24
    - 239
    - 235
    - 173
  homeassistant_legacy_entity_attributes: false
  legacy_api: false
  legacy_availability_payload: false
  log_level: debug
  channel: 25
mqtt:
  base_topic: zigbee2mqtt
  server: mqtt://192.168.2.107:1883
  user: xxxxxx
  password: xxxxxxx
  keepalive: 60
  reject_unauthorized: true
  version: 4
serial:
  port: >-
    /dev/serial/by-id/usb-ITEAD_SONOFF_Zigbee_3.0_USB_Dongle_Plus_V2_20231102142912-if00
  adapter: ember
frontend:
  port: 8080
device_options:
  legacy: false
devices:
  '0x6c5cb1fffe9868b8':
    friendly_name: Extender Cuisine
  '0xec1bbdfffe32fe29':
    friendly_name: Interrupteur livarno salon
  '0x588e81fffefb208e':
    friendly_name: Plaff Salon
  '0xbc026efffe239340':
    friendly_name: Ext Tour
  '0xb43522fffe03e207':
    friendly_name: 'Ext Gde Chambre '
  '0xb43522fffe03f5cd':
    friendly_name: 'Ext Buanderie '
  '0xa4c13895dd877109':
    friendly_name: Prise LIDL
  '0x00124b00292f5dbf':
    friendly_name: Sonoff Salon
  '0x00124b00292f818d':
    friendly_name: Sonoff ch bm
  '0x00124b00292f617f':
    friendly_name: Sonoff Cuisine
  '0x00124b00292fbd98':
    friendly_name: Sonoff Tour Haut
  '0x00124b002fac2612':
    friendly_name: Sonoff CH Facade
  '0x00124b002fac1c85':
    friendly_name: 'Sonoff Gde Chambre '
  '0x00124b002fac2e4e':
    friendly_name: Sonoff Tour Bas
  '0x70b3d52b600aee67':
    friendly_name: 'Prise tableau '
  '0x70b3d52b600aeca8':
    friendly_name: Prise tour
  '0x70b3d52b6009d327':
    friendly_name: Prise Salle Sport
  '0x70b3d52b6009e785':
    friendly_name: Prise Pi4
availability: true
permit_join: true

[ddfdom]

Oui ça semble bon mais le message est clair
Tu n’aurais pas quelque chose d’autre qui est connecté dessus ?
Je ne vois pas pourquoi mais des fois

Tu as déjà tout rebooté ? J’imagine

[bemo47]

pas d’autres usb connectés

j’ai déjà rebooté les vm et containers

mais pas le minipc lui même ou proxmox

edit : reboot minipc en cours

et idem…

reedit :

j’ai débranché et rebranché le dongle du port usb et le message d’erreur est différent :
[2024-10-20 23:21:44] error: zh:ember:uart:ash: Failed to init port with error Error: Error: No such file or directory, cannot open /dev/serial/by-id/usb-ITEAD_SONOFF_Zigbee_3.0_USB_Dongle_Plus_V2_20231102142912-if00

alors que juste avant c’était :
[2024-10-20 23:18:21] error: zh:ember:uart:ash: Failed to init port with error Error: Error Resource temporarily unavailable Cannot lock port

mais la commande ls citée plus haut donne « total 0 » maintenant, la clé n’est plus vue

---

même en branchant le dongle dans un autre port usb, le usb3 notamment, il n’est pas vu !

---

après déconnexion dongle, reconnexion, la clé est vue à nouveau, dans le port usb3, chemin inchangé
mais au start erreur à nouveau : [2024-10-20 23:39:19] error: zh:ember:uart:ash: Failed to init port with error Error: Error Resource temporarily unavailable Cannot lock port
donc retour au point de départ

[WarC0zes]

@bemo47

après déconnexion dongle, reconnexion, la clé est vue à nouveau, dans le port usb3

Bonjour,
Ce n’est pas bon d’utiliser le port USB3 directement sur ta clé. Ça fait des interférences sur la clé Zigbee.
Utilise une rallonge USB (1/1.5m). Le mieux serait sur un port USB2 ( mais si tu n’en as pas, pas trop le choix du USB3 ).

@ClassicRed

BON A SAVOIR:

Priviligié toujours le port USB2

Priviligié une rallonge USB de 1m /1.5m

[ddfdom]

avant de débrancher rebrancher lance une commande dmesg -w ça t’affiche en live les messages de kernel mais pour ça ton conteneur LXC doit être en privileged

[pctetra]

@ddfdom

ton conteneur LXC doit être en privileged

Les conteneurs LXC en privileged avec accés root sur l’hôte, mais bon quand on sait ce qu’on fait c’est pas grave

[ddfdom]

il utilises les scripts de tteck donc il ne sais pas ce qu’il fait

Edit:
et il l’est, c’est assez logique pur accéder a l’usb

[pctetra]

il y a moyen de configurer les ports usb en unprivileged mais ça demande un peu de compétences et tteck donne la possibilité de décocher la config par défaut