Koenkk / zigbee2mqtt

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

Problem changing colors with z2m groups #22386

Open wastez opened 2 weeks ago

wastez commented 2 weeks ago

What happened?

Since I while I’m using z2m group for a group of lights (6 spots). The problem is that if I change colors using the color pallete that it is not working good. Sometimes they are changing the color really slow or some of them do not change the color. If i use Home Assistant groups I don’t have the problem, it is working as it should.

My stick is a sonoff dongle e with ember. I‘m using the z2m 1.37. 0.

What did you expect to happen?

No response

How to reproduce it (minimal and precise)

No response

Zigbee2MQTT version

1.37.0

Adapter firmware version

ezsp ncp 7.4.2

Adapter

Sonoff dongle e

Setup

Addon on Home Assistant

Debug log

No response

wastez commented 2 weeks ago

@Nerivec What do you think about it? The problem was already before 1.37. I don’t think the problem is in the driver.

Nerivec commented 1 week ago

Can you provide some debug-level logs of when this happens?

wastez commented 1 week ago

Ok sorry missed this message

wastez commented 6 days ago

Ok here it is. Network is to busy because of multicasting, you will see it in the logs. debug.log

wastez commented 6 days ago

Can something be done here?

Of course a firmware with higher bitrate could help.

wastez commented 6 days ago

@Nerivec Any thoughts?

Nerivec commented 6 days ago

The Zigbee spec prevents more than 8 broadcasts over a 9-second period. Silabs docs (see paragraph "Broadcast Table").

Filtered logs ```logs [2024-05-10 14:04:11] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=0 messageTag=8 status=SUCCESS] [2024-05-10 14:04:11] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=1 messageTag=9 status=SUCCESS] [2024-05-10 14:04:12] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=2 messageTag=10 status=SUCCESS] [2024-05-10 14:04:12] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=3 messageTag=11 status=SUCCESS] [2024-05-10 14:04:13] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=4 messageTag=12 status=SUCCESS] [2024-05-10 14:04:13] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=5 messageTag=13 status=SUCCESS] [2024-05-10 14:04:14] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=6 messageTag=14 status=SUCCESS] [2024-05-10 14:04:14] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=7 messageTag=15 status=SUCCESS] [2024-05-10 14:04:15] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=8 messageTag=16 status=NETWORK_BUSY] [2024-05-10 14:04:15] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=9 messageTag=17 status=NETWORK_BUSY] [2024-05-10 14:04:16] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=10 messageTag=18 status=NETWORK_BUSY] [2024-05-10 14:04:16] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=11 messageTag=19 status=NETWORK_BUSY] [2024-05-10 14:04:17] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=12 messageTag=20 status=NETWORK_BUSY] [2024-05-10 14:04:17] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=13 messageTag=21 status=NETWORK_BUSY] [2024-05-10 14:04:18] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=14 messageTag=22 status=NETWORK_BUSY] [2024-05-10 14:04:19] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=15 messageTag=23 status=NETWORK_BUSY] [2024-05-10 14:04:19] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=16 messageTag=24 status=NETWORK_BUSY] [2024-05-10 14:04:20] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=17 messageTag=25 status=NETWORK_BUSY] [2024-05-10 14:04:20] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=18 messageTag=26 status=NETWORK_BUSY] [2024-05-10 14:04:21] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=19 messageTag=27 status=NETWORK_BUSY] [2024-05-10 14:04:21] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=20 messageTag=28 status=SUCCESS] [2024-05-10 14:04:21] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=21 messageTag=29 status=SUCCESS] [2024-05-10 14:04:21] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=22 messageTag=30 status=NETWORK_BUSY] [2024-05-10 14:04:22] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=23 messageTag=31 status=NETWORK_BUSY] [2024-05-10 14:04:22] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=24 messageTag=32 status=NETWORK_BUSY] [2024-05-10 14:04:23] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=25 messageTag=33 status=NETWORK_BUSY] [2024-05-10 14:04:23] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=26 messageTag=34 status=NETWORK_BUSY] [2024-05-10 14:04:24] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=27 messageTag=35 status=NETWORK_BUSY] [2024-05-10 14:04:24] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=28 messageTag=36 status=NETWORK_BUSY] [2024-05-10 14:04:25] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=29 messageTag=37 status=NETWORK_BUSY] [2024-05-10 14:04:25] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=30 messageTag=38 status=NETWORK_BUSY] [2024-05-10 14:04:26] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=31 messageTag=39 status=NETWORK_BUSY] [2024-05-10 14:04:26] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=32 messageTag=40 status=SUCCESS] [2024-05-10 14:04:26] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=33 messageTag=41 status=SUCCESS] [2024-05-10 14:04:26] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=34 messageTag=42 status=SUCCESS] [2024-05-10 14:04:26] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=35 messageTag=43 status=SUCCESS] [2024-05-10 14:04:26] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=36 messageTag=44 status=SUCCESS] [2024-05-10 14:04:26] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=37 messageTag=45 status=SUCCESS] [2024-05-10 14:04:27] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=39 messageTag=47 status=NETWORK_BUSY] [2024-05-10 14:04:27] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=40 messageTag=48 status=NETWORK_BUSY] [2024-05-10 14:04:28] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=41 messageTag=49 status=NETWORK_BUSY] [2024-05-10 14:04:28] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=42 messageTag=50 status=NETWORK_BUSY] [2024-05-10 14:04:29] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=43 messageTag=51 status=NETWORK_BUSY] [2024-05-10 14:04:29] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=44 messageTag=52 status=NETWORK_BUSY] [2024-05-10 14:04:30] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=45 messageTag=53 status=NETWORK_BUSY] [2024-05-10 14:04:30] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=46 messageTag=54 status=NETWORK_BUSY] [2024-05-10 14:04:31] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=47 messageTag=55 status=SUCCESS] [2024-05-10 14:04:31] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=48 messageTag=56 status=NETWORK_BUSY] [2024-05-10 14:04:32] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=49 messageTag=57 status=NETWORK_BUSY] [2024-05-10 14:04:32] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=50 messageTag=58 status=NETWORK_BUSY] [2024-05-10 14:04:33] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=51 messageTag=59 status=NETWORK_BUSY] [2024-05-10 14:04:33] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=52 messageTag=60 status=NETWORK_BUSY] [2024-05-10 14:04:34] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=53 messageTag=61 status=NETWORK_BUSY] [2024-05-10 14:04:34] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=54 messageTag=62 status=NETWORK_BUSY] [2024-05-10 14:04:35] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=55 messageTag=63 status=NETWORK_BUSY] [2024-05-10 14:04:35] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=56 messageTag=64 status=NETWORK_BUSY] [2024-05-10 14:04:36] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=57 messageTag=65 status=NETWORK_BUSY] [2024-05-10 14:04:36] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=58 messageTag=66 status=SUCCESS] [2024-05-10 14:04:36] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=59 messageTag=67 status=SUCCESS] [2024-05-10 14:04:36] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=60 messageTag=68 status=NETWORK_BUSY] [2024-05-10 14:04:37] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=61 messageTag=69 status=NETWORK_BUSY] [2024-05-10 14:04:37] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=62 messageTag=70 status=NETWORK_BUSY] [2024-05-10 14:04:38] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=63 messageTag=71 status=NETWORK_BUSY] [2024-05-10 14:04:38] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=64 messageTag=72 status=NETWORK_BUSY] [2024-05-10 14:04:39] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=65 messageTag=73 status=NETWORK_BUSY] [2024-05-10 14:04:39] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=66 messageTag=74 status=NETWORK_BUSY] [2024-05-10 14:04:40] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=67 messageTag=75 status=NETWORK_BUSY] [2024-05-10 14:04:40] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=68 messageTag=76 status=NETWORK_BUSY] [2024-05-10 14:04:41] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=69 messageTag=77 status=NETWORK_BUSY] [2024-05-10 14:04:41] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=70 messageTag=78 status=SUCCESS] [2024-05-10 14:04:41] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=71 messageTag=79 status=SUCCESS] [2024-05-10 14:04:41] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=72 messageTag=80 status=SUCCESS] [2024-05-10 14:04:41] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=73 messageTag=81 status=SUCCESS] [2024-05-10 14:04:41] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=74 messageTag=82 status=SUCCESS] [2024-05-10 14:04:41] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=75 messageTag=83 status=SUCCESS] [2024-05-10 14:04:41] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=76 messageTag=84 status=NETWORK_BUSY] [2024-05-10 14:04:42] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=77 messageTag=85 status=NETWORK_BUSY] [2024-05-10 14:04:42] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=78 messageTag=86 status=NETWORK_BUSY] [2024-05-10 14:04:43] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=79 messageTag=87 status=NETWORK_BUSY] [2024-05-10 14:04:43] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=80 messageTag=88 status=NETWORK_BUSY] [2024-05-10 14:04:44] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=81 messageTag=89 status=NETWORK_BUSY] [2024-05-10 14:04:44] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=82 messageTag=90 status=NETWORK_BUSY] [2024-05-10 14:04:45] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=83 messageTag=91 status=NETWORK_BUSY] [2024-05-10 14:04:46] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=84 messageTag=92 status=NETWORK_BUSY] [2024-05-10 14:04:46] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=85 messageTag=93 status=SUCCESS] [2024-05-10 14:04:46] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=86 messageTag=94 status=NETWORK_BUSY] [2024-05-10 14:04:47] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=87 messageTag=95 status=NETWORK_BUSY] [2024-05-10 14:04:47] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=88 messageTag=96 status=NETWORK_BUSY] [2024-05-10 14:04:48] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=89 messageTag=97 status=NETWORK_BUSY] [2024-05-10 14:04:48] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=90 messageTag=98 status=NETWORK_BUSY] [2024-05-10 14:04:49] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=91 messageTag=99 status=NETWORK_BUSY] [2024-05-10 14:04:49] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=92 messageTag=100 status=NETWORK_BUSY] [2024-05-10 14:04:50] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=93 messageTag=101 status=NETWORK_BUSY] [2024-05-10 14:04:50] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=94 messageTag=102 status=NETWORK_BUSY] [2024-05-10 14:04:51] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=95 messageTag=103 status=NETWORK_BUSY] [2024-05-10 14:04:51] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=96 messageTag=104 status=SUCCESS] [2024-05-10 14:04:51] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=97 messageTag=105 status=SUCCESS] [2024-05-10 14:04:51] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=98 messageTag=106 status=NETWORK_BUSY] [2024-05-10 14:04:52] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=99 messageTag=107 status=NETWORK_BUSY] [2024-05-10 14:04:52] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=100 messageTag=108 status=NETWORK_BUSY] [2024-05-10 14:04:53] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=101 messageTag=109 status=NETWORK_BUSY] [2024-05-10 14:04:53] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=102 messageTag=110 status=NETWORK_BUSY] [2024-05-10 14:04:54] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=103 messageTag=111 status=NETWORK_BUSY] [2024-05-10 14:04:54] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=105 messageTag=112 status=NETWORK_BUSY] [2024-05-10 14:04:55] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=106 messageTag=113 status=NETWORK_BUSY] [2024-05-10 14:04:55] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=107 messageTag=114 status=NETWORK_BUSY] [2024-05-10 14:04:56] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=108 messageTag=115 status=SUCCESS] [2024-05-10 14:04:56] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=109 messageTag=116 status=SUCCESS] [2024-05-10 14:04:56] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=110 messageTag=117 status=SUCCESS] [2024-05-10 14:04:56] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=111 messageTag=118 status=SUCCESS] [2024-05-10 14:04:56] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=112 messageTag=119 status=SUCCESS] [2024-05-10 14:04:56] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=113 messageTag=120 status=SUCCESS] [2024-05-10 14:04:56] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=114 messageTag=121 status=NETWORK_BUSY] [2024-05-10 14:04:56] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=115 messageTag=122 status=NETWORK_BUSY] [2024-05-10 14:04:57] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=116 messageTag=123 status=NETWORK_BUSY] [2024-05-10 14:04:57] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=117 messageTag=124 status=NETWORK_BUSY] [2024-05-10 14:04:58] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=118 messageTag=125 status=NETWORK_BUSY] [2024-05-10 14:04:58] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=119 messageTag=126 status=NETWORK_BUSY] [2024-05-10 14:04:59] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=120 messageTag=127 status=NETWORK_BUSY] [2024-05-10 14:04:59] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=121 messageTag=0 status=NETWORK_BUSY] [2024-05-10 14:05:00] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=122 messageTag=1 status=NETWORK_BUSY] [2024-05-10 14:05:01] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=123 messageTag=2 status=NETWORK_BUSY] [2024-05-10 14:05:01] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=124 messageTag=3 status=SUCCESS] [2024-05-10 14:05:01] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=125 messageTag=4 status=NETWORK_BUSY] [2024-05-10 14:05:02] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=126 messageTag=5 status=NETWORK_BUSY] [2024-05-10 14:05:02] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=127 messageTag=6 status=NETWORK_BUSY] [2024-05-10 14:05:03] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=128 messageTag=7 status=NETWORK_BUSY] [2024-05-10 14:05:03] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=129 messageTag=8 status=NETWORK_BUSY] [2024-05-10 14:05:04] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=130 messageTag=9 status=NETWORK_BUSY] [2024-05-10 14:05:04] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=131 messageTag=10 status=NETWORK_BUSY] [2024-05-10 14:05:05] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=132 messageTag=11 status=NETWORK_BUSY] [2024-05-10 14:05:05] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=133 messageTag=12 status=NETWORK_BUSY] [2024-05-10 14:05:06] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=134 messageTag=13 status=NETWORK_BUSY] [2024-05-10 14:05:06] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=135 messageTag=14 status=SUCCESS] [2024-05-10 14:05:06] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=136 messageTag=15 status=SUCCESS] [2024-05-10 14:05:06] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=137 messageTag=16 status=NETWORK_BUSY] [2024-05-10 14:05:07] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=138 messageTag=17 status=NETWORK_BUSY] [2024-05-10 14:05:07] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=139 messageTag=18 status=NETWORK_BUSY] [2024-05-10 14:05:08] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=140 messageTag=19 status=NETWORK_BUSY] [2024-05-10 14:05:08] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=141 messageTag=20 status=NETWORK_BUSY] [2024-05-10 14:05:09] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=142 messageTag=21 status=NETWORK_BUSY] [2024-05-10 14:05:09] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=143 messageTag=22 status=NETWORK_BUSY] [2024-05-10 14:05:10] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=144 messageTag=23 status=NETWORK_BUSY] [2024-05-10 14:05:10] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=145 messageTag=24 status=NETWORK_BUSY] [2024-05-10 14:05:11] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=146 messageTag=25 status=SUCCESS] [2024-05-10 14:05:11] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=147 messageTag=26 status=SUCCESS] [2024-05-10 14:05:11] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=148 messageTag=27 status=SUCCESS] [2024-05-10 14:05:11] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=149 messageTag=28 status=SUCCESS] [2024-05-10 14:05:11] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=150 messageTag=29 status=SUCCESS] [2024-05-10 14:05:11] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=151 messageTag=30 status=SUCCESS] [2024-05-10 14:05:11] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=152 messageTag=31 status=NETWORK_BUSY] [2024-05-10 14:05:11] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=153 messageTag=32 status=NETWORK_BUSY] [2024-05-10 14:05:12] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=154 messageTag=33 status=NETWORK_BUSY] [2024-05-10 14:05:12] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=155 messageTag=34 status=NETWORK_BUSY] [2024-05-10 14:05:13] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=156 messageTag=35 status=NETWORK_BUSY] [2024-05-10 14:05:13] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=157 messageTag=36 status=NETWORK_BUSY] [2024-05-10 14:05:14] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=158 messageTag=37 status=NETWORK_BUSY] [2024-05-10 14:05:14] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=159 messageTag=38 status=NETWORK_BUSY] [2024-05-10 14:05:15] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=160 messageTag=39 status=NETWORK_BUSY] [2024-05-10 14:05:15] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=161 messageTag=40 status=NETWORK_BUSY] [2024-05-10 14:05:16] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=162 messageTag=41 status=SUCCESS] [2024-05-10 14:05:16] debug: zh:ember:ezsp: ~~~> [SENT type=MULTICAST apsSequence=163 messageTag=42 status=NETWORK_BUSY] ```

That's ~160 broadcasts in roughly 1 minute.... (broadcast/multicast, same limit applies) So averaged that's 2.67, when the limit is 0.89. Definitely too much. 😅

I've been wanting to run some tests on this, see how we could maybe "optimize" it (though definitely not to that extent), but haven't had the time yet, plus I don't have enough devices in my testnet to run this effectively at the moment...

wastez commented 6 days ago

@Nerivec

Ok i can understand that this is much but then z2m groups are nothing to change the colors. If i use home assistant groups then it is working without problems. (clear no multicasting) Can i help you with the tests?

diegocjorge commented 2 days ago

I have the same issue. I have a total of 95 devices, with 57 of them organized into 14 groups (each device belongs to only one group).

My log is full of errors such as:

error: zh:ember: Delivery of MULTICAST failed for '65533' [apsFrame={"profileId":260,"clusterId":768,"sourceEndpoint":1,"destinationEndpoint":255,"options":256,"groupId":13,"sequence":145} messageTag=32]
info: zh:ember:ezsp: Received network/route error ROUTE_ERROR_MANY_TO_ONE_ROUTE_FAILURE for '5742'.

Rarely, I also encounter this:

info: zh:ember:ezsp: Received network/route error ROUTE_ERROR_SOURCE_ROUTE_FAILURE for '22550'.

Is there anything I could do to improve the situation? I already use channel 25 and have my 2.4GHz WiFi on channel 1.

I have a spare Sonoff dongle-P. Do you think it would be better to split my network into two?

Let me know if you would like for me to send some logs.

Nerivec commented 2 days ago

@diegocjorge That would not be the same problem. Yours are failing because it looks like the network isn't very stable, and it can't reach devices properly all the time. Try putting your logs (info level is enough) through this little tool I made https://nerivec.github.io/z2m-ember-helper/ and see what you get (you need several hours worth of logs to get decent feedback, the more the better).

diegocjorge commented 18 hours ago

@diegocjorge That would not be the same problem. Yours are failing because it looks like the network isn't very stable, and it can't reach devices properly all the time. Try putting your logs (info level is enough) through this little tool I made https://nerivec.github.io/z2m-ember-helper/ and see what you get (you need several hours worth of logs to get decent feedback, the more the better).

Thanks @Nerivec, I ran the tool and encountered a few issues:

  1. Broadcast Table Full Detected - This can indicate the network is relying too heavily on broadcasts (messages to the whole network or to groups): Could this be why some of my grouped lights don’t always change color correctly?

  2. ROUTE_ERROR_MANY_TO_ONE_ROUTE_FAILURE: These errors are mostly occurring with Gledopto’s GL-C-001P (5-in-1 Smart LED Controller).

  3. ROUTE_ERROR_ADDRESS_CONFLICT: The tool detected 26 instances of this error, but the device hex does not match any device in my network. Do you have any idea what could be causing this? Could it be an old device still lingering in the database?

  4. CCA Failure Count is High: This is odd because I ran an RF environment scan with my Ubiquiti AP, and it reported that WiFi channel 13 (frequency 2462~2482 MHz) has only 13% utilization and -87 dBm interference. Therefore, Zigbee channel 25 should be mostly clear, and CCA failure shouldn’t be so high.

There might be something broken with my database. I’m considering completely removing Z2M files and starting over from scratch. I'm just pondering whether to keep everything in one network or split it with my old Sonoff Dongle-P. Any suggestions?

Nerivec commented 17 hours ago
  1. It gets problematic if you then see NETWORK_BUSY returned for messages. The broadcast table can hold 15 messages (standard size), you need to reach over that limit before it starts actually being a problem. See "Broadcast table" if you want more details
  2. Some of these is okay, too many can indicate a problem with a router/an area (depends where they originate).
  3. This is weird if the device doesn't match anything in your network (doesn't involve the Z2M database though, this is detected by the adapter directly).
  4. The count has to be at least 10 times higher than the "ideal" before you see this message (15 times if it's red), so something appears to be messing with your 2.4GHz band. Although the "ideal" is from a network with nearly non-existent interferences. What's the actual average per device (check the top table, it's near the right-end)?

Are you using the default Z2M network config (i.e. didn't used GENERATE when you created the network originally)? Any chance there's another Zigbee network around you?

Find me on Discord if you can, when you have some time, we can run some tests, figure out what's best. It should be fine with one network, but you could put "problem routers/devices" in another one for example so they don't mess with the rest.