zigbee2mqtt icon indicating copy to clipboard operation
zigbee2mqtt copied to clipboard

Published 20 hours ago • verified publisher icon Koenkk

The "ember" driver of Zigbee2MQTT v1.37.0 doesn't work with Sonoff Dongle-E firmware v7.4.2 (but is okay with fw v7.4.1)

Open E-DESVIGNE opened this issue 9 months ago • 26 comments

What happened?

This morning, my Zigbee2MQTT was up to date (version 1.37.0), but I was still using the "ezsp" driver to control my Sonoff Dongle-E (SONOFF Zigbee 3.0 USB Dongle Plus V2), which had an old firmware version (ncp-uart-sw_v6.10.3_115200). Note: for your information, I'm working on a Raspberry Pi 3B+ running Debian GNU/Linux 11.

As I received the alert message "ezsp: Deprecated driver 'ezsp' currently in use, 'ember' will become the officially supported EmberZNet driver in the next release", I didn't want to wait. I wanted to update my dongle and switch to the new "ember" driver.

Easy steps:

  1. I stopped zigbee2mqtt: service zigbee2mqtt stop
  2. I used "universal-silabs-flasher" to flash the latest firmware for my dongle (ncp v7.4.2.0) with the command: universal-silabs-flasher --device /dev/ttyACM0 flash --firmware ncp-uart-hw-v7.4.2.0-zbdonglee-115200.gbl

Everything went smoothly except... I couldn't restart Zigbee2MQTT! I won't bore you with all the tests I did this afternoon, but I finally found the solution. I'm posting it here to help anyone who might encounter the same problem as me.

The "ember" driver of Zigbee2MQTT v1.37.0 doesn't work with the firmware "ncp-uart-hw-v7.4.2.0-zbdonglee-115200.gbl"! I downgraded my dongle to the version just before (v7.4.1) with: universal-silabs-flasher --device /dev/ttyACM0 flash --firmware ncp-uart-hw-v7.4.1.0-zbdonglee-115200.gbl --force

And since then... everything works perfectly fine :-)

Conclusion: Zigbee2MQTT version 1.37.0 doesn't work with a Sonoff Dongle-E having the firmware ncp v7.4.2.0, but works perfectly fine with the firmware ncp v7.4.1.0.

At this point, I'm not sure if the problem comes from the "ember" driver provided with Zigbee2MQTT version 1.37.0, or if it's the firmware "ncp-uart-hw-v7.4.2.0-zbdonglee-115200.gbl" that has a defect that "ncp-uart-hw-v7.4.1.0-zbdonglee-115200.gbl" doesn't have. I'll let the specialists investigate, but I'm sharing the information here in case it can save a few users from losing 2 hours like me ;-)

What did you expect to happen?

No response

How to reproduce it (minimal and precise)

A "SONOFF Zigbee 3.0 USB Dongle Plus V2" with "ncp-uart-hw-v7.4.2.0-zbdonglee" firmware, and Zigbee2MQTT version 1.37.0 with "ember" driver activated. Ultimately, everything worked when I downgraded the firmware of the dongle to version "ncp-uart-hw-v7.4.1.0-zbdonglee".

Zigbee2MQTT version

1.37.0 commit: ee5cf5a

Adapter firmware version

ncp-uart-hw-v7.4.2.0-zbdonglee-115200.gbl

Adapter

Sonoff Dongle-E (SONOFF Zigbee 3.0 USB Dongle Plus V2)

Setup

Raspberry Pi 3B+ running Debian GNU/Linux 11 + Domoticz Version 2024.4

Debug log

No response

E-DESVIGNE avatar May 05 '24 16:05 E-DESVIGNE

You can try 7.4.3 firmware... https://github.com/darkxst/silabs-firmware-builder/tree/4.4.3/firmware_builds

mamrai1 avatar May 05 '24 16:05 mamrai1

You can try 7.4.3 firmware... https://github.com/darkxst/silabs-firmware-builder/tree/4.4.3/firmware_builds

Well spotted... it works with v7.4.3! So, it's indeed the firmware 7.4.2 that has an issue. Thanks (I hadn't noticed there was a 7.4.3).

E-DESVIGNE avatar May 05 '24 17:05 E-DESVIGNE

Hello everyone

I can't get the ZigbeeDongle E to work with the latest firmware either.

My setup...

  • NiPoGI Intel N100, 16 GB RAM, Debian 12, Docker environment
  • Zigbee2Mqtt 1.37.0
  • SONOFF Zigbee 3.0 USB Dongle Plus V2, FW firmware_builds/zbdonglee/ncp-uart-hw-v7.4.3.0-zbdonglee-115200.gbl

Debug log Zigbee2Mqtt_Log-2024.5.5_20.5.39-(HomeServer).tar.gz

ChrisLSaar avatar May 05 '24 18:05 ChrisLSaar

@ChrisLSaar MQTT error: connect ECONNREFUSED 192.168.11.10:1883 Make sure your MQTT is okay and that the conf is correct. PS: The initial startup fail (your first log) is under investigation, looks to be related to some virtualization setups. It should start fine after that first error.

Nerivec avatar May 05 '24 18:05 Nerivec

@Nerivec

How embarrassing. Thank you, of course you're right. Sometimes you overlook the obvious when you concentrate on the little things. Firewall release was missing.

Now it's running, I'll keep testing

ChrisLSaar avatar May 05 '24 18:05 ChrisLSaar

Hey thanks for sharing! In my case it still showing me the error

22:41:57] INFO: Preparing to start... [22:41:58] INFO: Socat not enabled [22:41:59] INFO: Starting Zigbee2MQTT... [2024-05-05 22:42:01] info: z2m: Logging to console, file (filename: log.log) [2024-05-05 22:42:03] info: z2m: Starting Zigbee2MQTT version 1.37.0 (commit #unknown) [2024-05-05 22:42:03] info: z2m: Starting zigbee-herdsman (0.45.0) [2024-05-05 22:42:03] 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-05 22:42:08] info: z2m: zigbee-herdsman started (resumed) [2024-05-05 22:42:08] info: z2m: Coordinator firmware version: '{"meta":{"maintrel":"3 ","majorrel":"7","minorrel":"4","product":13,"revision":"7.4.3.0 build 0"},"type":"EZSP v13"}'

As you can see i am running the 7.4.3.0 build. And have changed the configuration.yml file to using ember serial: port: >- /dev/serial/by-id/usb-ITEAD_SONOFF_Zigbee_3.0_USB_Dongle_Plus_V2_20230505134542-if00 adapter: ember Ive also tried to change the serial adapter in the UI to ember but it reverts back to ezsp after saving the changes.

My setup Sonoff Dongle-E (SONOFF Zigbee 3.0 USB Dongle Plus V2) ncp-uart-hw-v7.4.3.0-zbdonglee-115200.gbl 1.37.0 Home Assistant Blue as hardware

Not sure what to do tbh, thankful for any help! :)

yaskad avatar May 05 '24 20:05 yaskad

@yaskad Shut down Z2M, edit the setting directly inside the configuration.yaml file then start again. As long as you are editing the right file (in case you changed the default data directory, you have to change the file in that one), that should work.

serial:
  port: >-
    /dev/serial/by-id/usb-ITEAD_SONOFF_Zigbee_3.0_USB_Dongle_Plus_V2_20230505134542-if00
  adapter: ember

Nerivec avatar May 05 '24 22:05 Nerivec

@Nerivec I was a bit confused about your comment.

The configuration file that I have edited is in /config/zigbee2mqtt/configuration.yml

But somehow the addon did not pick up the changes even after stop and start. But, your comment get me thinking if there was another config that I missed. Then I found this out

image

Once I changed there I could see ember was begin used now

[2024-05-06 08:07:44] info: z2m: Starting zigbee-herdsman (0.45.0) [2024-05-06 08:07:44] info: zh:ember: ======== Ember Adapter Starting ======== [2024-05-06 08:07:44] info: zh:ember:ezsp: ======== EZSP starting ========

Anyway, I don't really know where that configuration was saving its value but good to know for the future:)! Thanks for your help!

yaskad avatar May 06 '24 06:05 yaskad

I had the same problem as yaskad, and the solution was the same: if you are using the zigbee add-in you have to change "ezsp" to "ember" in the add-in configuration as this overrides the value in the config file. In fact it seems sufficient to change only the add-in config as that makes the change to the configuration.yaml file for you.

I think this requires a change to code or at least to documentation - it's easy to overlook this extra layer of configuration when using the zigbee2mqtt add-in.

johnholman avatar May 06 '24 10:05 johnholman

I am in 7.4.2 with z2m 1.37 it works well with the sonoff zbdongle-e and ember. Should I migrate my key to 7.4.3? THANKS

kwetnico avatar May 06 '24 10:05 kwetnico

Hello, by now I feel like I've tried everything. Old and new firmwares, init_firmware, delete config file and recreate. Set driver to "ember" and back again. Long and short device path. Nothing helped. Maybe one of you will find a mistake on my part that I am simply overlooking.

Zigbee2MQTT version: 1.37.0 commit: ee5cf5a

Adapter firmware version: ncp-uart-hw-v7.4.3.0-zbdonglee-115200.gbl

Adapter: Sonoff Dongle-E (SONOFF Zigbee 3.0 USB Dongle Plus V2)

Setup: Lenovo ThinkCentre M93p

Lg Raphael

An e.g. Logfile

[2024-05-06 00:18:39] info: z2m: Logging to console, file (filename: log.log) [2024-05-06 00:18:40] info: z2m: Starting Zigbee2MQTT version 1.37.0 (commit #unknown) [2024-05-06 00:18:40] info: z2m: Starting zigbee-herdsman (0.45.0) [2024-05-06 00:18:40] info: zh:ember: ======== Ember Adapter Starting ======== [2024-05-06 00:18:40] info: zh:ember:ezsp: ======== EZSP starting ======== [2024-05-06 00:18:40] info: zh:ember:uart:ash: ======== ASH NCP reset ======== [2024-05-06 00:18:40] info: zh:ember:uart:ash: RTS/CTS config is off, enabling software flow control. [2024-05-06 00:18:40] info: zh:ember:uart:ash: Serial port opened [2024-05-06 00:18:40] info: zh:ember:uart:ash: ======== ASH starting ======== [2024-05-06 00:18:42] info: zh:ember:uart:ash: ======== ASH NCP reset ======== [2024-05-06 00:18:42] info: zh:ember:uart:ash: ======== ASH starting ======== [2024-05-06 00:18:45] info: zh:ember:uart:ash: ======== ASH NCP reset ======== [2024-05-06 00:18:45] info: zh:ember:uart:ash: ======== ASH starting ======== [2024-05-06 00:18:47] info: zh:ember:uart:ash: ======== ASH NCP reset ======== [2024-05-06 00:18:47] info: zh:ember:uart:ash: ======== ASH starting ======== [2024-05-06 00:18:50] info: zh:ember:uart:ash: ======== ASH NCP reset ======== [2024-05-06 00:18:50] info: zh:ember:uart:ash: ======== ASH starting ======== [2024-05-06 00:18:52] error: z2m: Error while starting zigbee-herdsman [2024-05-06 00:18:52] error: z2m: Failed to start zigbee [2024-05-06 00:18:52] error: z2m: Check https://www.zigbee2mqtt.io/guide/installation/20_zigbee2mqtt-fails-to-start.html for possible solutions [2024-05-06 00:18:52] error: z2m: Exiting... [2024-05-06 00:18:53] error: z2m: Error: Failed to start EZSP layer with status=HOST_FATAL_ERROR. at EmberAdapter.initEzsp (/app/node_modules/zigbee-herdsman/src/adapter/ember/adapter/emberAdapter.ts:798:19) at EmberAdapter.start (/app/node_modules/zigbee-herdsman/src/adapter/ember/adapter/emberAdapter.ts:2660:24) at Controller.start (/app/node_modules/zigbee-herdsman/src/controller/controller.ts:124:29) at Zigbee.start (/app/lib/zigbee.ts:62:27) at Controller.start (/app/lib/controller.ts:108:27) at start (/app/index.js:107:5)

The connfig:

homeassistant: true advanced: network_key: - 8 - 44 - 75 - 185 - 126 - 223 - 89 - 158 - 206 - 107 - 5 - 135 - 66 - 25 - 107 - 67 pan_id: 20816 ext_pan_id: - 49 - 144 - 102 - 147 - 81 - 91 - 68 - 168 homeassistant_legacy_entity_attributes: false legacy_api: false legacy_availability_payload: false mqtt: server: mqtt://core-mosquitto:1883 user: addons password: xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx serial: port: /dev/ttyACM0 frontend: port: 8099 device_options: legacy: false

rgforward4 avatar May 06 '24 12:05 rgforward4

@rgforward4 Looks like it's unable to init the adapter on start. Can you set your log level to debug and send back the log file so I can get more details?

Nerivec avatar May 06 '24 13:05 Nerivec

Thank you for your helping. Here are the debug Log: [2024-05-06 16:33:33] info: z2m: Logging to console, file (filename: log.log) [2024-05-06 16:33:34] debug: z2m: Loaded state from file /config/zigbee2mqtt/state.json [2024-05-06 16:33:34] info: z2m: Starting Zigbee2MQTT version 1.37.0 (commit #unknown) [2024-05-06 16:33:34] info: z2m: Starting zigbee-herdsman (0.45.0) [2024-05-06 16:33:34] debug: z2m: Using zigbee-herdsman with settings: '{"adapter":{"concurrent":null,"delay":null,"disableLED":false},"backupPath":"/config/zigbee2mqtt/coordinator_backup.json","databaseBackupPath":"/config/zigbee2mqtt/database.db.backup","databasePath":"/config/zigbee2mqtt/database.db","network":{"channelList":[11],"extendedPanID":[49,144,102,147,81,91,68,168],"networkKey":"HIDDEN","panID":20816},"serialPort":{"adapter":"ember","path":"/dev/ttyACM0"}}' [2024-05-06 16:33:34] debug: zh:adapter: Failed to validate path: 'Error: spawn udevadm ENOENT' [2024-05-06 16:33:34] debug: zh:ember: Using delay=5. [2024-05-06 16:33:34] debug: zh:controller: Starting with options '{"network":{"networkKeyDistribute":false,"networkKey":[8,44,75,185,126,223,89,158,206,107,5,135,66,25,107,67],"panID":20816,"extendedPanID":[49,144,102,147,81,91,68,168],"channelList":[11]},"serialPort":{"path":"/dev/ttyACM0","adapter":"ember"},"databasePath":"/config/zigbee2mqtt/database.db","databaseBackupPath":"/config/zigbee2mqtt/database.db.backup","backupPath":"/config/zigbee2mqtt/coordinator_backup.json","adapter":{"disableLED":false,"concurrent":null,"delay":null}}' [2024-05-06 16:33:34] info: zh:ember: ======== Ember Adapter Starting ======== [2024-05-06 16:33:34] debug: zh:ember: Starting EZSP with stack configuration: "default". [2024-05-06 16:33:34] info: zh:ember:ezsp: ======== EZSP starting ======== [2024-05-06 16:33:34] info: zh:ember:uart:ash: ======== ASH NCP reset ======== [2024-05-06 16:33:34] info: zh:ember:uart:ash: RTS/CTS config is off, enabling software flow control. [2024-05-06 16:33:34] debug: zh:ember:uart:ash: Opening serial port with {"path":"/dev/ttyACM0","baudRate":115200,"rtscts":false,"autoOpen":false,"parity":"none","stopBits":1,"xon":true,"xoff":true} [2024-05-06 16:33:34] info: zh:ember:uart:ash: Serial port opened [2024-05-06 16:33:34] info: zh:ember:uart:ash: ======== ASH starting ======== [2024-05-06 16:33:34] debug: zh:ember:uart:ash: ---> [FRAME type=RST] [2024-05-06 16:33:34] debug: zh:ember:uart:ash: Waiting for RSTACK... 0/2500 [2024-05-06 16:33:34] debug: zh:ember:uart:ash: Waiting for RSTACK... 100/2500 [2024-05-06 16:33:34] debug: zh:ember:uart:ash: Waiting for RSTACK... 200/2500 [2024-05-06 16:33:34] debug: zh:ember:uart:ash: Waiting for RSTACK... 300/2500 [2024-05-06 16:33:34] debug: zh:ember:uart:ash: Waiting for RSTACK... 400/2500 [2024-05-06 16:33:35] debug: zh:ember:uart:ash: Waiting for RSTACK... 500/2500 [2024-05-06 16:33:35] debug: zh:ember:uart:ash: Waiting for RSTACK... 600/2500 [2024-05-06 16:33:35] debug: zh:ember:uart:ash: Waiting for RSTACK... 700/2500 [2024-05-06 16:33:35] debug: zh:ember:uart:ash: Waiting for RSTACK... 800/2500 [2024-05-06 16:33:35] debug: zh:ember:uart:ash: Waiting for RSTACK... 900/2500 [2024-05-06 16:33:35] debug: zh:ember:uart:ash: Waiting for RSTACK... 1000/2500 [2024-05-06 16:33:35] debug: zh:ember:uart:ash: Waiting for RSTACK... 1100/2500 [2024-05-06 16:33:35] debug: zh:ember:uart:ash: Waiting for RSTACK... 1200/2500 [2024-05-06 16:33:35] debug: zh:ember:uart:ash: Waiting for RSTACK... 1300/2500 [2024-05-06 16:33:36] debug: zh:ember:uart:ash: Waiting for RSTACK... 1400/2500 [2024-05-06 16:33:36] debug: zh:ember:uart:ash: Waiting for RSTACK... 1500/2500 [2024-05-06 16:33:36] debug: zh:ember:uart:ash: Waiting for RSTACK... 1600/2500 [2024-05-06 16:33:36] debug: zh:ember:uart:ash: Waiting for RSTACK... 1700/2500 [2024-05-06 16:33:36] debug: zh:ember:uart:ash: Waiting for RSTACK... 1800/2500 [2024-05-06 16:33:36] debug: zh:ember:uart:ash: Waiting for RSTACK... 1900/2500 [2024-05-06 16:33:36] debug: zh:ember:uart:ash: Waiting for RSTACK... 2000/2500 [2024-05-06 16:33:36] debug: zh:ember:uart:ash: Waiting for RSTACK... 2100/2500 [2024-05-06 16:33:36] debug: zh:ember:uart:ash: Waiting for RSTACK... 2200/2500 [2024-05-06 16:33:36] debug: zh:ember:uart:ash: Waiting for RSTACK... 2300/2500 [2024-05-06 16:33:37] debug: zh:ember:uart:ash: Waiting for RSTACK... 2400/2500 [2024-05-06 16:33:37] info: zh:ember:uart:ash: ======== ASH NCP reset ======== [2024-05-06 16:33:37] info: zh:ember:uart:ash: ======== ASH starting ======== [2024-05-06 16:33:37] debug: zh:ember:uart:ash: ---> [FRAME type=RST] [2024-05-06 16:33:37] debug: zh:ember:uart:ash: Waiting for RSTACK... 0/2500 [2024-05-06 16:33:37] debug: zh:ember:uart:ash: Waiting for RSTACK... 100/2500 [2024-05-06 16:33:37] debug: zh:ember:uart:ash: Waiting for RSTACK... 200/2500 [2024-05-06 16:33:37] debug: zh:ember:uart:ash: Waiting for RSTACK... 300/2500 [2024-05-06 16:33:37] debug: zh:ember:uart:ash: Waiting for RSTACK... 400/2500 [2024-05-06 16:33:37] debug: zh:ember:uart:ash: Waiting for RSTACK... 500/2500 [2024-05-06 16:33:37] debug: zh:ember:uart:ash: Waiting for RSTACK... 600/2500 [2024-05-06 16:33:37] debug: zh:ember:uart:ash: Waiting for RSTACK... 700/2500 [2024-05-06 16:33:37] debug: zh:ember:uart:ash: Waiting for RSTACK... 800/2500 [2024-05-06 16:33:38] debug: zh:ember:uart:ash: Waiting for RSTACK... 900/2500 [2024-05-06 16:33:38] debug: zh:ember:uart:ash: Waiting for RSTACK... 1000/2500 [2024-05-06 16:33:38] debug: zh:ember:uart:ash: Waiting for RSTACK... 1100/2500 [2024-05-06 16:33:38] debug: zh:ember:uart:ash: Waiting for RSTACK... 1200/2500 [2024-05-06 16:33:38] debug: zh:ember:uart:ash: Waiting for RSTACK... 1300/2500 [2024-05-06 16:33:38] debug: zh:ember:uart:ash: Waiting for RSTACK... 1400/2500 [2024-05-06 16:33:38] debug: zh:ember:uart:ash: Waiting for RSTACK... 1500/2500 [2024-05-06 16:33:38] debug: zh:ember:uart:ash: Waiting for RSTACK... 1600/2500 [2024-05-06 16:33:38] debug: zh:ember:uart:ash: Waiting for RSTACK... 1700/2500 [2024-05-06 16:33:38] debug: zh:ember:uart:ash: Waiting for RSTACK... 1800/2500 [2024-05-06 16:33:39] debug: zh:ember:uart:ash: Waiting for RSTACK... 1900/2500 [2024-05-06 16:33:39] debug: zh:ember:uart:ash: Waiting for RSTACK... 2000/2500 [2024-05-06 16:33:39] debug: zh:ember:uart:ash: Waiting for RSTACK... 2100/2500 [2024-05-06 16:33:39] debug: zh:ember:uart:ash: Waiting for RSTACK... 2200/2500 [2024-05-06 16:33:39] debug: zh:ember:uart:ash: Waiting for RSTACK... 2300/2500 [2024-05-06 16:33:39] debug: zh:ember:uart:ash: Waiting for RSTACK... 2400/2500 [2024-05-06 16:33:39] info: zh:ember:uart:ash: ======== ASH NCP reset ======== [2024-05-06 16:33:39] info: zh:ember:uart:ash: ======== ASH starting ======== [2024-05-06 16:33:39] debug: zh:ember:uart:ash: ---> [FRAME type=RST] [2024-05-06 16:33:39] debug: zh:ember:uart:ash: Waiting for RSTACK... 0/2500 [2024-05-06 16:33:39] debug: zh:ember:uart:ash: Waiting for RSTACK... 100/2500 [2024-05-06 16:33:39] debug: zh:ember:uart:ash: Waiting for RSTACK... 200/2500 [2024-05-06 16:33:39] debug: zh:ember:uart:ash: Waiting for RSTACK... 300/2500 [2024-05-06 16:33:40] debug: zh:ember:uart:ash: Waiting for RSTACK... 400/2500 [2024-05-06 16:33:40] debug: zh:ember:uart:ash: Waiting for RSTACK... 500/2500 [2024-05-06 16:33:40] debug: zh:ember:uart:ash: Waiting for RSTACK... 600/2500 [2024-05-06 16:33:40] debug: zh:ember:uart:ash: Waiting for RSTACK... 700/2500 [2024-05-06 16:33:40] debug: zh:ember:uart:ash: Waiting for RSTACK... 800/2500 [2024-05-06 16:33:40] debug: zh:ember:uart:ash: Waiting for RSTACK... 900/2500 [2024-05-06 16:33:40] debug: zh:ember:uart:ash: Waiting for RSTACK... 1000/2500 [2024-05-06 16:33:40] debug: zh:ember:uart:ash: Waiting for RSTACK... 1100/2500 [2024-05-06 16:33:40] debug: zh:ember:uart:ash: Waiting for RSTACK... 1200/2500 [2024-05-06 16:33:40] debug: zh:ember:uart:ash: Waiting for RSTACK... 1300/2500 [2024-05-06 16:33:41] debug: zh:ember:uart:ash: Waiting for RSTACK... 1400/2500 [2024-05-06 16:33:41] debug: zh:ember:uart:ash: Waiting for RSTACK... 1500/2500 [2024-05-06 16:33:41] debug: zh:ember:uart:ash: Waiting for RSTACK... 1600/2500 [2024-05-06 16:33:41] debug: zh:ember:uart:ash: Waiting for RSTACK... 1700/2500 [2024-05-06 16:33:41] debug: zh:ember:uart:ash: Waiting for RSTACK... 1800/2500 [2024-05-06 16:33:41] debug: zh:ember:uart:ash: Waiting for RSTACK... 1900/2500 [2024-05-06 16:33:41] debug: zh:ember:uart:ash: Waiting for RSTACK... 2000/2500 [2024-05-06 16:33:41] debug: zh:ember:uart:ash: Waiting for RSTACK... 2100/2500 [2024-05-06 16:33:41] debug: zh:ember:uart:ash: Waiting for RSTACK... 2200/2500 [2024-05-06 16:33:41] debug: zh:ember:uart:ash: Waiting for RSTACK... 2300/2500 [2024-05-06 16:33:42] debug: zh:ember:uart:ash: Waiting for RSTACK... 2400/2500 [2024-05-06 16:33:42] info: zh:ember:uart:ash: ======== ASH NCP reset ======== [2024-05-06 16:33:42] info: zh:ember:uart:ash: ======== ASH starting ======== [2024-05-06 16:33:42] debug: zh:ember:uart:ash: ---> [FRAME type=RST] [2024-05-06 16:33:42] debug: zh:ember:uart:ash: Waiting for RSTACK... 0/2500 [2024-05-06 16:33:42] debug: zh:ember:uart:ash: Waiting for RSTACK... 100/2500 [2024-05-06 16:33:42] debug: zh:ember:uart:ash: Waiting for RSTACK... 200/2500 [2024-05-06 16:33:42] debug: zh:ember:uart:ash: Waiting for RSTACK... 300/2500 [2024-05-06 16:33:42] debug: zh:ember:uart:ash: Waiting for RSTACK... 400/2500 [2024-05-06 16:33:42] debug: zh:ember:uart:ash: Waiting for RSTACK... 500/2500 [2024-05-06 16:33:42] debug: zh:ember:uart:ash: Waiting for RSTACK... 600/2500 [2024-05-06 16:33:42] debug: zh:ember:uart:ash: Waiting for RSTACK... 700/2500 [2024-05-06 16:33:42] debug: zh:ember:uart:ash: Waiting for RSTACK... 800/2500 [2024-05-06 16:33:43] debug: zh:ember:uart:ash: Waiting for RSTACK... 900/2500 [2024-05-06 16:33:43] debug: zh:ember:uart:ash: Waiting for RSTACK... 1000/2500 [2024-05-06 16:33:43] debug: zh:ember:uart:ash: Waiting for RSTACK... 1100/2500 [2024-05-06 16:33:43] debug: zh:ember:uart:ash: Waiting for RSTACK... 1200/2500 [2024-05-06 16:33:43] debug: zh:ember:uart:ash: Waiting for RSTACK... 1300/2500 [2024-05-06 16:33:43] debug: zh:ember:uart:ash: Waiting for RSTACK... 1400/2500 [2024-05-06 16:33:43] debug: zh:ember:uart:ash: Waiting for RSTACK... 1500/2500 [2024-05-06 16:33:43] debug: zh:ember:uart:ash: Waiting for RSTACK... 1600/2500 [2024-05-06 16:33:43] debug: zh:ember:uart:ash: Waiting for RSTACK... 1700/2500 [2024-05-06 16:33:43] debug: zh:ember:uart:ash: Waiting for RSTACK... 1800/2500 [2024-05-06 16:33:44] debug: zh:ember:uart:ash: Waiting for RSTACK... 1900/2500 [2024-05-06 16:33:44] debug: zh:ember:uart:ash: Waiting for RSTACK... 2000/2500 [2024-05-06 16:33:44] debug: zh:ember:uart:ash: Waiting for RSTACK... 2100/2500 [2024-05-06 16:33:44] debug: zh:ember:uart:ash: Waiting for RSTACK... 2200/2500 [2024-05-06 16:33:44] debug: zh:ember:uart:ash: Waiting for RSTACK... 2300/2500 [2024-05-06 16:33:44] debug: zh:ember:uart:ash: Waiting for RSTACK... 2400/2500 [2024-05-06 16:33:44] info: zh:ember:uart:ash: ======== ASH NCP reset ======== [2024-05-06 16:33:44] info: zh:ember:uart:ash: ======== ASH starting ======== [2024-05-06 16:33:44] debug: zh:ember:uart:ash: ---> [FRAME type=RST] [2024-05-06 16:33:44] debug: zh:ember:uart:ash: Waiting for RSTACK... 0/2500 [2024-05-06 16:33:44] debug: zh:ember:uart:ash: Waiting for RSTACK... 100/2500 [2024-05-06 16:33:44] debug: zh:ember:uart:ash: Waiting for RSTACK... 200/2500 [2024-05-06 16:33:44] debug: zh:ember:uart:ash: Waiting for RSTACK... 300/2500 [2024-05-06 16:33:45] debug: zh:ember:uart:ash: Waiting for RSTACK... 400/2500 [2024-05-06 16:33:45] debug: zh:ember:uart:ash: Waiting for RSTACK... 500/2500 [2024-05-06 16:33:45] debug: zh:ember:uart:ash: Waiting for RSTACK... 600/2500 [2024-05-06 16:33:45] debug: zh:ember:uart:ash: Waiting for RSTACK... 700/2500 [2024-05-06 16:33:45] debug: zh:ember:uart:ash: Waiting for RSTACK... 800/2500 [2024-05-06 16:33:45] debug: zh:ember:uart:ash: Waiting for RSTACK... 900/2500 [2024-05-06 16:33:45] debug: zh:ember:uart:ash: Waiting for RSTACK... 1000/2500 [2024-05-06 16:33:45] debug: zh:ember:uart:ash: Waiting for RSTACK... 1100/2500 [2024-05-06 16:33:45] debug: zh:ember:uart:ash: Waiting for RSTACK... 1200/2500 [2024-05-06 16:33:45] debug: zh:ember:uart:ash: Waiting for RSTACK... 1300/2500 [2024-05-06 16:33:46] debug: zh:ember:uart:ash: Waiting for RSTACK... 1400/2500 [2024-05-06 16:33:46] debug: zh:ember:uart:ash: Waiting for RSTACK... 1500/2500 [2024-05-06 16:33:46] debug: zh:ember:uart:ash: Waiting for RSTACK... 1600/2500 [2024-05-06 16:33:46] debug: zh:ember:uart:ash: Waiting for RSTACK... 1700/2500 [2024-05-06 16:33:46] debug: zh:ember:uart:ash: Waiting for RSTACK... 1800/2500 [2024-05-06 16:33:46] debug: zh:ember:uart:ash: Waiting for RSTACK... 1900/2500 [2024-05-06 16:33:46] debug: zh:ember:uart:ash: Waiting for RSTACK... 2000/2500 [2024-05-06 16:33:46] debug: zh:ember:uart:ash: Waiting for RSTACK... 2100/2500 [2024-05-06 16:33:46] debug: zh:ember:uart:ash: Waiting for RSTACK... 2200/2500 [2024-05-06 16:33:46] debug: zh:ember:uart:ash: Waiting for RSTACK... 2300/2500 [2024-05-06 16:33:47] debug: zh:ember:uart:ash: Waiting for RSTACK... 2400/2500 [2024-05-06 16:33:47] error: z2m: Error while starting zigbee-herdsman [2024-05-06 16:33:47] error: z2m: Failed to start zigbee [2024-05-06 16:33:47] error: z2m: Check https://www.zigbee2mqtt.io/guide/installation/20_zigbee2mqtt-fails-to-start.html for possible solutions [2024-05-06 16:33:47] error: z2m: Exiting... [2024-05-06 16:33:47] error: z2m: Error: Failed to start EZSP layer with status=HOST_FATAL_ERROR. at EmberAdapter.initEzsp (/app/node_modules/zigbee-herdsman/src/adapter/ember/adapter/emberAdapter.ts:798:19) at EmberAdapter.start (/app/node_modules/zigbee-herdsman/src/adapter/ember/adapter/emberAdapter.ts:2660:24) at Controller.start (/app/node_modules/zigbee-herdsman/src/controller/controller.ts:124:29) at Zigbee.start (/app/lib/zigbee.ts:62:27) at Controller.start (/app/lib/controller.ts:108:27) at start (/app/index.js:107:5)

rgforward4 avatar May 06 '24 14:05 rgforward4

Looks like your adapter is not replying to Z2M at all. Use the /dev/serial/by-id/... path for your adapter in case you have multiple devices plugged in, to ensure the proper one is used by Z2M.

Nerivec avatar May 06 '24 15:05 Nerivec

Yes, something is slowly dawning on me. I first tried it with a texas instrument. But I gave up because the system wasn't stable enough. Could it be that the first stick has written itself deep into the system somewhere? Do you mean the long device path? If so, I had already tried that. Or am I misunderstanding you?

rgforward4 avatar May 06 '24 15:05 rgforward4

Okay, i testet it with /dev/serial/by-id/usb-ITEAD_SONOFF_Zigbee_3.0_USB_Dongle_Plus_V2_20231214194237-if00 but it doesent work again.

rgforward4 avatar May 06 '24 16:05 rgforward4

A few things to try:

  • Flash this firmware again, make sure it loads properly again at the end (Continue button in the webflasher; it should load without error)
  • Shutdown Z2M, physically unplug your adapter for a minute or so, plug it back in, then try starting Z2M.

Nerivec avatar May 06 '24 16:05 Nerivec

Weird problem. Mine works with both ember and ezsp driver and also all firmwares above 7.4.0 Even changing the driver and rebooting z2m had no problems. Can you try and flash the cleanup file:

universal-silabs-flasher --device /dev/ttyACM0 --bootloader-reset sonoff flash --firmware nvm3_initfile.gbl

(https://github.com/xsp1989/zigbeeFirmware/blob/master/firmware/Zigbee3.0_Dongle-NoSigned/EZSP/nvm3_initfile.gbl)

mamrai1 avatar May 06 '24 16:05 mamrai1

Updated to 7.4.2 today and changed config to use ember, no problem at all here

felipejfc avatar May 06 '24 20:05 felipejfc

A few things to try:

  • Flash this firmware again, make sure it loads properly again at the end (Continue button in the webflasher; it should load without error)
  • Shutdown Z2M, physically unplug your adapter for a minute or so, plug it back in, then try starting Z2M.

Nice @Nerivec, that works!!! 7.4.1 works for me. All the other Firmware Version crasht, including 7.4.2

rgforward4 avatar May 06 '24 21:05 rgforward4

I experienced all the problems raised in the last days found here and in the others Issues opened since i changed driver to ember and updated to 1.37.0. Tryed all firmware from 7.4.0 to 7.4.4, i had to roll back to 1.36.0 and flashed firmware 7.4.1.

tomonetml avatar May 07 '24 06:05 tomonetml

Hi everyone, I'm faced with a strange problem with Z2M 1.37.0 / Sonoff E v2 7.4.3. I tried many firmwares but those errors still raising with the 7.4 firmware. I can't understand from where they come. I thought it was from GreenPower unicast,... The messages comes like that :

[2024-05-08 04:35:26] error: zh:ember:ezsp: ERROR Transaction failure; status=ERROR_WRONG_DIRECTION. Last: [FRAME: ID=52:"SEND_UNICAST" Seq=91 Len=26]. [2024-05-08 04:35:26] error: zh:ember: !!! NCP FATAL ERROR reason=ERROR_WRONG_DIRECTION. ATTEMPTING RESET... !!! [2024-05-08 04:35:26] error: zh:ember:ezsp: ERROR Transaction failure; status=ERROR_WRONG_DIRECTION. Last: [FRAME: ID=52:"SEND_UNICAST" Seq=91 Len=26]. [2024-05-08 04:35:26] error: zh:controller:device: Default response to 0xa4c138a17837c33e failed

If the "Default response" has to do with the errors above, then it happens only with NOUS TS011F plug but the bad is that i have 15 of those. I have updated their firmware to the latest available, but the issue still here.

Any ideas ? wrong direction ??

Thanks

FredC27 avatar May 08 '24 09:05 FredC27

That wrong direction means Z2M received a "command" instead of a "response" from the adapter. It seems to happen with interferences sometimes (around the adapter), check that first.

Nerivec avatar May 08 '24 18:05 Nerivec

Boa tarde amigos,

No meu caso desde que eu atualizei estou tendo os erros abaixo:

[15:21:05] INFO: Preparing to start... [15:21:05] INFO: Socat not enabled [15:21:06] INFO: Starting Zigbee2MQTT... [2024-05-08 15:21:06] info: z2m: Logging to console, file (filename: log.log) [2024-05-08 15:21:06] info: z2m: Starting Zigbee2MQTT version 1.37.0 (commit #unknown) [2024-05-08 15:21:06] info: z2m: Starting zigbee-herdsman (0.45.0) [2024-05-08 15:21:07] info: zh:ember: ======== Ember Adapter Starting ======== [2024-05-08 15:21:07] info: zh:ember:ezsp: ======== EZSP starting ======== [2024-05-08 15:21:07] info: zh:ember:uart:ash: ======== ASH NCP reset ======== [2024-05-08 15:21:07] info: zh:ember:uart:ash: RTS/CTS config is off, enabling software flow control. [2024-05-08 15:21:07] info: zh:ember:uart:ash: ASH COUNTERS since last clear: [2024-05-08 15:21:07] info: zh:ember:uart:ash: Total frames: RX=0, TX=0 [2024-05-08 15:21:07] info: zh:ember:uart:ash: Cancelled : RX=0, TX=0 [2024-05-08 15:21:07] info: zh:ember:uart:ash: DATA frames : RX=0, TX=0 [2024-05-08 15:21:07] info: zh:ember:uart:ash: DATA bytes : RX=0, TX=0 [2024-05-08 15:21:07] info: zh:ember:uart:ash: Retry frames: RX=0, TX=0 [2024-05-08 15:21:07] info: zh:ember:uart:ash: ACK frames : RX=0, TX=0 [2024-05-08 15:21:07] info: zh:ember:uart:ash: NAK frames : RX=0, TX=0 [2024-05-08 15:21:07] info: zh:ember:uart:ash: nRdy frames : RX=0, TX=0 [2024-05-08 15:21:07] info: zh:ember:uart:ash: CRC errors : RX=0 [2024-05-08 15:21:07] info: zh:ember:uart:ash: Comm errors : RX=0 [2024-05-08 15:21:07] info: zh:ember:uart:ash: Length < minimum: RX=0 [2024-05-08 15:21:07] info: zh:ember:uart:ash: Length > maximum: RX=0 [2024-05-08 15:21:07] info: zh:ember:uart:ash: Bad controls : RX=0 [2024-05-08 15:21:07] info: zh:ember:uart:ash: Bad lengths : RX=0 [2024-05-08 15:21:07] info: zh:ember:uart:ash: Bad ACK numbers : RX=0 [2024-05-08 15:21:07] info: zh:ember:uart:ash: Out of buffers : RX=0 [2024-05-08 15:21:07] info: zh:ember:uart:ash: Retry dupes : RX=0 [2024-05-08 15:21:07] info: zh:ember:uart:ash: Out of sequence : RX=0 [2024-05-08 15:21:07] info: zh:ember:uart:ash: ACK timeouts : RX=0 [2024-05-08 15:21:07] info: zh:ember:uart:ash: ======== ASH stopped ======== [2024-05-08 15:21:07] error: zh:ember:uart:ash: Failed to init port with error Error: Error Resource temporarily unavailable Cannot lock port [2024-05-08 15:21:07] error: z2m: Error while starting zigbee-herdsman [2024-05-08 15:21:07] error: z2m: Failed to start zigbee [2024-05-08 15:21:07] error: z2m: Check https://www.zigbee2mqtt.io/guide/installation/20_zigbee2mqtt-fails-to-start.html for possible solutions [2024-05-08 15:21:07] error: z2m: Exiting... [2024-05-08 15:21:07] error: z2m: Error: Failed to start EZSP layer with status=HOST_FATAL_ERROR. at EmberAdapter.initEzsp (/app/node_modules/zigbee-herdsman/src/adapter/ember/adapter/emberAdapter.ts:798:19) at EmberAdapter.start (/app/node_modules/zigbee-herdsman/src/adapter/ember/adapter/emberAdapter.ts:2660:24) at Controller.start (/app/node_modules/zigbee-herdsman/src/controller/controller.ts:124:29) at Zigbee.start (/app/lib/zigbee.ts:62:27) at Controller.start (/app/lib/controller.ts:108:27) at start (/app/index.js:107:5)

ESANTOS74 avatar May 08 '24 18:05 ESANTOS74

@ESANTOS74 English please. Failed to init port with error Error: Error Resource temporarily unavailable Cannot lock port Looks like something is currently using your port. Make sure to disable anything that might be before you start Z2M.

Nerivec avatar May 08 '24 18:05 Nerivec

Valeu Amigo, porem agora tenho esse erro:

[16:03:39] INFO: Preparing to start... [16:03:39] INFO: Socat not enabled [16:03:39] INFO: Starting Zigbee2MQTT... [2024-05-08 16:03:39] info: z2m: Logging to console, file (filename: log.log) [2024-05-08 16:03:40] info: z2m: Starting Zigbee2MQTT version 1.37.0 (commit #unknown) [2024-05-08 16:03:40] info: z2m: Starting zigbee-herdsman (0.45.0) [2024-05-08 16:03:40] info: zh:ember: ======== Ember Adapter Starting ======== [2024-05-08 16:03:40] info: zh:ember:ezsp: ======== EZSP starting ======== [2024-05-08 16:03:40] info: zh:ember:uart:ash: ======== ASH NCP reset ======== [2024-05-08 16:03:40] info: zh:ember:uart:ash: RTS/CTS config is off, enabling software flow control. [2024-05-08 16:03:40] info: zh:ember:uart:ash: Serial port opened [2024-05-08 16:03:40] info: zh:ember:uart:ash: ======== ASH starting ======== [2024-05-08 16:03:42] info: zh:ember:uart:ash: ======== ASH NCP reset ======== [2024-05-08 16:03:42] info: zh:ember:uart:ash: ======== ASH starting ======== [2024-05-08 16:03:45] info: zh:ember:uart:ash: ======== ASH NCP reset ======== [2024-05-08 16:03:45] info: zh:ember:uart:ash: ======== ASH starting ======== [2024-05-08 16:03:47] info: zh:ember:uart:ash: ======== ASH NCP reset ======== [2024-05-08 16:03:47] info: zh:ember:uart:ash: ======== ASH starting ======== [2024-05-08 16:03:50] info: zh:ember:uart:ash: ======== ASH NCP reset ======== [2024-05-08 16:03:50] info: zh:ember:uart:ash: ======== ASH starting ======== [2024-05-08 16:03:53] error: z2m: Error while starting zigbee-herdsman [2024-05-08 16:03:53] error: z2m: Failed to start zigbee [2024-05-08 16:03:53] error: z2m: Check https://www.zigbee2mqtt.io/guide/installation/20_zigbee2mqtt-fails-to-start.html for possible solutions [2024-05-08 16:03:53] error: z2m: Exiting... [2024-05-08 16:03:53] error: z2m: Error: Failed to start EZSP layer with status=HOST_FATAL_ERROR. at EmberAdapter.initEzsp (/app/node_modules/zigbee-herdsman/src/adapter/ember/adapter/emberAdapter.ts:798:19) at EmberAdapter.start (/app/node_modules/zigbee-herdsman/src/adapter/ember/adapter/emberAdapter.ts:2660:24) at Controller.start (/app/node_modules/zigbee-herdsman/src/controller/controller.ts:124:29) at Zigbee.start (/app/lib/zigbee.ts:62:27) at Controller.start (/app/lib/controller.ts:108:27) at start (/app/index.js:107:5)

ESANTOS74 avatar May 08 '24 19:05 ESANTOS74

Closing this as no longer relevant to the issue.

If you have trouble starting Z2M:

  • make sure you are using the proper firmware, proper baudrate, and corresponding baudrate in Z2M configuration.
  • unplug the adapter for 30+ seconds, then plug it back in and start Z2M again
  • re-flash the same firmware

FAQ Zigbee2MQTT fails to start

Please open a new issue if you have a specific problem that these do not fix.

Nerivec avatar May 10 '24 00:05 Nerivec

Same for me. With 7.4.2 firmware same error. It would be ok with 7.4.1

Loic691 avatar May 20 '24 19:05 Loic691

You can try 7.4.3 firmware... https://github.com/darkxst/silabs-firmware-builder/tree/4.4.3/firmware_builds

Well spotted... it works with v7.4.3! So, it's indeed the firmware 7.4.2 that has an issue. Thanks (I hadn't noticed there was a 7.4.3).

Hey,

I have the same hub and the same problem as you, how did you install the firmware on it?

thank you!

RazorDarkAMG avatar May 21 '24 22:05 RazorDarkAMG

Closing this as no longer relevant to the issue.

If you have trouble starting Z2M:

  • make sure you are using the proper firmware, proper baudrate, and corresponding baudrate in Z2M configuration.
  • unplug the adapter for 30+ seconds, then plug it back in and start Z2M again
  • re-flash the same firmware

FAQ Zigbee2MQTT fails to start

Please open a new issue if you have a specific problem that these do not fix.

Hello,

The official firmware to sonoff zbdongle-e is 7.4.2 or 7.4.3 ? Thanks

kwetnico avatar May 22 '24 05:05 kwetnico