Koenkk / zigbee2mqtt

Zigbee 🐝 to MQTT bridge 🌉, get rid of your proprietary Zigbee bridges 🔨
https://www.zigbee2mqtt.io
GNU General Public License v3.0
12.22k stars 1.69k forks source link

Bticino/Legrand devices not working after moving from ezsp to ember driver #22684

Open Crystian182 opened 6 months ago

Crystian182 commented 6 months ago

What happened?

I noticed this warning in my logs:

zh:ezsp: Deprecated driver ‘ezsp’ currently in use. ‘ember’ will become the officially supported EmberZNet driver in the next release.

and I decided to switch to the ember driver.

I flashed the 7.4.2 driver on my Sonoff Dongle E and changed the configuration from serial:adapter: ezsp to serial:adapter: ember.

All Bticino devices in my network stopped working. I saw they were showing the LQI info but they were not able to receive commands. I also have a bunch of Aqara devices, and they seemed to be working. Or at least, since they are temperature sensors, I saw they were able to send data.

I also tried firmware versions 7.4.1 and 7.4.3.

I had to downgrade to fw EZNet 6.10.3 and use ezsp driver and everything started to work again.

What did you expect to happen?

All my devices in my network to be working.

How to reproduce it (minimal and precise)

No response

Zigbee2MQTT version

1.37.1

Adapter firmware version

7.4.1, 7.4.2, 7.4.3

Adapter

SONOFF ZBDongle-E

Setup

Home Assistant OS on Intel NUC, running on Proxmox

Debug log

[2024-05-18 15:00:43] info: z2m: Logging to console, file (filename: log.log) [2024-05-18 15:00:43] info: z2m: Starting Zigbee2MQTT version 1.37.1 (commit #unknown) [2024-05-18 15:00:43] info: z2m: Starting zigbee-herdsman (0.46.6) [2024-05-18 15:00:43] info: zh:ember: ======== Ember Adapter Starting ======== [2024-05-18 15:00:43] info: zh:ember:ezsp: ======== EZSP starting ======== [2024-05-18 15:00:43] info: zh:ember:uart:ash: ======== ASH NCP reset ======== [2024-05-18 15:00:43] info: zh:ember:uart:ash: RTS/CTS config is off, enabling software flow control. [2024-05-18 15:00:43] info: zh:ember:uart:ash: Serial port opened [2024-05-18 15:00:43] info: zh:ember:uart:ash: ======== ASH starting ======== [2024-05-18 15:00:44] info: zh:ember:uart:ash: ======== ASH connected ======== [2024-05-18 15:00:44] info: zh:ember:uart:ash: ======== ASH started ======== [2024-05-18 15:00:44] info: zh:ember:ezsp: ======== EZSP started ======== [2024-05-18 15:00:44] info: zh:ember: [STACK STATUS] Network up. [2024-05-18 15:00:44] info: zh:ember: [INIT TC] NCP network matches config. [2024-05-18 15:00:44] info: zh:ember: [CONCENTRATOR] Started source route discovery. 1249ms until next broadcast. [2024-05-18 15:00:45] info: z2m: zigbee-herdsman started (resumed) [2024-05-18 15:00:45] info: z2m: Coordinator firmware version: '{"meta":{"build":0,"ezsp":13,"major":7,"minor":4,"patch":1,"revision":"7.4.1 [GA]","special":0,"type":170}> [2024-05-18 15:00:45] info: z2m: Currently 23 devices are joined: [2024-05-18 15:00:45] info: z2m: tapparella_cucina (0x000474000159618e): K4027C/L4027C/N4027C/NT4027C - BTicino Shutter SW with level control (Router) [2024-05-18 15:00:45] info: z2m: luce_esterno_ingresso_segnapassi (0x0004740000cb69f0): K4003C/L4003C/N4003C/NT4003C - BTicino Light switch with neutral (Router) [2024-05-18 15:00:45] info: z2m: luce_soggiorno (0x000474000025124d): 064888 - Legrand Wired micromodule switch (Router) [2024-05-18 15:00:45] info: z2m: luce_cucina_pranzo (0x0004740000251f82): 064888 - Legrand Wired micromodule switch (Router) [2024-05-18 15:00:45] info: z2m: luce_camera_matrimoniale (0x0004740000252255): 064888 - Legrand Wired micromodule switch (Router) [2024-05-18 15:00:45] info: z2m: luce_disimpegno (0x00047400002521ff): 064888 - Legrand Wired micromodule switch (Router) [2024-05-18 15:00:45] info: z2m: luce_cameretta (0x0004740000251fc1): 064888 - Legrand Wired micromodule switch (Router) [2024-05-18 15:00:45] info: z2m: luce_cucina (0x000474000085a7a5): K4003C/L4003C/N4003C/NT4003C - BTicino Light switch with neutral (Router) [2024-05-18 15:00:45] info: z2m: luce_cucina_led (0x000474000159f228): 4411C/L4411C/N4411C/NT4411C - BTicino Dimmer switch with neutral (Router) [2024-05-18 15:00:45] info: z2m: luce_cucina_led (0x000474000159f228): 4411C/L4411C/N4411C/NT4411C - BTicino Dimmer switch with neutral (Router) [2024-05-18 15:00:45] info: z2m: tapparella_soggiorno (0x0004740001449b31): K4027C/L4027C/N4027C/NT4027C - BTicino Shutter SW with level control (Router) [2024-05-18 15:00:45] info: z2m: luce_bagno_servizio_disimpegno (0x0004740000858b8e): K4003C/L4003C/N4003C/NT4003C - BTicino Light switch with neutral (Router) [2024-05-18 15:00:45] info: z2m: luce_bagno_servizio (0x00047400009512c9): K4003C/L4003C/N4003C/NT4003C - BTicino Light switch with neutral (Router) [2024-05-18 15:00:45] info: z2m: luce_esterno_giardino (0x0004740000cb69e7): K4003C/L4003C/N4003C/NT4003C - BTicino Light switch with neutral (Router) [2024-05-18 15:00:45] info: z2m: luce_scala (0x000474000095976b): K4003C/L4003C/N4003C/NT4003C - BTicino Light switch with neutral (Router) [2024-05-18 15:00:45] info: z2m: luce_ripostiglio (0x0004740000ca8440): K4003C/L4003C/N4003C/NT4003C - BTicino Light switch with neutral (Router) [2024-05-18 15:00:45] info: z2m: luce_esterno_ingresso (0x0004740000cb69c1): K4003C/L4003C/N4003C/NT4003C - BTicino Light switch with neutral (Router) [2024-05-18 15:00:45] info: z2m: tapparella_bagno (0x000474000146da17): K4027C/L4027C/N4027C/NT4027C - BTicino Shutter SW with level control (Router) [2024-05-18 15:00:45] info: z2m: temperatura_soggiorno (0x00158d0009f467bd): WSDCGQ11LM - Aqara Temperature and humidity sensor (EndDevice) [2024-05-18 15:00:45] info: z2m: pulsante_soggiorno (0xf082c0fffeee1487): TS0044 - TuYa Wireless switch with 4 buttons (EndDevice) [2024-05-18 15:00:45] info: z2m: movimento_scala_inferiore (0x54ef441000b62fa1): RTCGQ14LM - Aqara Motion sensor P1 (EndDevice) [2024-05-18 15:00:45] info: z2m: movimento_scala_superiore (0x54ef441000b62f25): RTCGQ14LM - Aqara Motion sensor P1 (EndDevice) [2024-05-18 15:00:45] info: z2m: luce_soggiorno_cortesia (0x00047400015ae320): 4411C/L4411C/N4411C/NT4411C - BTicino Dimmer switch with neutral (Router) [2024-05-18 15:00:45] info: z2m: luce_bagno (0x00047400015bfde8): K4003C/L4003C/N4003C/NT4003C - BTicino Light switch with neutral (Router) [2024-05-18 15:00:45] info: z2m: Zigbee: disabling joining new devices. [2024-05-18 15:00:45] info: z2m: Connecting to MQTT server at mqtt://core-mosquitto [2024-05-18 15:00:45] info: z2m: Connected to MQTT server [2024-05-18 15:00:45] info: z2m: Started frontend on port 8099 [2024-05-18 15:00:45] info: z2m: Zigbee2MQTT started! [2024-05-18 15:00:46] error: zh:ember: Delivery of BROADCAST failed for "65533" [apsFrame={"profileId":41440,"clusterId":33,"sourceEndpoint":242,"destinationEndpoint":242,> [2024-05-18 15:00:46] error: zh:ember: Delivery of BROADCAST failed for "65532" [apsFrame={"profileId":0,"clusterId":54,"sourceEndpoint":0,"destinationEndpoint":0,"options> [2024-05-18 15:00:57] error: zh:ember: Delivery of BROADCAST failed for "65533" [apsFrame={"profileId":0,"clusterId":6,"sourceEndpoint":0,"destinationEndpoint":0,"options"> [2024-05-18 15:00:57] error: zh:ember: Delivery of BROADCAST failed for "65532" [apsFrame={"profileId":0,"clusterId":31,"sourceEndpoint":0,"destinationEndpoint":0,"options> [2024-05-18 15:01:09] error: zh:ember: Delivery of BROADCAST failed for "65533" [apsFrame={"profileId":0,"clusterId":6,"sourceEndpoint":0,"destinationEndpoint":0,"options"> [2024-05-18 15:01:37] error: zh:ember: Delivery of BROADCAST failed for "65533" [apsFrame={"profileId":0,"clusterId":6,"sourceEndpoint":0,"destinationEndpoint":0,"options"> [2024-05-18 15:01:56] error: zh:ember: Delivery of BROADCAST failed for "65533" [apsFrame={"profileId":0,"clusterId":6,"sourceEndpoint":0,"destinationEndpoint":0,"options"> [2024-05-18 15:02:07] error: zh:ember: Delivery of BROADCAST failed for "65533" [apsFrame={"profileId":0,"clusterId":6,"sourceEndpoint":0,"destinationEndpoint":0,"options"> [2024-05-18 15:02:21] error: z2m: Publish 'set' 'state' to 'luce_disimpegno' failed: 'Error: ZCL command 0x00047400002521ff/1 genOnOff.on({}, {"timeout":10000,"disableResp> [2024-05-18 15:02:33] error: zh:ember: Delivery of BROADCAST failed for "65533" [apsFrame={"profileId":0,"clusterId":6,"sourceEndpoint":0,"destinationEndpoint":0,"options"> [2024-05-18 15:02:44] error: zh:ember: Delivery of BROADCAST failed for "65533" [apsFrame={"profileId":0,"clusterId":6,"sourceEndpoint":0,"destinationEndpoint":0,"options"> [2024-05-18 15:02:47] error: zh:ember: Delivery of BROADCAST failed for "65533" [apsFrame={"profileId":0,"clusterId":6,"sourceEndpoint":0,"destinationEndpoint":0,"options"> [2024-05-18 15:02:58] error: zh:ember: Delivery of BROADCAST failed for "65533" [apsFrame={"profileId":0,"clusterId":6,"sourceEndpoint":0,"destinationEndpoint":0,"options"> [2024-05-18 15:03:10] error: zh:ember: Delivery of BROADCAST failed for "65533" [apsFrame={"profileId":0,"clusterId":6,"sourceEndpoint":0,"destinationEndpoint":0,"options"> [2024-05-18 15:04:10] error: zh:ember: Delivery of BROADCAST failed for "65533" [apsFrame={"profileId":0,"clusterId":6,"sourceEndpoint":0,"destinationEndpoint":0,"options">

wastez commented 6 months ago

Some devices are not following the zigbee protocol standards. @Nerivec this is something for you

wastez commented 6 months ago

@Crystian182 You wrote you have to downgrade again and use also the ezsp driver. So wasn’t it working with the new firmware and the ezsp driver?

wastez commented 6 months ago

@Crystian182 Also the log is a little bit less, best would be to enable herdsman debug log and post it again.

Crystian182 commented 6 months ago

@Crystian182 You wrote you have to downgrade again and use also the ezsp driver. So wasn’t it working with the new firmware and the ezsp driver?

You know, I didn’t try. I’ll try again asap setting the log level at debug.

wastez commented 6 months ago

@Crystian182 Important is the zigbee-herdsman debug log. Do you know how to enable it?

Crystian182 commented 6 months ago

Following this

https://www.zigbee2mqtt.io/guide/usage/debug.html

wastez commented 6 months ago

@Crystian182 If you are using the home assistant addon it should be enough to set zigbee_herdsman_debug: true

But it would be the best to export the log over the container.

Nerivec commented 6 months ago

@wastez From 1.37.0, herdsman, converters and z2m logs are all unified in the same log file, just need to change the log level and done.😉

I've seen other reports of Bticino & Legrand misbehaving. I'll take a closer look at the combined logs of these. Although those broadcast failures look more like https://github.com/Koenkk/zigbee2mqtt/issues/22453 for which a "universal fix" remains elusive, but likely related to interferences in some way. See if one of the procedures given in there helps @Crystian182, and go through the usual, changing cable, changing port, unplugging the adapter for a minute or so, etc.

wastez commented 6 months ago

@Nerivec Good to know that the log situation now changed in the new version. (Already thought about it after i saw the docs of it but wasn’t sure, maybe a little information in the docs would be helpful that it changed from 1.37) Strange thing this broadcast errors on some systems, also because it is often related to slow cpu systems…. Really strange….

Crystian182 commented 6 months ago

guys @Nerivec @wastez , it's unbelievable! i managed to get it working!

here it is my steps:

  1. i unplugged the dongle
  2. i flashed the 7.4.3 firmware
  3. i plugged the dongle in, set ember driver, started zigbee2mqtt, enabled debug logs and i got the broadcast errors (and the network was not working): log_7.4.3.log
  4. switched to ezsp again and the network worked: log_7.4.3_ezsp.log
  5. switched to ember, changed the usb port from 1.0 to 3.0, restarted zigbee2mqtt and... working!! log_usb_3.0.log

So, I guess that plugging the dongle into the USB 3.0 port fixed the error for me. Or maybe that ember>ezsp>ember switching? I don't know if it's just a matter of speed, but let's consider that my dongle on the 1.0 port was surrounded by an ethernet cable and a Google Colab TPU.

By the way, I'll monitor my network in the next few days. I see no errors so far except for this one:

[2024-05-19 15:48:57] info: zh:ember:ezsp: Received network/route error ROUTE_ERROR_NO_ROUTE_AVAILABLE for "7448".

Nerivec commented 6 months ago

Good to know! This error is really strange, and the fixes for it are about just as strange 😉

Once you have a good length of logs (the more hours the better), you can run them through https://nerivec.github.io/z2m-ember-helper/ It will give you an idea of how "healthy" your network is, and possibly indications on where there might be problems.

Crystian182 commented 6 months ago

that's really nice, i'll do! very thanks guys!

sjorge commented 6 months ago

@Nerivec I'm assuming the answer is yes, but... does this get properly executed on ember driver? https://github.com/Koenkk/zigbee-herdsman-converters/blob/588b0353bd9246a947922d78d21b778f8a255068/src/index.ts#L409-L427

Those devices are really picky and weird.

Nerivec commented 6 months ago

@sjorge This is way above the driver level. As long as the layers above take care of it, the driver then just sends the resulting frame. I don't have any of these devices, so I can't confirm, but it should break in every driver if it wasn't getting executed properly. The "weird" part could definitely be a clue though. Like Aqara trying to lock you into their eco-system and requiring the adapter to fake being an Aqara hub... zstack had to fake that in the adapter firmware, for emberznet it's done through the driver...

wastez commented 6 months ago

@Crystian182 Could it be that the port the adapter is now is a non usb 3 port, while the other one was? That would make sense for example.

Edit: I saw you now plugged it on a usb 3 port, strange. But usb 1.0 could be to slow, but I don’t know a device today which has only usb 1.0.

Loic691 commented 6 months ago

Here's a link on another thread for ember and Legrand device https://github.com/Koenkk/zigbee2mqtt/issues/22611#issuecomment-2121895754

github-actions[bot] commented 1 week ago

This issue is stale because it has been open 180 days with no activity. Remove stale label or comment or this will be closed in 30 days