zigbee2mqtt icon indicating copy to clipboard operation
zigbee2mqtt copied to clipboard

Published 20 hours ago • verified publisher icon Koenkk

Problem with SONOFF Zigbee_3.0 USB_Dongle Plus V2 (Dongle E)

Open Ant118 opened this issue 10 months ago • 18 comments

What happened?

It starts successfully, but after a while the devices stop regressing. It was disabled with an error on the regular version: "Adapter disconnected, stopping"

The latest error on the Edge version: [2024-04-19 16:15:15] debug: zh:ezsp:ezsp: ==> nop: null [2024-04-19 16:15:25] debug: zh:ezsp:ezsp: Time to watchdog ... 0 [2024-04-19 16:15:25] debug: zh:ezsp:ezsp: ==> nop: null [2024-04-19 16:15:35] debug: zh:ezsp:ezsp: Time to watchdog ... 0 [2024-04-19 16:15:35] debug: zh:ezsp:ezsp: ==> nop: null [2024-04-19 16:15:46] debug: zh:ezsp:ezsp: Time to watchdog ... 0 [2024-04-19 16:15:47] debug: zh:ezsp:ezsp: ==> nop: null [2024-04-19 16:15:56] debug: zh:ezsp:ezsp: Time to watchdog ... 0 [2024-04-19 16:15:56] debug: zh:ezsp:ezsp: ==> nop: null

Config: data_path: /config/zigbee2mqtt socat: enabled: false master: pty,raw,echo=0,link=/tmp/ttyZ2M,mode=777 slave: tcp-listen:8485,keepalive,nodelay,reuseaddr,keepidle=1,keepintvl=1,keepcnt=5 options: "-d -d" log: false mqtt: server: mqtt://core-mosquitto:1883 serial: port: >- /dev/serial/by-id/usb-ITEAD_SONOFF_Zigbee_3.0_USB_Dongle_Plus_V2_20231215111023-if00 adapter: ezsp

What did you expect to happen?

No response

How to reproduce it (minimal and precise)

No response

Zigbee2MQTT version

1.36.1-dev commit:

Adapter firmware version

6.10.3.0 build 297

Adapter

SONOFF Zigbee 3.0 USB Dongle Plus V2 (Dongle E)

Setup

Home Assistant OS 11.4, Home Assistant Core: 2023.12.3, Raspberry Pi 3-64

Debug log

No response

Ant118 avatar Apr 20 '24 12:04 Ant118

New error on Edge version: [2024-04-20 15:36:46] error: z2m: Adapter disconnected, stopping [2024-04-20 15:36:49] error: zh:ezsp:uart: --> Error: Error: {"sequence":5} after 4000ms [2024-04-20 15:36:49] error: zh:ezsp:uart: -!- break waiting (5) [2024-04-20 15:36:50] error: zh:ezsp:uart: Can't send DATA frame (4,4,0): a100010500 [2024-04-20 15:36:59] error: z2m: Failed to stop Zigbee2MQTT

Ant118 avatar Apr 20 '24 12:04 Ant118

If i set adapter: ember then:

[16:00:14] INFO: Preparing to start... [16:00:16] INFO: Socat not enabled [16:00:22] INFO: Starting Zigbee2MQTT... [2024-04-20 16:00:46] error: z2m: Error while starting zigbee-herdsman [2024-04-20 16:00:46] error: z2m: Failed to start zigbee [2024-04-20 16:00:46] error: z2m: Check https://www.zigbee2mqtt.io/guide/installation/20_zigbee2mqtt-fails-to-start.html for possible solutions [2024-04-20 16:00:46] error: z2m: Exiting... [2024-04-20 16:00:46] error: z2m: Error: NCP EZSP protocol version of 12 does not match Host version 13 at EmberAdapter.emberVersion (/app/node_modules/zigbee-herdsman/src/adapter/ember/adapter/emberAdapter.ts:1650:19) at EmberAdapter.initEzsp (/app/node_modules/zigbee-herdsman/src/adapter/ember/adapter/emberAdapter.ts:801:9) at EmberAdapter.start (/app/node_modules/zigbee-herdsman/src/adapter/ember/adapter/emberAdapter.ts:2659: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)

Ant118 avatar Apr 20 '24 13:04 Ant118

Updating your adapter should fix it

Koenkk avatar Apr 20 '24 19:04 Koenkk

Updating your adapter should fix it

Update firmware? I am use Silabs Firmware Flasher web page. I don't see a newer firmware 7.3.1.0. screenshot

Ant118 avatar Apr 21 '24 12:04 Ant118

Update to 7.4.1.0

Error: [16:11:40] INFO: Preparing to start... [16:11:44] INFO: Socat not enabled [16:11:54] INFO: Starting Zigbee2MQTT... [2024-04-21 16:12:45] error: zh:ezsp:uart: --> Error: Error: {"sequence":7} after 4000ms [2024-04-21 16:12:45] error: zh:ezsp:uart: -!- break waiting (7) [2024-04-21 16:12:46] error: zh:ezsp:uart: Can't send DATA frame (6,1,0): 3e00013400005f46040100ef0101000100000c0d05108b0b0200 [2024-04-21 16:12:50] error: zh:ezsp:uart: --> Error: Error: {"sequence":7} after 4000ms [2024-04-21 16:12:50] error: zh:ezsp:uart: -!- break rewaiting (7) [2024-04-21 16:12:50] error: zh:ezsp:uart: Can't resend DATA frame (6,1,1): 3e00013400005f46040100ef0101000100000c0d05108b0b0200 [2024-04-21 16:12:52] error: zh:controller:device: Default response to 0xa4c138f3fdae7f63 failed [2024-04-21 16:12:52] error: zh:controller:device: Default response to 0xa4c138f3fdae7f63 failed [2024-04-21 16:12:52] error: zh:controller:device: Default response to 0xa4c138f3fdae7f63 failed [2024-04-21 16:12:52] error: zh:controller:device: Default response to 0xa4c138f3fdae7f63 failed [2024-04-21 16:12:52] error: zh:controller:device: Default response to 0xa4c138f3fdae7f63 failed [2024-04-21 16:12:52] error: zh:controller:device: Default response to 0xa4c138f3fdae7f63 failed [2024-04-21 16:12:53] error: zh:ezsp:uart: <-- CRC error: c509107e|0910|6819 [2024-04-21 16:12:53] error: zh:ezsp:uart: Error while parsing to NpiFrame 'Error: <-- CRC error: c509107e|0910|6819 at Frame.checkCRC (/app/node_modules/zigbee-herdsman/src/adapter/ezsp/driver/frame.ts:87:19) at SerialDriver.onParsed (/app/node_modules/zigbee-herdsman/src/adapter/ezsp/driver/uart.ts:169:19) at Parser.emit (node:events:517:28) at Parser._transform (/app/node_modules/zigbee-herdsman/src/adapter/ezsp/driver/parser.ts:49:26) at Parser.Transform._write (node:internal/streams/transform:175:8) at writeOrBuffer (node:internal/streams/writable:392:12) at _write (node:internal/streams/writable:333:10) at Parser.Writable.write (node:internal/streams/writable:337:10) at SerialPort.ondata (node:internal/streams/readable:809:22) at SerialPort.emit (node:events:517:28)'

Ant118 avatar Apr 21 '24 13:04 Ant118

It is still working, but I have errors 45df7312_zigbee2mqtt_edge_2024-04-21T14-42-30.182Z.log

Ant118 avatar Apr 21 '24 14:04 Ant118

Device control is lost. Then stop Zigbee2mqtt. 45df7312_zigbee2mqtt_edge_2024-04-21T16-41-39.081Z.log

Ant118 avatar Apr 21 '24 16:04 Ant118

Downgrade to 6.10.3.0 build 297

[16:03:19] INFO: Preparing to start... [16:03:27] INFO: Socat not enabled [16:03:43] INFO: Starting Zigbee2MQTT... [2024-04-22 16:03:58] info: z2m: Logging to console, file (filename: log.log) [2024-04-22 16:04:17] info: z2m: Starting Zigbee2MQTT version 1.36.1-dev (commit #1544317) [2024-04-22 16:04:17] info: z2m: Starting zigbee-herdsman (0.42.2) [2024-04-22 16:04:25] info: z2m: zigbee-herdsman started (resumed) [2024-04-22 16:04:25] info: z2m: Coordinator firmware version: '{"meta":{"maintrel":"3 ","majorrel":"6","minorrel":"10","product":8,"revision":"6.10.3.0 build 297"},"type":"EZSP v8"}' [2024-04-22 16:04:25] info: z2m: Currently 3 devices are joined: [2024-04-22 16:04:25] info: z2m: ShkafLight (0x70b3d52b6007fcf0): WHD02 - TuYa Wall switch module (Router) [2024-04-22 16:04:25] info: z2m: ShkafDoor (0xa4c1381c4cc3c66b): TS0203 - TuYa Door sensor (EndDevice) [2024-04-22 16:04:25] info: z2m: 0xa4c1384cd941cba2 (0xa4c1384cd941cba2): IH012-RT01 - TuYa Motion sensor (EndDevice) [2024-04-22 16:04:25] info: z2m: Zigbee: disabling joining new devices. [2024-04-22 16:04:25] info: z2m: Connecting to MQTT server at mqtt://core-mosquitto:1883 [2024-04-22 16:04:26] info: z2m: Connected to MQTT server [2024-04-22 16:04:28] info: z2m: Started frontend on port 8099 [2024-04-22 16:04:28] info: z2m: Zigbee2MQTT started!

Ant118 avatar Apr 22 '24 13:04 Ant118

Can you try with adapter: ember?

Koenkk avatar Apr 23 '24 19:04 Koenkk

There are a lot of errors, but control over the devices is preserved after a day. The old firmware is more stable! 45df7312_zigbee2mqtt_edge_2024-04-24T07-58-53.998Z.log

Ant118 avatar Apr 24 '24 08:04 Ant118

Can you try with adapter: ember?

[11:18:16] INFO: Preparing to start... [11:18:21] INFO: Socat not enabled [11:18:32] INFO: Starting Zigbee2MQTT... [2024-04-24 11:18:52] info: z2m: Logging to console, file (filename: log.log) [2024-04-24 11:19:08] info: z2m: Starting Zigbee2MQTT version 1.36.1-dev (commit #1544317) [2024-04-24 11:19:08] info: z2m: Starting zigbee-herdsman (0.42.2) [2024-04-24 11:19:11] info: zh:ember: ======== Ember Adapter Starting ======== [2024-04-24 11:19:11] info: zh:ember:ezsp: ======== EZSP starting ======== [2024-04-24 11:19:11] info: zh:ember:uart:ash: ======== ASH NCP reset ======== [2024-04-24 11:19:11] info: zh:ember:uart:ash: RTS/CTS config is off, enabling software flow control. [2024-04-24 11:19:11] info: zh:ember:uart:ash: Serial port opened [2024-04-24 11:19:11] info: zh:ember:uart:ash: ======== ASH starting ======== [2024-04-24 11:19:12] info: zh:ember:uart:ash: ======== ASH connected ======== [2024-04-24 11:19:12] info: zh:ember:uart:ash: ======== ASH started ======== [2024-04-24 11:19:12] info: zh:ember:ezsp: ======== EZSP started ======== [2024-04-24 11:19:12] error: z2m: Error while starting zigbee-herdsman [2024-04-24 11:19:12] error: z2m: Failed to start zigbee [2024-04-24 11:19:12] error: z2m: Check https://www.zigbee2mqtt.io/guide/installation/20_zigbee2mqtt-fails-to-start.html for possible solutions [2024-04-24 11:19:12] error: z2m: Exiting... [2024-04-24 11:19:13] error: z2m: Error: NCP EZSP protocol version of 8 does not match Host version 13 at EmberAdapter.emberVersion (/app/node_modules/zigbee-herdsman/src/adapter/ember/adapter/emberAdapter.ts:1650:19) at EmberAdapter.initEzsp (/app/node_modules/zigbee-herdsman/src/adapter/ember/adapter/emberAdapter.ts:801:9) at EmberAdapter.start (/app/node_modules/zigbee-herdsman/src/adapter/ember/adapter/emberAdapter.ts:2659: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)

Ant118 avatar Apr 24 '24 08:04 Ant118

You need to update your firmware to 7.4.1

Koenkk avatar Apr 25 '24 19:04 Koenkk

You need to update your firmware to 7.4.1

I already tried it, there is an error log in the message above. It breaks down very quickly. I want to try to backup and update Home Assistant tomorrow

Ant118 avatar Apr 25 '24 19:04 Ant118

Hi, after every update I have to change port: >- /dev/serial/by-id/usb-ITEAD_SONOFF_Zigbee_3.0_USB_Dongle_Plus_V2_20231215111023-if00 to port: /dev/serial/by-id/usb-ITEAD_SONOFF_Zigbee_3.0_USB_Dongle_Plus_V2_20231215111023-if00 Regards

ds-106 avatar Apr 26 '24 11:04 ds-106

You need to update your firmware to 7.4.1

Ok: screen14

screen15

Testing ember driver

Ant118 avatar Apr 28 '24 10:04 Ant118

Hi, after every update I have to change port: >- /dev/serial/by-id/usb-ITEAD_SONOFF_Zigbee_3.0_USB_Dongle_Plus_V2_20231215111023-if00 to port: /dev/serial/by-id/usb-ITEAD_SONOFF_Zigbee_3.0_USB_Dongle_Plus_V2_20231215111023-if00 Regards

If I delete the add-ons in the configuration, click save - it appears again ">-" I tried to edit config/zigbee2mqtt/configuration in the file manager.yaml, then rebooted the Home Assistant. But today I have a crash again.

Ant118 avatar Apr 29 '24 09:04 Ant118

"zonestatus","type":33},{"name":"extendedstatus","type":32}],"name":"statusChangeNotification"}} [2024-04-28 22:38:02] debug: zh:controller:endpoint: ZCL command 0xa4c1384cd941cba2/1 ssIasZone.defaultRsp({"cmdId":0,"statusCode":0}, {"timeout":10000,"disableResponse":false,"disableRecovery":false,"disableDefaultResponse":true,"direction":0,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":121,"writeUndiv":false}) [2024-04-28 22:38:02] debug: zh:ember:queue: Status queue=0 priorityQueue=0. [2024-04-28 22:38:02] debug: z2m: Received Zigbee message from '0xa4c1384cd941cba2', type 'commandStatusChangeNotification', cluster 'ssIasZone', data '{"extendedstatus":0,"zonestatus":1}' from endpoint 1 with groupID 0 [2024-04-28 22:38:02] debug: z2m: MQTT publish: topic 'zigbee2mqtt/0xa4c1384cd941cba2', payload '{"battery":100,"battery_low":false,"keep_time":30,"linkquality":144,"occupancy":true,"sensitivity":"medium","tamper":false,"voltage":2900}' [2024-04-28 22:38:02] debug: zh:ember: ~~~> [ZCL to=65410 apsFrame={"profileId":260,"clusterId":1280,"sourceEndpoint":1,"destinationEndpoint":1,"options":4352,"groupId":0,"sequence":0} header={"frameControl":{"reservedBits":0,"frameType":0,"direction":0,"disableDefaultResponse":true,"manufacturerSpecific":false},"manufacturerCode":null,"transactionSequenceNumber":121,"commandIdentifier":11}] [2024-04-28 22:38:02] debug: zh:ember:ezsp: ===> [FRAME: ID=52:"SEND_UNICAST" Seq=38 Len=26] [2024-04-28 22:38:02] debug: zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=6 frmRx=1] [2024-04-28 22:38:02] debug: zh:ember:uart:ash: <--- [FRAME type=DATA] [2024-04-28 22:38:02] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=7] [2024-04-28 22:38:02] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=7 frmNum=1] Added to rxQueue [2024-04-28 22:38:02] debug: zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=2] [2024-04-28 22:38:02] debug: zh:ember:ezsp: <=== [FRAME: ID=52:"SEND_UNICAST" Seq=38 Len=7] [2024-04-28 22:38:02] debug: zh:ember:ezsp: ~~~> [SENT type=DIRECT apsSequence=234 messageTag=109 status=SUCCESS] [2024-04-28 22:38:02] debug: zh:ember:uart:ash: <--- [FRAME type=DATA] [2024-04-28 22:38:02] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=7] [2024-04-28 22:38:02] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=7 frmNum=2] Added to rxQueue [2024-04-28 22:38:02] debug: zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=3] [2024-04-28 22:38:02] debug: zh:ember:ezsp: <=== [FRAME: ID=63:"MESSAGE_SENT_HANDLER" Seq=38 Len=27] [2024-04-28 22:38:02] debug: zh:ember:ezsp: ezspMessageSentHandler(): callback called with: [type=DIRECT], [indexOrDestination=65410], [apsFrame={"profileId":260,"clusterId":1280,"sourceEndpoint":1,"destinationEndpoint":1,"options":4352,"groupId":0,"sequence":234}], [messageTag=109], [status=SUCCESS], [messageContents=10790b0000] [2024-04-28 22:38:20] debug: zh:ember:uart:ash: <--- [FRAME type=DATA] [2024-04-28 22:38:20] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=7] [2024-04-28 22:38:20] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=7 frmNum=3] Added to rxQueue [2024-04-28 22:38:20] debug: zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=4] [2024-04-28 22:38:20] debug: zh:ember:ezsp: <=== [FRAME: ID=69:"INCOMING_MESSAGE_HANDLER" Seq=38 Len=34] [2024-04-28 22:38:20] debug: zh:ember:ezsp: ezspIncomingMessageHandler(): callback called with: [type=UNICAST], [apsFrame={"profileId":260,"clusterId":1280,"sourceEndpoint":1,"destinationEndpoint":1,"options":256,"groupId":0,"sequence":27}], [lastHopLqi=148], [lastHopRssi=193], [sender=65410], [bindingIndex=255], [addressIndex=255], [messageContents=097a00000000170000] [2024-04-28 22:38:20] debug: zh:controller: Received payload: clusterID=1280, address=65410, groupID=0, endpoint=1, destinationEndpoint=1, wasBroadcast=false, linkQuality=148, frame={"header":{"frameControl":{"frameType":1,"manufacturerSpecific":false,"direction":1,"disableDefaultResponse":false,"reservedBits":0},"manufacturerCode":null,"transactionSequenceNumber":122,"commandIdentifier":0},"payload":{"zonestatus":0,"extendedstatus":0},"command":{"ID":0,"parameters":[{"name":"zonestatus","type":33},{"name":"extendedstatus","type":32}],"name":"statusChangeNotification"}} [2024-04-28 22:38:20] debug: zh:controller:endpoint: ZCL command 0xa4c1384cd941cba2/1 ssIasZone.defaultRsp({"cmdId":0,"statusCode":0}, {"timeout":10000,"disableResponse":false,"disableRecovery":false,"disableDefaultResponse":true,"direction":0,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":122,"writeUndiv":false}) [2024-04-28 22:38:20] debug: zh:ember:queue: Status queue=0 priorityQueue=0. [2024-04-28 22:38:20] debug: z2m: Received Zigbee message from '0xa4c1384cd941cba2', type 'commandStatusChangeNotification', cluster 'ssIasZone', data '{"extendedstatus":0,"zonestatus":0}' from endpoint 1 with groupID 0 [2024-04-28 22:38:20] debug: z2m: MQTT publish: topic 'zigbee2mqtt/0xa4c1384cd941cba2', payload '{"battery":100,"battery_low":false,"keep_time":30,"linkquality":148,"occupancy":false,"sensitivity":"medium","tamper":false,"voltage":2900}' [2024-04-28 22:38:20] debug: zh:ember: ~~~> [ZCL to=65410 apsFrame={"profileId":260,"clusterId":1280,"sourceEndpoint":1,"destinationEndpoint":1,"options":4352,"groupId":0,"sequence":0} header={"frameControl":{"reservedBits":0,"frameType":0,"direction":0,"disableDefaultResponse":true,"manufacturerSpecific":false},"manufacturerCode":null,"transactionSequenceNumber":122,"commandIdentifier":11}] [2024-04-28 22:38:20] debug: zh:ember:ezsp: ===> [FRAME: ID=52:"SEND_UNICAST" Seq=39 Len=26] [2024-04-28 22:38:20] debug: zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=7 frmRx=4] [2024-04-28 22:38:20] debug: zh:ember:uart:ash: <--- [FRAME type=DATA] [2024-04-28 22:38:20] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=0] [2024-04-28 22:38:20] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=0 frmNum=4] Added to rxQueue [2024-04-28 22:38:20] debug: zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=5] [2024-04-28 22:38:20] debug: zh:ember:ezsp: <=== [FRAME: ID=52:"SEND_UNICAST" Seq=39 Len=7] [2024-04-28 22:38:20] debug: zh:ember:ezsp: ~~~> [SENT type=DIRECT apsSequence=235 messageTag=110 status=SUCCESS] [2024-04-28 22:38:20] debug: zh:ember:uart:ash: <--- [FRAME type=DATA] [2024-04-28 22:38:20] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=0] [2024-04-28 22:38:20] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=0 frmNum=5] Added to rxQueue [2024-04-28 22:38:20] debug: zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=6] [2024-04-28 22:38:20] debug: zh:ember:ezsp: <=== [FRAME: ID=63:"MESSAGE_SENT_HANDLER" Seq=39 Len=27] [2024-04-28 22:38:20] debug: zh:ember:ezsp: ezspMessageSentHandler(): callback called with: [type=DIRECT], [indexOrDestination=65410], [apsFrame={"profileId":260,"clusterId":1280,"sourceEndpoint":1,"destinationEndpoint":1,"options":4352,"groupId":0,"sequence":235}], [messageTag=110], [status=SUCCESS], [messageContents=107a0b0000] [2024-04-28 22:39:05] debug: z2m: Saving state to file /config/zigbee2mqtt/state.json [2024-04-28 22:39:07] debug: zh:ember:uart:ash: <--- [FRAME type=DATA] [2024-04-28 22:39:07] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=0] [2024-04-28 22:39:07] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=0 frmNum=6] Added to rxQueue [2024-04-28 22:39:07] debug: zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=7] [2024-04-28 22:39:07] debug: zh:ember:ezsp: <=== [FRAME: ID=89:"INCOMING_ROUTE_RECORD_HANDLER" Seq=39 Len=18] [2024-04-28 22:39:07] debug: zh:ember:ezsp: ezspIncomingRouteRecordHandler(): callback called with: [source=58606], [sourceEui=0x70b3d52b6007fcf0], [lastHopLqi=144], [lastHopRssi=192], [relayCount=0], [relayList=] [2024-04-28 22:39:07] debug: zh:ember:uart:ash: <--- [FRAME type=DATA] [2024-04-28 22:39:07] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=0] [2024-04-28 22:39:07] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=0 frmNum=7] Added to rxQueue [2024-04-28 22:39:07] debug: zh:ember:uart:ash: <--- [FRAME type=DATA] [2024-04-28 22:39:07] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=0] [2024-04-28 22:39:07] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=0 frmNum=0] Added to rxQueue [2024-04-28 22:39:07] debug: zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=1] [2024-04-28 22:39:07] debug: zh:ember:ezsp: <=== [FRAME: ID=98:"INCOMING_SENDER_EUI64_HANDLER" Seq=39 Len=13] [2024-04-28 22:39:07] debug: zh:ember:ezsp: ezspIncomingSenderEui64Handler(): callback called with: [senderEui64=0x70b3d52b6007fcf0] [2024-04-28 22:39:07] debug: zh:ember:ezsp: <=== [FRAME: ID=69:"INCOMING_MESSAGE_HANDLER" Seq=39 Len=32] [2024-04-28 22:39:07] debug: zh:ember:ezsp: ezspIncomingMessageHandler(): callback called with: [type=UNICAST], [apsFrame={"profileId":260,"clusterId":0,"sourceEndpoint":1,"destinationEndpoint":1,"options":3328,"groupId":0,"sequence":175}], [lastHopLqi=144], [lastHopRssi=192], [sender=58606], [bindingIndex=255], [addressIndex=255], [messageContents=181c0a01002064] [2024-04-28 22:39:07] debug: zh:controller: Received payload: clusterID=0, address=58606, groupID=0, endpoint=1, destinationEndpoint=1, wasBroadcast=false, linkQuality=144, frame={"header":{"frameControl":{"frameType":0,"manufacturerSpecific":false,"direction":1,"disableDefaultResponse":true,"reservedBits":0},"manufacturerCode":null,"transactionSequenceNumber":28,"commandIdentifier":10},"payload":[{"attrId":1,"dataType":32,"attrData":100}],"command":{"ID":10,"name":"report","parameters":[{"name":"attrId","type":33},{"name":"dataType","type":32},{"name":"attrData","type":1000}]}} [2024-04-28 22:39:07] debug: z2m: Received Zigbee message from 'ShkafLight', type 'attributeReport', cluster 'genBasic', data '{"appVersion":100}' from endpoint 1 with groupID 0 [2024-04-28 22:44:05] debug: z2m: Saving state to file /config/zigbee2mqtt/state.json [2024-04-28 22:45:03] debug: zh:ember:uart:ash: <--- [FRAME type=DATA] [2024-04-28 22:45:03] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=0] [2024-04-28 22:45:03] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=0 frmNum=1] Added to rxQueue [2024-04-28 22:45:03] debug: zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=2] [2024-04-28 22:45:03] debug: zh:ember:ezsp: <=== [FRAME: ID=89:"INCOMING_ROUTE_RECORD_HANDLER" Seq=39 Len=18] [2024-04-28 22:45:03] debug: zh:ember:ezsp: ezspIncomingRouteRecordHandler(): callback called with: [source=58606], [sourceEui=0x70b3d52b6007fcf0], [lastHopLqi=148], [lastHopRssi=193], [relayCount=0], [relayList=] [2024-04-28 22:45:03] debug: zh:ember:uart:ash: <--- [FRAME type=DATA] [2024-04-28 22:45:03] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=0] [2024-04-28 22:45:03] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=0 frmNum=2] Added to rxQueue [2024-04-28 22:45:03] debug: zh:ember:uart:ash: <--- [FRAME type=DATA] [2024-04-28 22:45:03] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=0] [2024-04-28 22:45:03] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=0 frmNum=3] Added to rxQueue [2024-04-28 22:45:03] debug: zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=4] [2024-04-28 22:45:03] debug: zh:ember:ezsp: <=== [FRAME: ID=98:"INCOMING_SENDER_EUI64_HANDLER" Seq=39 Len=13] [2024-04-28 22:45:03] debug: zh:ember:ezsp: ezspIncomingSenderEui64Handler(): callback called with: [senderEui64=0x70b3d52b6007fcf0] [2024-04-28 22:45:03] debug: zh:ember:ezsp: <=== [FRAME: ID=69:"INCOMING_MESSAGE_HANDLER" Seq=39 Len=32] [2024-04-28 22:45:03] debug: zh:ember:ezsp: ezspIncomingMessageHandler(): callback called with: [type=UNICAST], [apsFrame={"profileId":260,"clusterId":0,"sourceEndpoint":1,"destinationEndpoint":1,"options":3328,"groupId":0,"sequence":176}], [lastHopLqi=112], [lastHopRssi=184], [sender=58606], [bindingIndex=255], [addressIndex=255], [messageContents=181d0a01002064] [2024-04-28 22:45:03] debug: zh:controller: Received payload: clusterID=0, address=58606, groupID=0, endpoint=1, destinationEndpoint=1, wasBroadcast=false, linkQuality=112, frame={"header":{"frameControl":{"frameType":0,"manufacturerSpecific":false,"direction":1,"disableDefaultResponse":true,"reservedBits":0},"manufacturerCode":null,"transactionSequenceNumber":29,"commandIdentifier":10},"payload":[{"attrId":1,"dataType":32,"attrData":100}],"command":{"ID":10,"name":"report","parameters":[{"name":"attrId","type":33},{"name":"dataType","type":32},{"name":"attrData","type":1000}]}} [2024-04-28 22:45:03] debug: z2m: Received Zigbee message from 'ShkafLight', type 'attributeReport', cluster 'genBasic', data '{"appVersion":100}' from endpoint 1 with groupID 0 [2024-04-28 22:49:05] debug: z2m: Saving state to file /config/zigbee2mqtt/state.json [2024-04-28 22:50:15] debug: zh:ember:uart:ash: <--- [FRAME type=DATA] [2024-04-28 22:50:15] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=0] [2024-04-28 22:50:15] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=0 frmNum=4] Added to rxQueue [2024-04-28 22:50:15] debug: zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=5] [2024-04-28 22:50:15] debug: zh:ember:ezsp: <=== [FRAME: ID=89:"INCOMING_ROUTE_RECORD_HANDLER" Seq=39 Len=18] [2024-04-28 22:50:15] debug: zh:ember:ezsp: ezspIncomingRouteRecordHandler(): callback called with: [source=58606], [sourceEui=0x70b3d52b6007fcf0], [lastHopLqi=148], [lastHopRssi=193], [relayCount=0], [relayList=] [2024-04-28 22:50:15] debug: zh:ember:uart:ash: <--- [FRAME type=DATA] [2024-04-28 22:50:15] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=0] [2024-04-28 22:50:15] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=0 frmNum=5] Added to rxQueue [2024-04-28 22:50:15] debug: zh:ember:uart:ash: <--- [FRAME type=DATA] [2024-04-28 22:50:15] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=0] [2024-04-28 22:50:15] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=0 frmNum=6] Added to rxQueue [2024-04-28 22:50:15] debug: zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=7] [2024-04-28 22:50:15] debug: zh:ember:ezsp: <=== [FRAME: ID=98:"INCOMING_SENDER_EUI64_HANDLER" Seq=39 Len=13] [2024-04-28 22:50:15] debug: zh:ember:ezsp: ezspIncomingSenderEui64Handler(): callback called with: [senderEui64=0x70b3d52b6007fcf0] [2024-04-28 22:50:15] debug: zh:ember:ezsp: <=== [FRAME: ID=69:"INCOMING_MESSAGE_HANDLER" Seq=39 Len=32] [2024-04-28 22:50:15] debug: zh:ember:ezsp: ezspIncomingMessageHandler(): callback called with: [type=UNICAST], [apsFrame={"profileId":260,"clusterId":0,"sourceEndpoint":1,"destinationEndpoint":1,"options":3328,"groupId":0,"sequence":177}], [lastHopLqi=152], [lastHopRssi=194], [sender=58606], [bindingIndex=255], [addressIndex=255], [messageContents=181e0a01002064] [2024-04-28 22:50:15] debug: zh:controller: Received payload: clusterID=0, address=58606, groupID=0, endpoint=1, destinationEndpoint=1, wasBroadcast=false, linkQuality=152, frame={"header":{"frameControl":{"frameType":0,"manufacturerSpecific":false,"direction":1,"disableDefaultResponse":true,"reservedBits":0},"manufacturerCode":null,"transactionSequenceNumber":30,"commandIdentifier":10},"payload":[{"attrId":1,"dataType":32,"attrData":100}],"command":{"ID":10,"name":"report","parameters":[{"name":"attrId","type":33},{"name":"dataType","type":32},{"name":"attrData","type":1000}]}} [2024-04-28 22:50:15] debug: z2m: Received Zigbee message from 'ShkafLight', type 'attributeReport', cluster 'genBasic', data '{"appVersion":100}' from endpoint 1 with groupID 0 [2024-04-28 22:54:05] debug: z2m: Saving state to file /config/zigbee2mqtt/state.json [2024-04-28 22:55:34] debug: zh:ember:uart:ash: <--- [FRAME type=DATA] [2024-04-28 22:55:34] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=0] [2024-04-28 22:55:34] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=0 frmNum=7] Added to rxQueue [2024-04-28 22:55:34] debug: zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=0] [2024-04-28 22:55:34] debug: zh:ember:ezsp: <=== [FRAME: ID=89:"INCOMING_ROUTE_RECORD_HANDLER" Seq=39 Len=18] [2024-04-28 22:55:34] debug: zh:ember:ezsp: ezspIncomingRouteRecordHandler(): callback called with: [source=58606], [sourceEui=0x70b3d52b6007fcf0], [lastHopLqi=144], [lastHopRssi=192], [relayCount=0], [relayList=] [2024-04-28 22:55:34] debug: zh:ember:uart:ash: <--- [FRAME type=DATA] [2024-04-28 22:55:34] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=0] [2024-04-28 22:55:34] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=0 frmNum=0] Added to rxQueue [2024-04-28 22:55:34] debug: zh:ember:uart:ash: <--- [FRAME type=DATA] [2024-04-28 22:55:34] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=0] [2024-04-28 22:55:34] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=0 frmNum=1] Added to rxQueue [2024-04-28 22:55:34] debug: zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=2] [2024-04-28 22:55:34] debug: zh:ember:ezsp: <=== [FRAME: ID=98:"INCOMING_SENDER_EUI64_HANDLER" Seq=39 Len=13] [2024-04-28 22:55:34] debug: zh:ember:ezsp: ezspIncomingSenderEui64Handler(): callback called with: [senderEui64=0x70b3d52b6007fcf0] [2024-04-28 22:55:34] debug: zh:ember:ezsp: <=== [FRAME: ID=69:"INCOMING_MESSAGE_HANDLER" Seq=39 Len=32] [2024-04-28 22:55:34] debug: zh:ember:ezsp: ezspIncomingMessageHandler(): callback called with: [type=UNICAST], [apsFrame={"profileId":260,"clusterId":0,"sourceEndpoint":1,"destinationEndpoint":1,"options":3328,"groupId":0,"sequence":178}], [lastHopLqi=140], [lastHopRssi=191], [sender=58606], [bindingIndex=255], [addressIndex=255], [messageContents=181f0a01002064] [2024-04-28 22:55:34] debug: zh:controller: Received payload: clusterID=0, address=58606, groupID=0, endpoint=1, destinationEndpoint=1, wasBroadcast=false, linkQuality=140, frame={"header":{"frameControl":{"frameType":0,"manufacturerSpecific":false,"direction":1,"disableDefaultResponse":true,"reservedBits":0},"manufacturerCode":null,"transactionSequenceNumber":31,"commandIdentifier":10},"payload":[{"attrId":1,"dataType":32,"attrData":100}],"command":{"ID":10,"name":"report","parameters":[{"name":"attrId","type":33},{"name":"dataType","type":32},{"name":"attrData","type":1000}]}} [2024-04-28 22:55:34] debug: z2m: Received Zigbee message from 'ShkafLight', type 'attributeReport', cluster 'genBasic', data '{"appVersion":100}' from endpoint 1 with groupID 0 [2024-04-28 22:59:05] debug: z2m: Saving state to file /config/zigbee2mqtt/state.json [2024-04-28 23:01:32] debug: zh:ember:uart:ash: <--- [FRAME type=DATA] [2024-04-28 23:01:32] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=0] [2024-04-28 23:01:32] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=0 frmNum=2] Added to rxQueue [2024-04-28 23:01:32] debug: zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=3] [2024-04-28 23:01:32] debug: zh:ember:ezsp: <=== [FRAME: ID=89:"INCOMING_ROUTE_RECORD_HANDLER" Seq=39 Len=18] [2024-04-28 23:01:32] debug: zh:ember:ezsp: ezspIncomingRouteRecordHandler(): callback called with: [source=58606], [sourceEui=0x70b3d52b6007fcf0], [lastHopLqi=144], [lastHopRssi=192], [relayCount=0], [relayList=] [2024-04-28 23:01:32] debug: zh:ember:uart:ash: <--- [FRAME type=DATA] [2024-04-28 23:01:32] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=0] [2024-04-28 23:01:32] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=0 frmNum=3] Added to rxQueue [2024-04-28 23:01:32] debug: zh:ember:uart:ash: <--- [FRAME type=DATA] [2024-04-28 23:01:32] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=0] [2024-04-28 23:01:32] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=0 frmNum=4] Added to rxQueue [2024-04-28 23:01:32] debug: zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=5] [2024-04-28 23:01:33] debug: zh:ember:ezsp: <=== [FRAME: ID=98:"INCOMING_SENDER_EUI64_HANDLER" Seq=39 Len=13] [2024-04-28 23:01:33] debug: zh:ember:ezsp: ezspIncomingSenderEui64Handler(): callback called with: [senderEui64=0x70b3d52b6007fcf0] [2024-04-28 23:01:33] debug: zh:ember:ezsp: <=== [FRAME: ID=69:"INCOMING_MESSAGE_HANDLER" Seq=39 Len=32] [2024-04-28 23:01:33] debug: zh:ember:ezsp: ezspIncomingMessageHandler(): callback called with: [type=UNICAST], [apsFrame={"profileId":260,"clusterId":0,"sourceEndpoint":1,"destinationEndpoint":1,"options":3328,"groupId":0,"sequence":179}], [lastHopLqi=144], [lastHopRssi=192], [sender=58606], [bindingIndex=255], [addressIndex=255], [messageContents=18200a01002064] [2024-04-28 23:01:33] debug: zh:controller: Received payload: clusterID=0, address=58606, groupID=0, endpoint=1, destinationEndpoint=1, wasBroadcast=false, linkQuality=144, frame={"header":{"frameControl":{"frameType":0,"manufacturerSpecific":false,"direction":1,"disableDefaultResponse":true,"reservedBits":0},"manufacturerCode":null,"transactionSequenceNumber":32,"commandIdentifier":10},"payload":[{"attrId":1,"dataType":32,"attrData":100}],"command":{"ID":10,"name":"report","parameters":[{"name":"attrId","type":33},{"name":"dataType","type":32},{"name":"attrData","type":1000}]}} [2024-04-28 23:01:33] debug: z2m: Received Zigbee message from 'ShkafLight', type 'attributeReport', cluster 'genBasic', data '{"appVersion":100}' from endpoint 1 with groupID 0 [2024-04-28 23:02:08] debug: zh:ember:uart:ash: <--- [FRAME type=DATA] [2024-04-28 23:02:08] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=0] [2024-04-28 23:02:08] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=0 frmNum=5] Added to rxQueue [2024-04-28 23:02:08] debug: zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=6] [2024-04-28 23:02:08] debug: zh:ember:ezsp: <=== [FRAME: ID=69:"INCOMING_MESSAGE_HANDLER" Seq=39 Len=34] [2024-04-28 23:02:08] debug: zh:ember:ezsp: ezspIncomingMessageHandler(): callback called with: [type=UNICAST], [apsFrame={"profileId":260,"clusterId":1280,"sourceEndpoint":1,"destinationEndpoint":1,"options":256,"groupId":0,"sequence":28}], [lastHopLqi=148], [lastHopRssi=193], [sender=65410], [bindingIndex=255], [addressIndex=255], [messageContents=097b00010000170000] [2024-04-28 23:02:08] debug: zh:controller: Received payload: clusterID=1280, address=65410, groupID=0, endpoint=1, destinationEndpoint=1, wasBroadcast=false, linkQuality=148, frame={"header":{"frameControl":{"frameType":1,"manufacturerSpecific":false,"direction":1,"disableDefaultResponse":false,"reservedBits":0},"manufacturerCode":null,"transactionSequenceNumber":123,"commandIdentifier":0},"payload":{"zonestatus":1,"extendedstatus":0},"command":{"ID":0,"parameters":[{"name":"zonestatus","type":33},{"name":"extendedstatus","type":32}],"name":"statusChangeNotification"}} [2024-04-28 23:02:08] debug: zh:controller:endpoint: ZCL command 0xa4c1384cd941cba2/1 ssIasZone.defaultRsp({"cmdId":0,"statusCode":0}, {"timeout":10000,"disableResponse":false,"disableRecovery":false,"disableDefaultResponse":true,"direction":0,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":123,"writeUndiv":false}) [2024-04-28 23:02:09] debug: zh:ember:queue: Status queue=0 priorityQueue=0. [2024-04-28 23:02:09] debug: z2m: Received Zigbee message from '0xa4c1384cd941cba2', type 'commandStatusChangeNotification', cluster 'ssIasZone', data '{"extendedstatus":0,"zonestatus":1}' from endpoint 1 with groupID 0 [2024-04-28 23:02:09] debug: z2m: MQTT publish: topic 'zigbee2mqtt/0xa4c1384cd941cba2', payload '{"battery":100,"battery_low":false,"keep_time":30,"linkquality":148,"occupancy":true,"sensitivity":"medium","tamper":false,"voltage":2900}' [2024-04-28 23:02:09] debug: zh:ember: ~~~> [ZCL to=65410 apsFrame={"profileId":260,"clusterId":1280,"sourceEndpoint":1,"destinationEndpoint":1,"options":4352,"groupId":0,"sequence":0} header={"frameControl":{"reservedBits":0,"frameType":0,"direction":0,"disableDefaultResponse":true,"manufacturerSpecific":false},"manufacturerCode":null,"transactionSequenceNumber":123,"commandIdentifier":11}] [2024-04-28 23:02:09] debug: zh:ember:ezsp: ===> [FRAME: ID=52:"SEND_UNICAST" Seq=40 Len=26] [2024-04-28 23:02:09] debug: zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=0 frmRx=6] [2024-04-28 23:02:09] debug: zh:ember:uart:ash: <--- [FRAME type=DATA] [2024-04-28 23:02:09] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=1] [2024-04-28 23:02:09] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=1 frmNum=6] Added to rxQueue [2024-04-28 23:02:09] debug: zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=7] [2024-04-28 23:02:09] debug: zh:ember:ezsp: <=== [FRAME: ID=52:"SEND_UNICAST" Seq=40 Len=7] [2024-04-28 23:02:09] debug: zh:ember:ezsp: ~~~> [SENT type=DIRECT apsSequence=236 messageTag=111 status=SUCCESS] [2024-04-28 23:02:09] debug: zh:ember:uart:ash: <--- [FRAME type=DATA] [2024-04-28 23:02:09] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=1] [2024-04-28 23:02:09] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=1 frmNum=7] Added to rxQueue [2024-04-28 23:02:09] debug: zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=0] [2024-04-28 23:02:09] debug: zh:ember:ezsp: <=== [FRAME: ID=63:"MESSAGE_SENT_HANDLER" Seq=40 Len=27] [2024-04-28 23:02:09] debug: zh:ember:ezsp: ezspMessageSentHandler(): callback called with: [type=DIRECT], [indexOrDestination=65410], [apsFrame={"profileId":260,"clusterId":1280,"sourceEndpoint":1,"destinationEndpoint":1,"options":4352,"groupId":0,"sequence":236}], [messageTag=111], [status=SUCCESS], [messageContents=107b0b0000] [2024-04-28 23:02:09] debug: zh:ember:uart:ash: <--- [FRAME type=DATA] [2024-04-28 23:02:09] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=1] [2024-04-28 23:02:10] debug: zh:ember:uart:ash: <--- [FRAME type=DATA] [2024-04-28 23:02:10] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=1] [2024-04-28 23:02:11] debug: zh:ember:uart:ash: <--- [FRAME type=DATA] [2024-04-28 23:02:11] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=1] [2024-04-28 23:02:15] debug: zh:ember:uart:ash: <--- [FRAME type=ERROR] [2024-04-28 23:02:15] error: zh:ember:uart:ash: Received ERROR from NCP, with code=ERROR_EXCEEDED_MAXIMUM_ACK_TIMEOUT_COUNT. [2024-04-28 23:02:15] error: zh:ember:uart:ash: ASH disconnected | NCP status: ASH_NCP_FATAL_ERROR [2024-04-28 23:02:15] debug: zh:ember:uart:ash: Error while parsing received frame in NOT_CONNECTED state (flags=0), status=ASH_NCP_FATAL_ERROR. [2024-04-28 23:02:27] debug: zh:ember:uart:ash: Error while parsing received frame in NOT_CONNECTED state (flags=0), status=ASH_NCP_FATAL_ERROR. [2024-04-28 23:02:27] debug: zh:ember:uart:ash: Error while parsing received frame in NOT_CONNECTED state (flags=0), status=ASH_NCP_FATAL_ERROR. [2024-04-28 23:03:20] debug: zh:ember:uart:ash: Error while parsing received frame in NOT_CONNECTED state (flags=0), status=ASH_NCP_FATAL_ERROR. [2024-04-28 23:03:38] debug: zh:ember:uart:ash: Error while parsing received frame in NOT_CONNECTED state (flags=0), status=ASH_NCP_FATAL_ERROR. [2024-04-28 23:04:05] debug: z2m: Saving state to file /config/zigbee2mqtt/state.json [2024-04-28 23:09:05] debug: z2m: Saving state to file /config/zigbee2mqtt/state.json [2024-04-28 23:11:34] debug: zh:controller:endpoint: ZCL command 0x70b3d52b6007fcf0/1 genBasic.read(["zclVersion"], {"timeout":10000,"disableResponse":false,"disableRecovery":true,"disableDefaultResponse":true,"direction":0,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":null,"writeUndiv":false}) [2024-04-28 23:11:34] debug: zh:ember:queue: Status queue=0 priorityQueue=0. [2024-04-28 23:11:34] debug: zh:ember: ~~~> [ZCL to=58606 apsFrame={"profileId":260,"clusterId":0,"sourceEndpoint":1,"destinationEndpoint":1,"options":4416,"groupId":0,"sequence":0} header={"frameControl":{"reservedBits":0,"frameType":0,"direction":0,"disableDefaultResponse":true,"manufacturerSpecific":false},"manufacturerCode":null,"transactionSequenceNumber":14,"commandIdentifier":0}] [2024-04-28 23:11:34] debug: zh:ember:ezsp: [SEND COMMAND] NOT CONNECTED [2024-04-28 23:11:34] debug: zh:ember:queue: Dispatching deferred: Network not ready [2024-04-28 23:11:34] debug: zh:ember:queue: Dispatching stopped; queue=1 priorityQueue=0 [2024-04-28 23:11:35] debug: zh:ember:queue: Dispatching started. [2024-04-28 23:11:35] debug: zh:ember: ~~~> [ZCL to=58606 apsFrame={"profileId":260,"clusterId":0,"sourceEndpoint":1,"destinationEndpoint":1,"options":4416,"groupId":0,"sequence":0} header={"frameControl":{"reservedBits":0,"frameType":0,"direction":0,"disableDefaultResponse":true,"manufacturerSpecific":false},"manufacturerCode":null,"transactionSequenceNumber":14,"commandIdentifier":0}] [2024-04-28 23:11:35] error: zh:ember:ezsp: [SEND COMMAND] Cannot send second one before processing response from first one. [2024-04-28 23:11:36] debug: zh:controller:endpoint: ZCL command 0x70b3d52b6007fcf0/1 genBasic.read(["zclVersion"], {"timeout":10000,"disableResponse":false,"disableRecovery":true,"disableDefaultResponse":true,"direction":0,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":null,"writeUndiv":false}) failed (ERROR_INVALID_CALL) [2024-04-28 23:11:36] warning: z2m: Failed to ping 'ShkafLight' (attempt 1/2, ZCL command 0x70b3d52b6007fcf0/1 genBasic.read(["zclVersion"], {"timeout":10000,"disableResponse":false,"disableRecovery":true,"disableDefaultResponse":true,"direction":0,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":null,"writeUndiv":false}) failed (ERROR_INVALID_CALL)) [2024-04-28 23:11:39] debug: zh:controller:endpoint: ZCL command 0x70b3d52b6007fcf0/1 genBasic.read(["zclVersion"], {"timeout":10000,"disableResponse":false,"disableRecovery":false,"disableDefaultResponse":true,"direction":0,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":null,"writeUndiv":false}) [2024-04-28 23:11:39] debug: zh:ember:queue: Status queue=0 priorityQueue=0. [2024-04-28 23:11:39] debug: zh:ember: ~~~> [ZCL to=58606 apsFrame={"profileId":260,"clusterId":0,"sourceEndpoint":1,"destinationEndpoint":1,"options":4416,"groupId":0,"sequence":0} header={"frameControl":{"reservedBits":0,"frameType":0,"direction":0,"disableDefaultResponse":true,"manufacturerSpecific":false},"manufacturerCode":null,"transactionSequenceNumber":15,"commandIdentifier":0}] [2024-04-28 23:11:39] error: zh:ember:ezsp: [SEND COMMAND] Cannot send second one before processing response from first one. [2024-04-28 23:11:39] debug: zh:controller:endpoint: ZCL command 0x70b3d52b6007fcf0/1 genBasic.read(["zclVersion"], {"timeout":10000,"disableResponse":false,"disableRecovery":false,"disableDefaultResponse":true,"direction":0,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":null,"writeUndiv":false}) failed (ERROR_INVALID_CALL) [2024-04-28 23:11:39] warning: z2m: Failed to ping 'ShkafLight' (attempt 2/2, ZCL command 0x70b3d52b6007fcf0/1 genBasic.read(["zclVersion"], {"timeout":10000,"disableResponse":false,"disableRecovery":false,"disableDefaultResponse":true,"direction":0,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":null,"writeUndiv":false}) failed (ERROR_INVALID_CALL)) [2024-04-28 23:11:42] debug: z2m: Active device 'ShkafLight' was last seen '10.15' minutes ago. [2024-04-28 23:11:42] debug: z2m: MQTT publish: topic 'zigbee2mqtt/ShkafLight/availability', payload '{"state":"offline"}' [2024-04-28 23:14:05] debug: z2m: Saving state to file /config/zigbee2mqtt/state.json [2024-04-28 23:14:13] debug: zh:ember:queue: Status queue=0 priorityQueue=0. [2024-04-28 23:14:13] error: zh:ember:ezsp: [SEND COMMAND] Cannot send second one before processing response from first one.

Ant118 avatar Apr 29 '24 09:04 Ant118

[2024-04-29 14:22:38] error: zh:ember:ezsp: [SEND COMMAND] Cannot send second one before processing response from first one. Error: ERROR_INVALID_CALL at Ezsp.startCommand (/app/node_modules/zigbee-herdsman/src/adapter/ember/ezsp/ezsp.ts:462:19) at Ezsp.ezspReadAndClearCounters (/app/node_modules/zigbee-herdsman/src/adapter/ember/ezsp/ezsp.ts:2009:14) at Object.func (/app/node_modules/zigbee-herdsman/src/adapter/ember/adapter/emberAdapter.ts:753:58) at EmberRequestQueue.dispatch (/app/node_modules/zigbee-herdsman/src/adapter/ember/adapter/requestQueue.ts:117:58) at listOnTimeout (node:internal/timers:569:17) at processTimers (node:internal/timers:512:7)

Ant118 avatar Apr 29 '24 11:04 Ant118

The firmware of the adapter 6.10.7.0 build 435 turned out to be stable enough.

Ant118 avatar May 02 '24 16:05 Ant118

@Ant118 where can this firmware be found?

At least not here: https://github.com/darkxst/silabs-firmware-builder/tree/main/firmware_builds/zbdonglee

shivan avatar May 02 '24 16:05 shivan

@Ant118 where can this firmware be found?

At least not here: https://github.com/darkxst/silabs-firmware-builder/tree/main/firmware_builds/zbdonglee

I haven't tried version 7.4.2, I'm tired of experimenting while I stay on the old version.

Ant118 avatar May 03 '24 08:05 Ant118

@Ant118 where can this firmware be found? At least not here: https://github.com/darkxst/silabs-firmware-builder/tree/main/firmware_builds/zbdonglee

I haven't tried version 7.4.2, I'm tired of experimenting while I stay on the old version.

That's why I ask: Where can I get 6.10.7.0 build 435, since even at the manufacturer there is only 6.10.3.0 build 297: https://github.com/itead/Sonoff_Zigbee_Dongle_Firmware/tree/master/Dongle-E/NCP and that was the version my SONOFF-E stick was delivered with.

shivan avatar May 03 '24 09:05 shivan

@Ant118 where can this firmware be found? At least not here: https://github.com/darkxst/silabs-firmware-builder/tree/main/firmware_builds/zbdonglee

I haven't tried version 7.4.2, I'm tired of experimenting while I stay on the old version.

That's why I ask: Where can I get 6.10.7.0 build 435, since even at the manufacturer there is only 6.10.3.0 build 297: https://github.com/itead/Sonoff_Zigbee_Dongle_Firmware/tree/master/Dongle-E/NCP and that was the version my SONOFF-E stick was delivered with.

https://raw.githubusercontent.com/xsp1989/zigbeeFirmware/master/firmware/Zigbee3.0_Dongle-NoSigned/EZSP/ncp-uart-sw_6.10.7.0_115200.gbl

Ant118 avatar May 03 '24 09:05 Ant118

The firmware of the adapter 6.10.7.0 build 435 turned out to be stable enough.

Did that work also with the Ember driver?

Did you also have problems with devices that go Offline after a while? What ever firmware I use. Always some random devices go offline after a while until I restart.

lanwin avatar May 03 '24 09:05 lanwin

Did that work also with the Ember driver?

Did you also have problems with devices that go Offline after a while? What ever firmware I use. Always some random devices go offline after a while until I restart.

Ember does not work on older firmware! Control over the devices was maintained for 2 days. However, I have only 3 devices so far, today I added 2 more and plan to add 2 more. I lost control only after restarting the Home Assistant, they wrote about this problem. Restarting Zigbee2MQTT helped.

Ant118 avatar May 03 '24 10:05 Ant118

Suddenly, device management is gone, rebooting does not help. So the firmware didn't save me. In thought, change the adapter to Dongle-P or deploy HA on more powerful hardware.

Ant118 avatar May 03 '24 18:05 Ant118

You need to update your firmware to 7.4.1

Hi, I have the same dongle. Tried to move from ezsp to ember driver, this is not working, same errors as @Ant118 . Tried several firmware for the dongle from https://github.com/darkxst/silabs-firmware-builder/tree/main/firmware_builds/zbdonglee (7.4.2, 7.4.1, 7.4.0) and all I got is:

[2024-05-10 20:56:09] info: 	z2m: Logging to console, file (filename: log.log)
[2024-05-10 20:56:09] info: 	z2m: Starting Zigbee2MQTT version 1.37.1 (commit #ea39d86)
[2024-05-10 20:56:09] info: 	z2m: Starting zigbee-herdsman (0.46.6)
[2024-05-10 20:56:09] info: 	zh:ember: ======== Ember Adapter Starting ========
[2024-05-10 20:56:09] info: 	zh:ember:ezsp: ======== EZSP starting ========
[2024-05-10 20:56:09] info: 	zh:ember:uart:ash: ======== ASH NCP reset ========
[2024-05-10 20:56:09] info: 	zh:ember:uart:ash: RTS/CTS config is off, enabling software flow control.
[2024-05-10 20:56:09] info: 	zh:ember:uart:ash: Serial port opened
[2024-05-10 20:56:09] info: 	zh:ember:uart:ash: ======== ASH starting ========
[2024-05-10 20:56:10] info: 	zh:ember:uart:ash: ======== ASH connected ========
[2024-05-10 20:56:10] info: 	zh:ember:uart:ash: ======== ASH started ========
[2024-05-10 20:56:10] info: 	zh:ember:ezsp: ======== EZSP started ========
[2024-05-10 20:56:10] error: 	z2m: Error while starting zigbee-herdsman
[2024-05-10 20:56:10] error: 	z2m: Failed to start zigbee
[2024-05-10 20:56:10] error: 	z2m: Check https://www.zigbee2mqtt.io/guide/installation/20_zigbee2mqtt-fails-to-start.html for possible solutions
[2024-05-10 20:56:10] error: 	z2m: Exiting...
[2024-05-10 20:56:10] error: 	z2m: Error: NCP EZSP protocol version of 12 does not match Host version 13
    at EmberAdapter.emberVersion (/app/node_modules/zigbee-herdsman/src/adapter/ember/adapter/emberAdapter.ts:1633:19)
    at EmberAdapter.initEzsp (/app/node_modules/zigbee-herdsman/src/adapter/ember/adapter/emberAdapter.ts:784:9)
    at EmberAdapter.start (/app/node_modules/zigbee-herdsman/src/adapter/ember/adapter/emberAdapter.ts:2642: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:109:27)
    at start (/app/index.js:107:5)

In fact, with these last firmwares, impossible to use ezsp too, I had this error:

[2024-05-10 21:15:42] info: 	z2m: Logging to console, file (filename: log.log)
[2024-05-10 21:15:42] info: 	z2m: Starting Zigbee2MQTT version 1.37.1 (commit #ea39d86)
[2024-05-10 21:15:42] info: 	z2m: Starting zigbee-herdsman (0.46.6)
[2024-05-10 21:15:42] warning: 	zh:ezsp: Deprecated driver 'ezsp' currently in use, 'ember' will become the officially supported EmberZNet driver in next release. If using Zigbee2MQTT see https://github.com/Koenkk/zigbee2mqtt/discussions/21462
[2024-05-10 21:15:52] error: 	zh:ezsp:uart: --> Error: Error: {"sequence":-1} after 10000ms
[2024-05-10 21:15:52] error: 	zh:ezsp:ezsp: Connection attempt 1 error: Error: Failure to connect
    at SerialDriver.resetForReconnect (/app/node_modules/zigbee-herdsman/src/adapter/ezsp/driver/ezsp.ts:347:19)
    at SerialDriver.emit (node:events:517:28)
    at /app/node_modules/zigbee-herdsman/src/adapter/ezsp/driver/uart.ts:348:22
    at Queue.execute (/app/node_modules/zigbee-herdsman/src/utils/queue.ts:35:20)
    at SerialDriver.openSerialPort (/app/node_modules/zigbee-herdsman/src/adapter/ezsp/driver/uart.ts:108:13)
    at SerialDriver.connect (/app/node_modules/zigbee-herdsman/src/adapter/ezsp/driver/uart.ts:63:13)
    at Ezsp.connect (/app/node_modules/zigbee-herdsman/src/adapter/ezsp/driver/ezsp.ts:353:17)
    at Driver.startup (/app/node_modules/zigbee-herdsman/src/adapter/ezsp/driver/driver.ts:164:13)
    at Controller.start (/app/node_modules/zigbee-herdsman/src/controller/controller.ts:124:29)
    at Zigbee.start (/app/lib/zigbee.ts:62:27)
[2024-05-10 21:16:07] error: 	zh:ezsp:uart: --> Error: Error: {"sequence":-1} after 10000ms
[2024-05-10 21:16:07] error: 	zh:ezsp:ezsp: Connection attempt 2 error: Error: Failure to connect
    at SerialDriver.resetForReconnect (/app/node_modules/zigbee-herdsman/src/adapter/ezsp/driver/ezsp.ts:347:19)
    at SerialDriver.emit (node:events:517:28)
    at /app/node_modules/zigbee-herdsman/src/adapter/ezsp/driver/uart.ts:348:22
    at Queue.execute (/app/node_modules/zigbee-herdsman/src/utils/queue.ts:35:20)
    at SerialDriver.openSerialPort (/app/node_modules/zigbee-herdsman/src/adapter/ezsp/driver/uart.ts:108:13)
    at SerialDriver.connect (/app/node_modules/zigbee-herdsman/src/adapter/ezsp/driver/uart.ts:63:13)
    at Ezsp.connect (/app/node_modules/zigbee-herdsman/src/adapter/ezsp/driver/ezsp.ts:353:17)
    at Driver.startup (/app/node_modules/zigbee-herdsman/src/adapter/ezsp/driver/driver.ts:164:13)
    at Controller.start (/app/node_modules/zigbee-herdsman/src/controller/controller.ts:124:29)
    at Zigbee.start (/app/lib/zigbee.ts:62:27)
[2024-05-10 21:16:27] error: 	zh:ezsp:uart: --> Error: Error: {"sequence":-1} after 10000ms
[2024-05-10 21:16:27] error: 	zh:ezsp:ezsp: Connection attempt 3 error: Error: Failure to connect
    at SerialDriver.resetForReconnect (/app/node_modules/zigbee-herdsman/src/adapter/ezsp/driver/ezsp.ts:347:19)
    at SerialDriver.emit (node:events:517:28)
    at /app/node_modules/zigbee-herdsman/src/adapter/ezsp/driver/uart.ts:348:22
    at Queue.execute (/app/node_modules/zigbee-herdsman/src/utils/queue.ts:35:20)
    at SerialDriver.openSerialPort (/app/node_modules/zigbee-herdsman/src/adapter/ezsp/driver/uart.ts:108:13)
    at SerialDriver.connect (/app/node_modules/zigbee-herdsman/src/adapter/ezsp/driver/uart.ts:63:13)
    at Ezsp.connect (/app/node_modules/zigbee-herdsman/src/adapter/ezsp/driver/ezsp.ts:353:17)
    at Driver.startup (/app/node_modules/zigbee-herdsman/src/adapter/ezsp/driver/driver.ts:164:13)
    at Controller.start (/app/node_modules/zigbee-herdsman/src/controller/controller.ts:124:29)
    at Zigbee.start (/app/lib/zigbee.ts:62:27)

So I dowgraded to 7.1.3.0 which work with ezsp (but not with ember), waiting for a solution.

BenDavidson90 avatar May 13 '24 08:05 BenDavidson90

For a while now i have the same problem. Already tried different types of firmware, currently running on 7.4.3.0 but still not stable. As soon as I reboot my HASS instance it works again but most of the times after a few hours all my devices stop responding again and I get the same error:

[2024-07-31 21:48:59] error: zh:ezsp:uart: --> Error: Error: {"sequence":2} after 4000ms [2024-07-31 21:48:59] error: zh:ezsp:uart: -!- break waiting (2) [2024-07-31 21:48:59] error: zh:ezsp:uart: Can't send DATA frame (1,0,0): 01000134000039cb04010600010100010000b0b103011000

I have tried downgrading and upgrading my firmware multiple times but still no working one has been found. I am using the dongle-e as well.

3Dieuwer avatar Jul 31 '24 19:07 3Dieuwer

My experience with the recent firmware update, which has unfortunately caused significant stability issues for my Sonoff dongle e device. Prior to the upgrade, my device was functioning smoothly for almost two years without any problems. However, after learning that the EZSP protocol was being phased out, I proceeded with the update (big mistake).

Since upgrading, I have encountered numerous stability issues, leading to hours of troubleshooting. The device occasionally operates for a few minutes to a few hours, and on rare occasions, it will run for a couple of days before crashing again, if I'm lucky.

I have attempted to resolve these issues by testing firmware versions 7.4.3, 7.4.2, and 7.4.1, as well as switching between the "ember" and "ezsp" adapter settings. Unfortunately, none of these efforts have yielded a lasting solution. I find myself relieved when the device operates for a few days, but that has become the exception rather than the rule.

The process of unplugging, replugging, and rebooting the system flash has become increasingly frustrating. As a next step, I plan to downgrade to firmware version 6.10.3 and revert to the EZSP protocol.

I hope this feedback is helpful and that future updates can improve the stability and functionality of the Sonoff dongle e device.

I strongly recommend that support for EZSP be maintained and not deprecated, as Ember and the new firmware version combined with the Sonoff Dongle E clearly do not work for many users. I have ordered the latest version of the coordinator device (version 07) and will check if the same problems persist once it arrives.

[2024-08-12 21:39:53] error: zh:ezsp:uart: --> Error: Error: {"sequence":3} after 4000ms [2024-08-12 21:39:53] error: zh:ezsp:uart: -!- break waiting (3) [2024-08-12 21:39:53] error: zh:ezsp:uart: Can't send DATA frame (2,2,0): 1a00010200010401efbe0007140000030006000a0019001a0000030000030004000500060008002000000300040204050406040005010b030b040b0207001001fc02fc [2024-08-12 21:39:57] error: zh:ezsp:uart: --> Error: Error: {"sequence":3} after 4000ms [2024-08-12 21:39:57] error: zh:ezsp:uart: -!- break rewaiting (3) [2024-08-12 21:39:57] error: zh:ezsp:uart: Can't resend DATA frame (2,2,1): 1a00010200010401efbe0007140000030006000a0019001a0000030000030004000500060008002000000300040204050406040005010b030b040b0207001001fc02fc [2024-08-12 21:39:57] error: z2m: Error while starting zigbee-herdsman [2024-08-12 21:39:57] error: z2m: Failed to start zigbee [2024-08-12 21:39:57] error: z2m: Check https://www.zigbee2mqtt.io/guide/installation/20_zigbee2mqtt-fails-to-start.html for possible solutions [2024-08-12 21:39:57] error: z2m: Exiting... [2024-08-12 21:39:58] error: z2m: Error: Failure send addEndpoint:{"type":"Buffer","data":[26,0,1,2,0,1,4,1,239,190,0,7,20,0,0,3,0,6,0,10,0,25,0,26,0,0,3,0,0,3,0,4,0,5,0,6,0,8,0,32,0,0,3,0,4,2,4,5,4,6,4,0,5,1,11,3,11,4,11,2,7,0,16,1,252,2,252]} at /app/node_modules/zigbee-herdsman/src/adapter/ezsp/driver/ezsp.ts:675:23 at Queue.execute (/app/node_modules/zigbee-herdsman/src/utils/queue.ts:35:20) at Driver.addEndpoint (/app/node_modules/zigbee-herdsman/src/adapter/ezsp/driver/driver.ts:811:21) at Driver.startup (/app/node_modules/zigbee-herdsman/src/adapter/ezsp/driver/driver.ts:195:9) at Controller.start (/app/node_modules/zigbee-herdsman/src/controller/controller.ts:127:29) at Zigbee.start (/app/lib/zigbee.ts:63:27) at Controller.start (/app/lib/controller.ts:139:27) at start (/app/index.js:154:5)

Bizzmo avatar Aug 12 '24 19:08 Bizzmo

How can I check the version of dongle ? Do you solve with news version ?

SabatoArdolino avatar Sep 10 '24 12:09 SabatoArdolino