Random frozen devices after OTAU

[bluemoehre]

Does the issue really belong here?

• [X] I definitively want to report a bug within deCONZ or its REST-API

Is there already an existing issue for this?

• [X] I have searched the existing issues and there is none for the bug at hand

Describe the bug

I noticed recurrently that devices are inresponsive directly after the OTAU and remain unreachable. It happens with a chance of approx 80% with my IKEA & HUE devices. So far I didn't see it with other manufacturers - but that doesn't mean anything since the rest is mostly Hue and updated via their app.

This is how it looks like in deCONZ (2 bulbs are frozen)

In between I tried to restart deCONZ as well as Conbee II, to see if its related to the high uptime - but it's not.

I have also noticed that bulb updates already in progress are interrupted/slowed down when new bulbs appear on the network that also require an update. I saw 3x "updating" at the same time using kinda round robin. (Dunno if this is a problem, but it slows down the whole thing and is more risky than queueing)

To fix the hick-up, I need to enable Pairing Mode at the gateway and also put the bulbs into pairing. So I am finally good now.

EDIT: I force tried updating HUEs via deCONZ and it got stuck the same way.

Steps to reproduce the behavior

1. Download latest firmwares for your devices into deconz folder
2. Restart deCONZ so it will recognize new OTAU images
3. Power on all your devices at the same time

Expected behavior

Devices get updated one by one and behave normal after the process finishes.

Screenshots

No response

Environment

• Host system: PC
• Running method: (Ubuntu / Docker)
• Firmware version: (26720700)
• deCONZ version: 2.22.02 / 19.9.2022
• Device: ConBee II
• Do you use an USB extension cable: yes
• Is there any other USB or serial devices connected to the host system? If so: Which?: multiple external drives

deCONZ Logs

After OTAU:

deconz           | 18:13:11:107 GW firmware version is up to date: 0x26720700
deconz           | 18:13:27:352 0x000B57FFFECB5330 error APSDE-DATA.confirm: 0xD0 on task
deconz           | 18:13:27:353 max transmit errors for node 0x000B57FFFECB5330, last seen by neighbors 1079 s
deconz           | 18:13:41:250 0x000B57FFFEB9314B error APSDE-DATA.confirm: 0xD0 on task
deconz           | 18:13:41:251 max transmit errors for node 0x000B57FFFEB9314B, last seen by neighbors 2412 s
deconz           | 18:13:56:630 0x000B57FFFECB5330 error APSDE-DATA.confirm: 0xD0 on task
deconz           | 18:14:16:734 max transmit errors for node 0x000B57FFFECB5330, last seen by neighbors 1128 s
deconz           | 18:14:27:536 0x000B57FFFEB9314B error APSDE-DATA.confirm: 0xD0 on task
deconz           | 18:14:27:537 max transmit errors for node 0x000B57FFFEB9314B, last seen by neighbors 2458 s

... repeated infinite times

First re-pairing:

deconz           | 18:28:54:105 send permit join, duration: 57
deconz           | 18:29:04:277 0x000B57FFFECB5330 error APSDE-DATA.confirm: 0xD0 on task
deconz           | 18:29:04:278 max transmit errors for node 0x000B57FFFECB5330, last seen by neighbors 2016 s
deconz           | 18:29:08:285 ZCL attribute report 0x001788010CD5ACF1 for cluster: 0x0406, ep: 0x02, frame control: 0x08, mfcode: 0x0000
deconz           | 18:29:08:819 ZCL attribute report 0x001788010BD092DC for cluster: 0x0406, ep: 0x02, frame control: 0x08, mfcode: 0x0000
deconz           | 18:29:10:117 unknown node 0x000B57FFFECB5330 (0xA1D0), lqi: 255
deconz           | 18:29:10:118 0x5DFF nwk changed to 0xA1D0
deconz           | 18:29:10:118 DeviceAnnce of LightNode: 0x000b57fffecb5330 Permit Join: 41
deconz           | 18:29:10:119 device announce 0x000B57FFFECB5330 (0xA1D0) mac capabilities 0x8E
deconz           | 18:29:10:120 device announce 0x000B57FFFECB5330 (0xA1D0) mac capabilities 0x8E
deconz           | 18:29:10:120 DEV Tick.Join: event/device.anounce
deconz           | 18:29:10:121 DEV Tick: fast poll 0x000B57FFFECB5330, mac capabilities: 0x8E
deconz           | 18:29:10:977 restore group  0xFFF0 for lightNode 0x000b57fffecb5330
deconz           | 18:29:11:132 remove dead link for (A0F0, C63F)
deconz           | 18:29:17:848 0x000B57FFFEB9314B error APSDE-DATA.confirm: 0xD0 on task
deconz           | 18:29:17:848 max transmit errors for node 0x000B57FFFEB9314B, last seen by neighbors 3348 s
deconz           | 18:29:18:227 ZCL attribute report 0x001788010CD5ACF1 for cluster: 0x0406, ep: 0x02, frame control: 0x08, mfcode: 0x0000
deconz           | 18:29:20:022 Add to group response for light 18. Status:0x00, capacity: 254
deconz           | 18:29:22:899 ZCL attribute report 0x001788010BD092DC for cluster: 0x0406, ep: 0x02, frame control: 0x08, mfcode: 0x0000
deconz           | 18:29:32:819 ZCL attribute report 0x001788010BCF779F for cluster: 0x0400, ep: 0x02, frame control: 0x08, mfcode: 0x0000
deconz           | 18:29:40:188 0x000B57FFFEB9314B error APSDE-DATA.confirm: 0xD0 on task
deconz           | 18:29:40:189 max transmit errors for node 0x000B57FFFEB9314B, last seen by neighbors 3371 s
deconz           | 18:29:43:759 ZCL attribute report 0x2C1165FFFE0916F9 for cluster: 0x0300, ep: 0x01, frame control: 0x08, mfcode: 0x0000
deconz           | 18:29:47:458 Search sensors done
deconz           | 18:29:48:194 Bind response success for 0x000b57fffecb5330 ep: 0x01 cluster: 0x0000
deconz           | 18:29:48:266 ZCL configure reporting rsp seq: 186 0x000B57FFFECB5330 for ep: 0x01 cluster: 0x0000 attr: 0x4000 status: 0x00
deconz           | 18:29:48:361 Bind response success for 0x000b57fffecb5330 ep: 0x01 cluster: 0x0006
deconz           | 18:29:48:413 ZCL configure reporting rsp seq: 187 0x000B57FFFECB5330 for ep: 0x01 cluster: 0x0006 attr: 0x0000 status: 0x00
deconz           | 18:29:48:483 Bind response success for 0x000b57fffecb5330 ep: 0x01 cluster: 0x0008
deconz           | 18:29:48:554 ZCL configure reporting rsp seq: 188 0x000B57FFFECB5330 for ep: 0x01 cluster: 0x0008 attr: 0x0000 status: 0x00
deconz           | 18:29:50:928 ZCL attribute report 0x001788010CD86925 for cluster: 0x0400, ep: 0x02, frame control: 0x08, mfcode: 0x0000
deconz           | 18:29:55:104 Skip idle timer callback, too early: elapsed 938 msec
deconz           | 18:29:56:105 binding for cluster 0x0000 of 0x14B457FFFE7F419C exists (verified by reporting)
deconz           | 18:29:56:106 binding for cluster 0x0006 of 0x14B457FFFE7F419C exists (verified by reporting)
deconz           | 18:29:56:107 skip configure report for cluster: 0x0006 attr: 0x0000 of node 0x14B457FFFE7F419C (seems to be active)
deconz           | 18:29:56:107 binding for cluster 0x0008 of 0x14B457FFFE7F419C exists (verified by reporting)
deconz           | 18:29:56:108 skip configure report for cluster: 0x0008 attr: 0x0000 of node 0x14B457FFFE7F419C (seems to be active)
deconz           | 18:29:56:108 binding for cluster 0x0300 of 0x14B457FFFE7F419C exists (verified by reporting)
deconz           | 18:29:56:109 skip configure report for cluster: 0x0300 attr: 0x0007 of node 0x14B457FFFE7F419C (seems to be active)
deconz           | 18:29:56:109 skip configure report for cluster: 0x0300 attr: 0x0003 of node 0x14B457FFFE7F419C (seems to be active)
deconz           | 18:29:56:111 skip configure report for cluster: 0x0300 attr: 0x0004 of node 0x14B457FFFE7F419C (seems to be active)
deconz           | 18:29:56:112 skip configure report for cluster: 0x0300 attr: 0x0008 of node 0x14B457FFFE7F419C (seems to be active)
deconz           | 18:29:56:881 ZCL attribute report 0x001788010CD86925 for cluster: 0x0406, ep: 0x02, frame control: 0x08, mfcode: 0x0000
deconz           | 18:30:02:850 0x000B57FFFEB9314B error APSDE-DATA.confirm: 0xD0 on task
deconz           | 18:30:02:851 max transmit errors for node 0x000B57FFFEB9314B, last seen by neighbors 3393 s
deconz           | 18:30:07:656 Bind response success for 0x000b57fffecb5330 ep: 0x01 cluster: 0x0000

Second re-pairing:

deconz           | 18:33:58:105 send permit join, duration: 65
deconz           | 18:34:00:379 ZCL attribute report 0x001788010BD092DC for cluster: 0x0406, ep: 0x02, frame control: 0x08, mfcode: 0x0000
deconz           | 18:34:00:581 ZCL attribute report 0x001788010BD092DC for cluster: 0x0400, ep: 0x02, frame control: 0x08, mfcode: 0x0000
deconz           | 18:34:02:403 ZCL attribute report 0x2C1165FFFE0916F9 for cluster: 0x0006, ep: 0x01, frame control: 0x08, mfcode: 0x0000
deconz           | 18:34:03:160 ZCL attribute report 0x001788010CD5ACF1 for cluster: 0x0406, ep: 0x02, frame control: 0x08, mfcode: 0x0000
deconz           | 18:34:05:619 ZCL attribute report 0x001788010BD092DC for cluster: 0x0400, ep: 0x02, frame control: 0x08, mfcode: 0x0000
deconz           | 18:34:06:194 ZCL attribute report 0x00178801032AC065 for cluster: 0x0406, ep: 0x02, frame control: 0x08, mfcode: 0x0000
deconz           | 18:34:14:790 ZCL attribute report 0x001788010BD092DC for cluster: 0x0406, ep: 0x02, frame control: 0x08, mfcode: 0x0000
deconz           | 18:34:17:704 ZCL attribute report 0x001788010CD5ACF1 for cluster: 0x0406, ep: 0x02, frame control: 0x08, mfcode: 0x0000
deconz           | 18:34:17:918 ZCL attribute report 0x001788010CD5ACF1 for cluster: 0x0400, ep: 0x02, frame control: 0x08, mfcode: 0x0000
deconz           | 18:34:18:559 0x000B57FFFEB9314B error APSDE-DATA.confirm: 0xD0 on task
deconz           | 18:34:18:560 max transmit errors for node 0x000B57FFFEB9314B, last seen by neighbors 3649 s
deconz           | 18:34:19:629 ZCL attribute report 0x70AC08FFFEDCF44C for cluster: 0x0001, ep: 0x01, frame control: 0x08, mfcode: 0x0000
deconz           | 18:34:21:728 Bind response success for 0x70ac08fffedcf44c ep: 0x01 cluster: 0x0000
deconz           | 18:34:23:928 ZCL attribute report 0x001788010CD5ACF1 for cluster: 0x0400, ep: 0x02, frame control: 0x18, mfcode: 0x0000
deconz           | 18:34:26:487 ZCL attribute report 0x14B457FFFE7F419C for cluster: 0x0006, ep: 0x01, frame control: 0x38, mfcode: 0x0000
deconz           | 18:34:28:626 ZCL attribute report 0x001788010CD5ACF1 for cluster: 0x0406, ep: 0x02, frame control: 0x08, mfcode: 0x0000
deconz           | 18:34:31:955 ZCL attribute report 0x001788010BCF779F for cluster: 0x0400, ep: 0x02, frame control: 0x08, mfcode: 0x0000
deconz           | 18:34:33:938 0x840E nwk changed to 0xC488
deconz           | 18:34:33:939 DeviceAnnce of LightNode: 0x000b57fffeb9314b Permit Join: 144
deconz           | 18:34:33:940 device announce 0x000B57FFFEB9314B (0xC488) mac capabilities 0x8E
deconz           | 18:34:33:941 device announce 0x000B57FFFEB9314B (0xC488) mac capabilities 0x8E
deconz           | 18:34:33:941 DEV Tick.Join: event/device.anounce
deconz           | 18:34:33:942 DEV Tick: fast poll 0x000B57FFFEB9314B, mac capabilities: 0x8E
deconz           | 18:34:34:604 delay sending request 30 dt 4 ms to 0x000B57FFFEB9314B, ep: 0x01 cluster: 0x0004 onAir: 1
deconz           | 18:34:34:605 delay sending request 30 dt 4 ms to 0x000B57FFFEB9314B, ep: 0x01 cluster: 0x0004 onAir: 1
deconz           | 18:34:34:704 delay sending request 30 dt 4 ms to 0x000B57FFFEB9314B, ep: 0x01 cluster: 0x0004 onAir: 1
deconz           | 18:34:34:804 delay sending request 30 dt 4 ms to 0x000B57FFFEB9314B, ep: 0x01 cluster: 0x0004 onAir: 1
deconz           | 18:34:34:905 delay sending request 30 dt 4 ms to 0x000B57FFFEB9314B, ep: 0x01 cluster: 0x0004 onAir: 1
deconz           | 18:34:35:004 delay sending request 30 dt 4 ms to 0x000B57FFFEB9314B, ep: 0x01 cluster: 0x0004 onAir: 1
deconz           | 18:34:35:389 restore group  0xFFF0 for lightNode 0x000b57fffeb9314b
deconz           | 18:34:37:916 ZCL attribute report 0x001788010BD092DC for cluster: 0x0406, ep: 0x02, frame control: 0x18, mfcode: 0x0000
deconz           | 18:34:40:019 ZCL attribute report 0x2C1165FFFE0916F9 for cluster: 0x0300, ep: 0x01, frame control: 0x08, mfcode: 0x0000
deconz           | 18:34:40:649 0x000B57FFFEB9314B error APSDE-DATA.confirm: 0xD0 on task
deconz           | 18:34:42:000 ZCL attribute report 0x001788010CD5ACF1 for cluster: 0x0406, ep: 0x02, frame control: 0x08, mfcode: 0x0000
deconz           | 18:34:43:808 ZCL attribute report 0x2C1165FFFE0916F9 for cluster: 0x0300, ep: 0x01, frame control: 0x08, mfcode: 0x0000
deconz           | 18:34:44:104 ZCL attribute report 0x2C1165FFFE0916F9 for cluster: 0x0300, ep: 0x01, frame control: 0x08, mfcode: 0x0000
deconz           | 18:34:44:668 Add to group response for light 19. Status:0x00, capacity: 254
deconz           | 18:34:46:610 ZCL attribute report 0x001788010BD092DC for cluster: 0x0406, ep: 0x02, frame control: 0x08, mfcode: 0x0000
deconz           | 18:34:50:785 ZCL attribute report 0x001788010CD86925 for cluster: 0x0400, ep: 0x02, frame control: 0x08, mfcode: 0x0000
deconz           | 18:34:44:104 ZCL attribute report 0x2C1165FFFE0916F9 for cluster: 0x0300, ep: 0x01, frame control: 0x08, mfcode: 0x0000
deconz           | 18:34:44:668 Add to group response for light 19. Status:0x00, capacity: 254
deconz           | 18:34:46:610 ZCL attribute report 0x001788010BD092DC for cluster: 0x0406, ep: 0x02, frame control: 0x08, mfcode: 0x0000
deconz           | 18:34:50:785 ZCL attribute report 0x001788010CD86925 for cluster: 0x0400, ep: 0x02, frame control: 0x08, mfcode: 0x0000
deconz           | 18:34:56:725 ZCL attribute report 0x001788010CD86925 for cluster: 0x0406, ep: 0x02, frame control: 0x08, mfcode: 0x0000
deconz           | 18:34:59:105 send permit join, duration: 65
deconz           | 18:35:06:049 ZCL attribute report 0x00178801032AC065 for cluster: 0x0406, ep: 0x02, frame control: 0x08, mfcode: 0x0000
deconz           | 18:35:20:397 ZCL attribute report 0x001788010CD86925 for cluster: 0x0402, ep: 0x02, frame control: 0x08, mfcode: 0x0000
deconz           | 18:35:21:105 GW firmware version is up to date: 0x26720700
deconz           | 18:35:26:304 Announced to internet https://phoscon.de/discover
deconz           | 18:35:34:219 ZCL attribute report 0x001788010BD1B540 for cluster: 0x0406, ep: 0x02, frame control: 0x08, mfcode: 0x0000
deconz           | 18:35:46:401 ZCL attribute report 0x0017880106F5A633 for cluster: 0x0402, ep: 0x02, frame control: 0x08, mfcode: 0x0000
deconz           | 18:36:00:105 send permit join, duration: 57
deconz           | 18:36:03:945 0x001788010bf58900 found group 0xFFF0
deconz           | 18:36:03:946 0x001788010bf58900 found group 0x0015
deconz           | 18:36:19:222 ZCL attribute report 0x001788010BCF779F for cluster: 0x0402, ep: 0x02, frame control: 0x08, mfcode: 0x0000
deconz           | 18:36:30:993 ZCL attribute report 0x00178801032AC065 for cluster: 0x0400, ep: 0x02, frame control: 0x08, mfcode: 0x0000
deconz           | 18:36:37:696 0x00178801084b3738 found group 0xFFF0
deconz           | 18:36:37:697 0x00178801084b3738 found group 0x0005
deconz           | 18:36:37:697 0x00178801084b3738 found group 0x0006
deconz           | 18:36:47:426 0x00178801097a346d found group 0xFFF0
deconz           | 18:36:47:427 0x00178801097a346d found group 0x000C
deconz           | 18:36:52:696 0x001788010b50b3e0 found group 0xFFF0
deconz           | 18:36:52:697 0x001788010b50b3e0 found group 0x0016
deconz           | 18:36:57:105 send permit join, duration: 0
deconz           | 18:36:57:622 ZCL attribute report 0x54EF44100075D06C for cluster: 0x0006, ep: 0x01, frame control: 0x18, mfcode: 0x0000
deconz           | 18:36:57:940 Search sensors done
deconz           | 18:37:07:187 Bind response success for 0x000b57fffeb9314b ep: 0x01 cluster: 0x0000
deconz           | 18:37:07:278 ZCL configure reporting rsp seq: 145 0x000B57FFFEB9314B for ep: 0x01 cluster: 0x0000 attr: 0x4000 status: 0x00
deconz           | 18:37:07:393 Bind response success for 0x000b57fffeb9314b ep: 0x01 cluster: 0x0006
deconz           | 18:37:07:459 ZCL configure reporting rsp seq: 146 0x000B57FFFEB9314B for ep: 0x01 cluster: 0x0006 attr: 0x0000 status: 0x00
deconz           | 18:37:07:563 Bind response success for 0x000b57fffeb9314b ep: 0x01 cluster: 0x0008
deconz           | 18:37:07:673 ZCL configure reporting rsp seq: 148 0x000B57FFFEB9314B for ep: 0x01 cluster: 0x0008 attr: 0x0000 status: 0x00
deconz           | 18:37:14:534 ZCL attribute report 0x001788010BCF6A64 for cluster: 0x0402, ep: 0x02, frame control: 0x08, mfcode: 0x0000

Additional context

Currently I run approx. 60 devices in my network:

• 50% IKEA
• 40% Hue
• 5% Xiaomi
• 5% dresden electronics

[bluemoehre]

Update: I added an OTAU image for a bunch of my HUE bulbs. deCONZ tried to update them all at once. That caused the network to be almost inresponsible. Huge delays (1-5s) in commands and after hours the OTAU page still showed the update timers stuck at minutes. Not a single device was updated successfully.

Logs look similar to above. But I gonna put more which looks interesting to me

Logs:

deconz           | 01:41:18:953 0x54EF44100075D06C error APSDE-DATA.confirm: 0xA7 on task
deconz           | 01:41:18:953 max transmit errors for node 0x54EF44100075D06C, last seen by neighbors 91 s
deconz           | 01:41:33:524 0x54EF44100075D06C error APSDE-DATA.confirm: 0xA7 on task
deconz           | 01:41:33:524 max transmit errors for node 0x54EF44100075D06C, last seen by neighbors 106 s
deconz           | 01:41:48:224 0x54EF44100075D06C error APSDE-DATA.confirm: 0xA7 on task
deconz           | 01:41:48:225 max transmit errors for node 0x54EF44100075D06C, last seen by neighbors 120 s
deconz           | 01:41:58:473 0x54EF44100075D06C error APSDE-DATA.confirm: 0xA7 on task
deconz           | 01:41:58:473 max transmit errors for node 0x54EF44100075D06C, last seen by neighbors 7 s
deconz           | 01:42:12:552 0x54EF44100075D06C error APSDE-DATA.confirm: 0xA7 on task
deconz           | 01:42:12:552 max transmit errors for node 0x54EF44100075D06C, last seen by neighbors 21 s
deconz           | 01:42:29:403 0x54EF44100075D06C error APSDE-DATA.confirm: 0xA7 on task
deconz           | 01:42:29:403 max transmit errors for node 0x54EF44100075D06C, last seen by neighbors 38 s
deconz           | 01:42:46:065 0x54EF44100075D06C error APSDE-DATA.confirm: 0xA7 on task
deconz           | 01:42:46:066 max transmit errors for node 0x54EF44100075D06C, last seen by neighbors 55 s
deconz           | 01:42:56:156 0x54EF44100075D06C error APSDE-DATA.confirm: 0xA7 on task
deconz           | 01:42:56:156 max transmit errors for node 0x54EF44100075D06C, last seen by neighbors 65 s
deconz           | 01:43:07:985 0x54EF44100075D06C error APSDE-DATA.confirm: 0xA7 on task
deconz           | 01:43:07:986 max transmit errors for node 0x54EF44100075D06C, last seen by neighbors 77 s

deconz           | 02:52:04:605 delay sending request 234 dt 0 ms to 0x001788010B50B526, ep: 0x0B cluster: 0x0300 onAir: 1
deconz           | 02:52:04:606 delay sending request 236 dt 0 ms to 0x001788010B50B526, ep: 0x0B cluster: 0x0008 onAir: 1
deconz           | 02:52:04:704 delay sending request 234 dt 0 ms to 0x001788010B50B526, ep: 0x0B cluster: 0x0300 onAir: 1
deconz           | 02:52:04:704 delay sending request 236 dt 0 ms to 0x001788010B50B526, ep: 0x0B cluster: 0x0008 onAir: 1
deconz           | 02:52:04:792 delay sending request 234 dt 0 ms to 0x001788010B50B526, ep: 0x0B cluster: 0x0300 onAir: 1
deconz           | 02:52:04:793 delay sending request 236 dt 0 ms to 0x001788010B50B526, ep: 0x0B cluster: 0x0008 onAir: 1
deconz           | 02:52:04:796 delay sending request 234 dt 0 ms to 0x001788010B50B526, ep: 0x0B cluster: 0x0300 onAir: 1
deconz           | 02:52:04:797 delay sending request 236 dt 0 ms to 0x001788010B50B526, ep: 0x0B cluster: 0x0008 onAir: 1
deconz           | 02:52:04:797 delay sending request 244 dt 0 ms to 0x001788010971B077, ep: 0x0B cluster: 0x0300 onAir: 1
deconz           | 02:52:04:797 delay sending request 245 dt 0 ms to 0x001788010971B077, ep: 0x0B cluster: 0x0300 onAir: 1
deconz           | 02:52:04:798 delay sending request 247 dt 0 ms to 0x001788010971B077, ep: 0x0B cluster: 0x0008 onAir: 1
deconz           | 02:52:04:805 delay sending request 234 dt 0 ms to 0x001788010B50B526, ep: 0x0B cluster: 0x0300 onAir: 1
deconz           | 02:52:04:805 delay sending request 236 dt 0 ms to 0x001788010B50B526, ep: 0x0B cluster: 0x0008 onAir: 1
deconz           | 02:52:04:805 delay sending request 244 dt 0 ms to 0x001788010971B077, ep: 0x0B cluster: 0x0300 onAir: 1
deconz           | 02:52:04:806 delay sending request 245 dt 0 ms to 0x001788010971B077, ep: 0x0B cluster: 0x0300 onAir: 1
deconz           | 02:52:04:806 delay sending request 247 dt 0 ms to 0x001788010971B077, ep: 0x0B cluster: 0x0008 onAir: 1
deconz           | 02:52:04:904 delay sending request 234 dt 0 ms to 0x001788010B50B526, ep: 0x0B cluster: 0x0300 onAir: 1
deconz           | 02:52:04:905 delay sending request 236 dt 0 ms to 0x001788010B50B526, ep: 0x0B cluster: 0x0008 onAir: 1
deconz           | 02:52:04:905 delay sending request 244 dt 0 ms to 0x001788010971B077, ep: 0x0B cluster: 0x0300 onAir: 1
deconz           | 02:52:04:906 delay sending request 245 dt 0 ms to 0x001788010971B077, ep: 0x0B cluster: 0x0300 onAir: 1
deconz           | 02:52:04:906 delay sending request 247 dt 0 ms to 0x001788010971B077, ep: 0x0B cluster: 0x0008 onAir: 1
deconz           | 02:52:05:004 delay sending request 234 dt 0 ms to 0x001788010B50B526, ep: 0x0B cluster: 0x0300 onAir: 1
deconz           | 02:52:05:004 delay sending request 236 dt 0 ms to 0x001788010B50B526, ep: 0x0B cluster: 0x0008 onAir: 1
deconz           | 02:52:05:005 delay sending request 244 dt 0 ms to 0x001788010971B077, ep: 0x0B cluster: 0x0300 onAir: 1
deconz           | 02:52:05:005 delay sending request 245 dt 0 ms to 0x001788010971B077, ep: 0x0B cluster: 0x0300 onAir: 1
deconz           | 02:52:05:005 delay sending request 247 dt 0 ms to 0x001788010971B077, ep: 0x0B cluster: 0x0008 onAir: 1
deconz           | 02:52:05:104 delay sending request 234 dt 1 ms to 0x001788010B50B526, ep: 0x0B cluster: 0x0300 onAir: 1
deconz           | 02:52:05:105 delay sending request 236 dt 1 ms to 0x001788010B50B526, ep: 0x0B cluster: 0x0008 onAir: 1
deconz           | 02:52:05:105 delay sending request 244 dt 1 ms to 0x001788010971B077, ep: 0x0B cluster: 0x0300 onAir: 1
deconz           | 02:52:05:105 delay sending request 245 dt 1 ms to 0x001788010971B077, ep: 0x0B cluster: 0x0300 onAir: 1
deconz           | 02:52:05:106 delay sending request 247 dt 1 ms to 0x001788010971B077, ep: 0x0B cluster: 0x0008 onAir: 1
deconz           | 02:52:05:205 delay sending request 234 dt 1 ms to 0x001788010B50B526, ep: 0x0B cluster: 0x0300 onAir: 1
deconz           | 02:52:05:205 delay sending request 236 dt 1 ms to 0x001788010B50B526, ep: 0x0B cluster: 0x0008 onAir: 1
deconz           | 02:52:05:205 delay sending request 244 dt 1 ms to 0x001788010971B077, ep: 0x0B cluster: 0x0300 onAir: 1
deconz           | 02:52:05:206 delay sending request 245 dt 1 ms to 0x001788010971B077, ep: 0x0B cluster: 0x0300 onAir: 1
deconz           | 02:52:05:206 delay sending request 247 dt 1 ms to 0x001788010971B077, ep: 0x0B cluster: 0x0008 onAir: 1
deconz           | 02:52:05:240 delay sending request 234 dt 1 ms to 0x001788010B50B526, ep: 0x0B cluster: 0x0300 onAir: 1
deconz           | 02:52:05:240 delay sending request 236 dt 1 ms to 0x001788010B50B526, ep: 0x0B cluster: 0x0008 onAir: 1
deconz           | 02:52:05:241 delay sending request 244 dt 1 ms to 0x001788010971B077, ep: 0x0B cluster: 0x0300 onAir: 1
deconz           | 02:52:05:241 delay sending request 245 dt 1 ms to 0x001788010971B077, ep: 0x0B cluster: 0x0300 onAir: 1
deconz           | 02:52:05:241 delay sending request 247 dt 1 ms to 0x001788010971B077, ep: 0x0B cluster: 0x0008 onAir: 1
deconz           | 02:52:05:245 delay sending request 234 dt 1 ms to 0x001788010B50B526, ep: 0x0B cluster: 0x0300 onAir: 1
deconz           | 02:52:05:245 delay sending request 236 dt 1 ms to 0x001788010B50B526, ep: 0x0B cluster: 0x0008 onAir: 1
deconz           | 02:52:05:245 delay sending request 244 dt 1 ms to 0x001788010971B077, ep: 0x0B cluster: 0x0300 onAir: 1
deconz           | 02:52:05:246 delay sending request 245 dt 1 ms to 0x001788010971B077, ep: 0x0B cluster: 0x0300 onAir: 1
deconz           | 02:52:05:246 delay sending request 247 dt 1 ms to 0x001788010971B077, ep: 0x0B cluster: 0x0008 onAir: 1
deconz           | 02:52:05:246 delay sending request 250 dt 0 ms to 0x00178801097A346D, ep: 0x0B cluster: 0x0300 onAir: 1
deconz           | 02:52:05:246 delay sending request 251 dt 0 ms to 0x00178801097A346D, ep: 0x0B cluster: 0x0300 onAir: 1
deconz           | 02:52:05:247 delay sending request 253 dt 0 ms to 0x00178801097A346D, ep: 0x0B cluster: 0x0008 onAir: 1
deconz           | 02:52:05:304 delay sending request 234 dt 1 ms to 0x001788010B50B526, ep: 0x0B cluster: 0x0300 onAir: 1
deconz           | 02:52:05:304 delay sending request 236 dt 1 ms to 0x001788010B50B526, ep: 0x0B cluster: 0x0008 onAir: 1
deconz           | 02:52:05:305 delay sending request 244 dt 1 ms to 0x001788010971B077, ep: 0x0B cluster: 0x0300 onAir: 1
deconz           | 02:52:05:305 delay sending request 245 dt 1 ms to 0x001788010971B077, ep: 0x0B cluster: 0x0300 onAir: 1
deconz           | 02:52:05:305 delay sending request 247 dt 1 ms to 0x001788010971B077, ep: 0x0B cluster: 0x0008 onAir: 1
deconz           | 02:52:05:305 delay sending request 250 dt 0 ms to 0x00178801097A346D, ep: 0x0B cluster: 0x0300 onAir: 1
deconz           | 02:52:05:306 delay sending request 251 dt 0 ms to 0x00178801097A346D, ep: 0x0B cluster: 0x0300 onAir: 1
deconz           | 02:52:05:306 delay sending request 253 dt 0 ms to 0x00178801097A346D, ep: 0x0B cluster: 0x0008 onAir: 1
deconz           | 02:52:05:321      0x001788010971B077 force poll (2)
deconz           | 02:52:05:321 delay sending request 234 dt 1 ms to 0x001788010B50B526, ep: 0x0B cluster: 0x0300 onAir: 1
deconz           | 02:52:05:321 delay sending request 236 dt 1 ms to 0x001788010B50B526, ep: 0x0B cluster: 0x0008 onAir: 1
deconz           | 02:52:05:339      0x00178801097A346D force poll (2)
deconz           | 02:52:05:340 delay sending request 234 dt 1 ms to 0x001788010B50B526, ep: 0x0B cluster: 0x0300 onAir: 1
deconz           | 02:52:05:340 delay sending request 236 dt 1 ms to 0x001788010B50B526, ep: 0x0B cluster: 0x0008 onAir: 1

deconz           | 03:04:23:415         0x4C5BB3FFFEC27A4A force poll (2)
deconz           | 03:04:23:472         0x4C5BB3FFFEC27A4A force poll (2)
deconz           | 03:04:37:931         0x001788010B50B526 force poll (2)
deconz           | 03:04:38:053         0x00178801065018ED force poll (2)
deconz           | 03:04:38:063         0x001788010B50B526 force poll (2)
deconz           | 03:04:38:875         0x00178801065018ED force poll (2)
deconz           | 03:04:38:902         0x001788010B50B526 force poll (2)
deconz           | 03:04:38:931         0x00178801097A346D force poll (2)
deconz           | 03:04:38:974         0x00178801065018ED force poll (2)
deconz           | 03:04:38:992         0x00178801097A346D force poll (2)
deconz           | 03:04:39:073         0x001788010971B077 force poll (2)
deconz           | 03:04:39:114         0x001788010971B077 force poll (2)
deconz           | 03:04:39:164         0x001788010971B077 force poll (2)
deconz           | 03:04:40:083         0x00178801097A346D force poll (2)

deconz           | 03:36:07:072 0x00178801096FF44D error APSDE-DATA.confirm: 0xA7 on task
deconz           | 03:36:07:104 5 running tasks, wait
deconz           | 03:36:07:204 5 running tasks, wait
deconz           | 03:36:07:305 5 running tasks, wait
deconz           | 03:36:07:404 5 running tasks, wait
deconz           | 03:36:07:505 5 running tasks, wait
deconz           | 03:36:07:605 5 running tasks, wait
deconz           | 03:36:07:704 5 running tasks, wait
deconz           | 03:36:07:805 5 running tasks, wait
deconz           | 03:36:07:904 5 running tasks, wait
deconz           | 03:36:08:004 5 running tasks, wait
deconz           | 03:36:08:105 5 running tasks, wait
deconz           | 03:36:08:205 5 running tasks, wait
deconz           | 03:36:08:304 5 running tasks, wait
deconz           | 03:36:08:405 5 running tasks, wait
deconz           | 03:36:08:504 5 running tasks, wait
deconz           | 03:36:08:604 5 running tasks, wait
deconz           | 03:36:08:704 5 running tasks, wait
deconz           | 03:36:08:805 5 running tasks, wait
deconz           | 03:36:08:904 5 running tasks, wait
deconz           | 03:36:09:004 5 running tasks, wait
deconz           | 03:36:09:104 5 running tasks, wait
deconz           | 03:36:09:204 5 running tasks, wait
deconz           | 03:36:09:305 5 running tasks, wait
deconz           | 03:36:09:405 5 running tasks, wait
deconz           | 03:36:09:504 5 running tasks, wait
deconz           | 03:36:09:604 5 running tasks, wait
deconz           | 03:36:09:704 5 running tasks, wait
deconz           | 03:36:09:805 5 running tasks, wait
deconz           | 03:36:09:905 5 running tasks, wait
deconz           | 03:36:10:005 5 running tasks, wait
deconz           | 03:36:10:105 5 running tasks, wait
deconz           | 03:36:10:204 5 running tasks, wait
deconz           | 03:36:10:305 5 running tasks, wait
deconz           | 03:36:10:405 5 running tasks, wait
deconz           | 03:36:10:505 5 running tasks, wait
deconz           | 03:36:10:604 5 running tasks, wait
deconz           | 03:36:10:662 0x001788010B50B3E0 error APSDE-DATA.confirm: 0xA7 on task
deconz           | 03:36:10:663 delay sending request 15 dt 4 ms to 0x00178801096FF44D, ep: 0x0B cluster: 0x0300 onAir: 1
deconz           | 03:36:10:706 5 running tasks, wait
deconz           | 03:36:10:805 5 running tasks, wait
deconz           | 03:36:10:905 5 running tasks, wait
deconz           | 03:36:11:005 5 running tasks, wait
deconz           | 03:36:11:104 5 running tasks, wait

[Mimiix]

Asked devs to checkin. However, this looks like an issue that was fixed before.

In the meanwhile, can you unplug the conbee/raspbee and re-plug and see what happens?

[bluemoehre]

I did that more than once, but this issue is recurring =/

In the end I aborted the updates and did it manually on some bulbs, which worked fine.

[bluemoehre]

Hey @Mimiix , I just want to let you know the problem is growing dramatically with the number of devices. I added like 8 more things to the network (in total about 70 now) and I need to reboot the Conbee II / deCONZ like every two days since the logs get flooded with delay sending request & 5 running tasks, wait entries.

Automations are often stalled/hanging. Sometimes lights just get turned on at minimum brightness (last state) but the command to bring them to 100% is delayed. There are also situations in which only part of a group reacts. And the worst thing is when you come home when it's already dark and nothing reacts at all. Either the sensor events are not getting received or the automation cannot be run due to the (whatever) dead lock.

In a short: this is unusable at the moment to me. I cannot recommend tagging the current v2.24.1-beta version as stable until this is fixed. I dunno how to help you guys debug this, so just let me know what I can do. Thanks a lot for your support!

[rikroe]

EDIT: Issue seems to have been caused by me moving something near the Conbee stick which caused it to sit directly on the metal enclosure of the host PC. Adding a 1.5m USB extension and placing the stick somewhere else helped (at least with 2.23.2). Will update to 2.24.1 later and report back

---

I also see massive freezes after 2.24.1. For me, not even replugging my Conbee I worked.

I only see a lot of error like 0xDC8E95FFFE52A644 error APSDE-DATA.confirm: 0xE1 on task.

I have less than 15 devices connected.

What I did:

• Upgrade to 2.24.1
• Run OTA updates on 3 IKEA bulbs (thats why I'm posting it here, not as a separate issue)
  • I actually paired two of the bulbs directly with one IKEA remote and the last one with another remote
• Repaired the IKEA bulbs

It worked fine for a couple of hourse, then nothing worked anymore and the Phoscon UI was very slow (clicking on Devices > Lights took ~5 seconds to load).

Steps I've tried:

• Restarting the Docker container
• Restarting the PC the container is running on
• Removing my Conbee I and waiting for 10 minutes before plugging it back in
• Physically turning off the bulb that show error messages (there are some that always show errors, some only once or twice)
• Removing the bulb with most errors via deCONZ GUI (error messages are still shown)
• Downgrading to stable (2.23.2)

The only thing that is still working is controlling the 3 IKEA lights with the remotes directly connected to them (the remote shows up as a group in deCONZ).

Using 2.24.1, I created the following debug logs. I hope this helps in pinning down the issue.

2023-11-13_deconz_logs-debug.txt

Thanks!

[Mimiix]

Hey @Mimiix , I just want to let you know the problem is growing dramatically with the number of devices. I added like 8 more things to the network (in total about 70 now) and I need to reboot the Conbee II / deCONZ like every two days since the logs get flooded with delay sending request & 5 running tasks, wait entries.

Automations are often stalled/hanging. Sometimes lights just get turned on at minimum brightness (last state) but the command to bring them to 100% is delayed. There are also situations in which only part of a group reacts. And the worst thing is when you come home when it's already dark and nothing reacts at all. Either the sensor events are not getting received or the automation cannot be run due to the (whatever) dead lock.

In a short: this is unusable at the moment to me. I cannot recommend tagging the current v2.24.1-beta version as stable until this is fixed. I dunno how to help you guys debug this, so just let me know what I can do. Thanks a lot for your support!

Ive forwarded this. But no response.

@manup can you check in?

[Mimiix]

EDIT: Issue seems to have been caused by me moving something near the Conbee stick which caused it to sit directly on the metal enclosure of the host PC. Adding a 1.5m USB extension and placing the stick somewhere else helped (at least with 2.23.2). Will update to 2.24.1 later and report back

I also see massive freezes after 2.24.1. For me, not even replugging my Conbee I worked.

I only see a lot of error like 0xDC8E95FFFE52A644 error APSDE-DATA.confirm: 0xE1 on task.

I have less than 15 devices connected.

What I did:

• Upgrade to 2.24.1

• Run OTA updates on 3 IKEA bulbs (thats why I'm posting it here, not as a separate issue)

  • I actually paired two of the bulbs directly with one IKEA remote and the last one with another remote
• Repaired the IKEA bulbs

It worked fine for a couple of hourse, then nothing worked anymore and the Phoscon UI was very slow (clicking on Devices > Lights took ~5 seconds to load).

Steps I've tried:

• Restarting the Docker container
• Restarting the PC the container is running on
• Removing my Conbee I and waiting for 10 minutes before plugging it back in
• Physically turning off the bulb that show error messages (there are some that always show errors, some only once or twice)
• Removing the bulb with most errors via deCONZ GUI (error messages are still shown)
• Downgrading to stable (2.23.2)

The only thing that is still working is controlling the 3 IKEA lights with the remotes directly connected to them (the remote shows up as a group in deCONZ).

Using 2.24.1, I created the following debug logs. I hope this helps in pinning down the issue.

2023-11-13_deconz_logs-debug.txt

Thanks!

Hi

Prior your edit I was going to say that your issue is related to interference , which you indeed concluded.

It is not related to this issue, so for any more support on that I'd like to ask you to open a forumpost.

[manup]

just want to let you know the problem is growing dramatically with the number of devices. I added like 8 more things to the network (in total about 70 now) and I need to reboot the Conbee II / deCONZ like every two days since the logs get flooded with delay sending request & 5 running tasks, wait entries.

The delay sending request & 5 running tasks is related to legacy code perhaps doing something strange. We got many Ikea and Hue DDFs recently which is good, but might need to deactivate more legacy code for these devices. The 2023-11-13_deconz_logs-debug.txt doesn't show the task logging, would be helpful to see in the logs where the messages appear + the related APS commands to filter out what is queued up here.

[github-actions[bot]]

As there has not been any response in 21 days, this issue has been automatically marked as stale. At OP: Please either close this issue or keep it active It will be closed in 7 days if no further activity occurs.

[github-actions[bot]]

As there has not been any response in 28 days, this issue will be closed. @ OP: If this issue is solved post what fixed it for you. If it is not solved, request to get this opened again.

[bluemoehre]

Again this bot just closed an issue which isn't solved. @manup would you mind to re-open? And I'm afraid you mixed the messages with @rikroe since your post comments my one but refers to his debug log?

[Mimiix]

Again this bot just closed an issue which isn't solved. @manup would you mind to re-open? And I'm afraid you mixed the messages with @rikroe since your post comments my one but refers to his debug log?

The bot is clear on what to do when it expires. If there's no response, it closes. Next time, please follow the bit message.

Reopening on request.

[bluemoehre]

Hi @mimix, thank u for re-opening this. In first place I understood the question was asked to rikroe since his debug log was quoted. That's why I expected him to answer. Then I was off for a few days and didn't see the warning in time.

@manup how can I help you helping me:

but might need to deactivate more legacy code for these devices

Can I do anything here?

would be helpful to see in the logs where the messages appear + the related APS commands to filter out what is queued up here

What do you need exactly and where do I find it? I need a bit more explanation to this.

[github-actions[bot]]

As there has not been any response in 21 days, this issue has been automatically marked as stale. At OP: Please either close this issue or keep it active It will be closed in 7 days if no further activity occurs.

[bluemoehre]

bump

[github-actions[bot]]

As there has not been any response in 21 days, this issue has been automatically marked as stale. At OP: Please either close this issue or keep it active It will be closed in 7 days if no further activity occurs.

[github-actions[bot]]

As there has not been any response in 28 days, this issue will be closed. @ OP: If this issue is solved post what fixed it for you. If it is not solved, request to get this opened again.