Deconz-rest-plugin: New install of lights get poor performance after 24h

[Kane610]

So I've done a move for most of my lights from my hue bridge over to my conbee + deconz on x86. 7 hue lights with the latest firmware, 1 osram rgbw led strip and one Ikea tunable white gu10 and one Ikea motion detector. It all worked great and was responsive the first 24h.

Until tonight where my plan was to add a hue remote to control certain lights. After this I have to spam any setting I want to send to the lights to get a reaction. All hue lights have been installed together on the bridge for 2 years and I have never had any issue like this before.

I removed the battery from the remote to get it out of the picture, but it didn't really have any effect.

I see a lot of posts like this in the logs and I don't know if this is relevant.

Feb 21 23:42:41 debbie deCONZ[6582]: 23:42:41:207 unhandled APS-DATA.confirm id: 180 status 0xE1
Feb 21 23:42:41 debbie deCONZ[6582]: 23:42:41:784 unhandled APS-DATA.confirm id: 193 status 0xE1
Feb 21 23:42:52 debbie deCONZ[6582]: 23:42:52:069 CTRL got nwk update id 4
Feb 21 23:42:55 debbie deCONZ[6582]: 23:42:55:081 unhandled APS-DATA.confirm id: 24 status 0xE1
Feb 21 23:42:56 debbie deCONZ[6582]: 23:42:56:074 unhandled APS-DATA.confirm id: 39 status 0xE1
Feb 21 23:42:56 debbie deCONZ[6582]: 23:42:56:731 unhandled APS-DATA.confirm id: 47 status 0xE1
Feb 21 23:42:57 debbie deCONZ[6582]: 23:42:57:147 unhandled APS-DATA.confirm id: 49 status 0xE1
Feb 21 23:42:57 debbie deCONZ[6582]: 23:42:57:436 unhandled APS-DATA.confirm id: 52 status 0xE1
Feb 21 23:42:58 debbie deCONZ[6582]: 23:42:58:653 unhandled APS-DATA.confirm id: 68 status 0xE1
Feb 21 23:42:59 debbie deCONZ[6582]: 23:42:59:134 unhandled APS-DATA.confirm id: 75 status 0xE1

How can I help you get to the bottom of this? Deconz is running on 2.05.04.

/R

[manup]

Looks like something is stuck, can you please show log file by starting deCONZ like:

$ deCONZ --http-port=80 --dbg-info=1 --dbg-aps=1

When we see which requests to which device are causing this.

Further questions:

• What is the version of ConBee firmware (deCONZ > Help > About)
• Are the IKEA bulbs at latest version?

There is a little python script to get IKEA firmware for deCONZ OTA:
https://github.com/dresden-elektronik/deconz-rest-plugin/blob/master/ikea-ota-download.py

[Kane610]

I will get right on this tonight.

I think I saw in the logs that Conbee had latest version, there is no update button in settings. I'm running headless so I guess I can see it in the logs otherwise?

The Ikea light was bought a month ago, will check version.

[Kane610]

17:35:11:029 GW firmware version: 0x261e0500
17:35:11:029 GW firmware version is up to date: 0x261e0500
Unsupported device protocol version: 0x0106
0x000B57FFFEE89915 error APSDE-DATA.confirm: 0xA7 on task

I see a lot of these
17:33:21:125 APS-DATA.request id: 247, addrmode: 0x03, addr: 0x00178801027a3dd1, profile: 0x0104, cluster: 0x0008, ep: 0x0B queue: 0 len: 5
17:33:21:348 0x00178801027A3DD1 error APSDE-DATA.confirm: 0xE1 on task
17:33:21:348 APS-DATA.confirm id: 247, status: 0xE1
17:33:21:425 APS-DATA.request id: 252, addrmode: 0x03, addr: 0x00178801027a3dd1, profile: 0x0104, cluster: 0x0300, ep: 0x0B queue: 0 len: 17
17:33:21:653 0x00178801027A3DD1 error APSDE-DATA.confirm: 0xE1 on task
17:33:21:653 APS-DATA.confirm id: 252, status: 0xE1
17:33:21:825 APS-DATA.request id: 255, addrmode: 0x03, addr: 0x001788010116e301, profile: 0x0104, cluster: 0x0006, ep: 0x0B queue: 0 len: 5
17:33:21:941 0x001788010116E301 error APSDE-DATA.confirm: 0xE1 on task
17:33:21:941 APS-DATA.confirm id: 255, status: 0xE1
17:33:22:125 APS-DATA.request id: 2, addrmode: 0x03, addr: 0x001788010116e301, profile: 0x0104, cluster: 0x0008, ep: 0x0B queue: 0 len: 5
17:33:22:229 0x001788010116E301 error APSDE-DATA.confirm: 0xE1 on task
17:33:22:229 APS-DATA.confirm id: 2, status: 0xE1
17:33:22:326 APS-DATA.request id: 3, addrmode: 0x03, addr: 0x001788010116e301, profile: 0x0104, cluster: 0x0300, ep: 0x0B queue: 0 len: 17
17:33:22:566 0x001788010116E301 error APSDE-DATA.confirm: 0xE1 on task
17:33:22:566 APS-DATA.confirm id: 3, status: 0xE1

Sending a dim down to one hue rgb e27 light takes a few seconds to react

17:51:18:414 APS-DATA.request id: 177, addrmode: 0x02, addr: 0x0000, profile: 0x0000, cluster: 0x0031, ep: 0x00 queue: 0 len: 2
17:51:18:448 APS-DATA.confirm id: 177, status: 0x00 SUCCESS
17:51:18:448 APS-DATA.confirm request id: 177 -> confirmed, timeout 59920
17:51:18:480 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x0031, lqi: 0, rssi: 0
17:51:18:512 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x8031, lqi: 0, rssi: 0
17:51:18:512 APS-DATA.indication request id: 177 -> finished
17:51:18:512 APS-DATA.request id: 177 erase from queue
17:51:18:740 Content not completely loaded (got 0 of 48), wait 20ms
17:51:18:741 APS-DATA.request id: 183, addrmode: 0x03, addr: 0x00178801027a3dd1, profile: 0x0104, cluster: 0x0008, ep: 0x0B queue: 0 len: 6
17:51:19:057 APS-DATA.indication srcAddr: 0x7cb03eaa000026a9, dstAddrMode: 2, profile: 0x0104, cluster: 0x0008, lqi: 231, rssi: 0
17:51:19:057 ZCL attribute report 0x7CB03EAA000026A9 for cluster 0x0008, ep 0x03
17:51:19:057 0x7CB03EAA000026A9 level 0 --> 178
17:51:23:694 APS-DATA.request id: 215, addrmode: 0x02, addr: 0x0000, profile: 0x0000, cluster: 0x0031, ep: 0x00 queue: 1 len: 2
17:51:23:735 APS-DATA.confirm id: 215, status: 0x00 SUCCESS
17:51:23:735 APS-DATA.confirm request id: 215 -> confirmed, timeout 59920
17:51:23:766 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x0031, lqi: 0, rssi: 0
17:51:23:799 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x8031, lqi: 0, rssi: 0
17:51:23:799 APS-DATA.indication request id: 215 -> finished
17:51:23:799 APS-DATA.request id: 215 erase from queue
17:51:28:957 0x00178801027A3DD1 force poll (2)
17:51:28:957 APS-DATA.confirm id: 183, status: 0x00 SUCCESS
17:51:28:957 APS-DATA.confirm request id: 183 -> erase from queue

[Kane610]

Unfortunately I didn't check the firmware before creating the otau and files. But the Ikea light has got the latest fw when I checked.

[Kane610]

More weird stuff

23:03:42:500 APS-DATA.confirm id: 155, status: 0x00 SUCCESS
23:03:42:500 APS-DATA.confirm request id: 155 -> erase from queue
23:03:42:525 aps request id: 155 finished, erase from queue
23:03:43:611 APS-DATA.request id: 163, addrmode: 0x03, addr: 0x7cb03eaa000026a9, profile: 0x0104, cluster: 0x0006, ep: 0x03 queue: 0 len: 3
23:03:45:501 Poll APS request to 0x7CB03EAA000026A9 cluster: 0x0006 dropped, values are fresh enough
23:03:47:386 0x7CB03EAA000026A9 error APSDE-DATA.confirm: 0xA7 on task
23:03:47:386 APS-DATA.confirm id: 163, status: 0xA7 NO_ACK
23:03:47:880 APS-DATA.request id: 182, addrmode: 0x03, addr: 0x001788011054e8dd, profile: 0x0104, cluster: 0x0006, ep: 0x0B queue: 0 len: 3
23:03:48:737 delay sending request 187 dt 1 ms to 0x001788011054E8DD, cluster 0x0006
23:03:48:825 delay sending request 187 dt 1 ms to 0x001788011054E8DD, cluster 0x0006
23:03:48:925 delay sending request 187 dt 1 ms to 0x001788011054E8DD, cluster 0x0006
23:03:49:025 delay sending request 187 dt 1 ms to 0x001788011054E8DD, cluster 0x0006
23:03:49:125 delay sending request 187 dt 1 ms to 0x001788011054E8DD, cluster 0x0006
23:03:49:225 delay sending request 187 dt 1 ms to 0x001788011054E8DD, cluster 0x0006
23:03:49:325 delay sending request 187 dt 1 ms to 0x001788011054E8DD, cluster 0x0006
23:03:49:425 delay sending request 187 dt 1 ms to 0x001788011054E8DD, cluster 0x0006
23:03:49:525 delay sending request 187 dt 2 ms to 0x001788011054E8DD, cluster 0x0006
23:03:49:625 delay sending request 187 dt 2 ms to 0x001788011054E8DD, cluster 0x0006
23:03:49:725 delay sending request 187 dt 2 ms to 0x001788011054E8DD, cluster 0x0006
23:03:49:825 delay sending request 187 dt 2 ms to 0x001788011054E8DD, cluster 0x0006
23:03:49:926 delay sending request 187 dt 2 ms to 0x001788011054E8DD, cluster 0x0006
23:03:50:025 delay sending request 187 dt 2 ms to 0x001788011054E8DD, cluster 0x0006
23:03:50:126 delay sending request 187 dt 2 ms to 0x001788011054E8DD, cluster 0x0006
23:03:50:225 delay sending request 187 dt 2 ms to 0x001788011054E8DD, cluster 0x0006
23:03:50:326 delay sending request 187 dt 2 ms to 0x001788011054E8DD, cluster 0x0006
23:03:50:426 delay sending request 187 dt 2 ms to 0x001788011054E8DD, cluster 0x0006
23:03:50:525 delay sending request 187 dt 3 ms to 0x001788011054E8DD, cluster 0x0006
23:03:50:625 delay sending request 187 dt 3 ms to 0x001788011054E8DD, cluster 0x0006
23:03:50:726 delay sending request 187 dt 3 ms to 0x001788011054E8DD, cluster 0x0006
23:03:50:825 delay sending request 187 dt 3 ms to 0x001788011054E8DD, cluster 0x0006
23:03:50:926 delay sending request 187 dt 3 ms to 0x001788011054E8DD, cluster 0x0006
23:03:51:025 delay sending request 187 dt 3 ms to 0x001788011054E8DD, cluster 0x0006
23:03:51:125 delay sending request 187 dt 3 ms to 0x001788011054E8DD, cluster 0x0006
23:03:51:225 delay sending request 187 dt 3 ms to 0x001788011054E8DD, cluster 0x0006
23:03:51:325 delay sending request 187 dt 3 ms to 0x001788011054E8DD, cluster 0x0006
23:03:51:425 delay sending request 187 dt 3 ms to 0x001788011054E8DD, cluster 0x0006
23:03:51:526 delay sending request 187 dt 4 ms to 0x001788011054E8DD, cluster 0x0006
23:03:51:625 delay sending request 187 dt 4 ms to 0x001788011054E8DD, cluster 0x0006
23:03:51:726 delay sending request 187 dt 4 ms to 0x001788011054E8DD, cluster 0x0006
23:03:51:826 delay sending request 187 dt 4 ms to 0x001788011054E8DD, cluster 0x0006
23:03:51:925 delay sending request 187 dt 4 ms to 0x001788011054E8DD, cluster 0x0006
23:03:52:025 delay sending request 187 dt 4 ms to 0x001788011054E8DD, cluster 0x0006
23:03:52:125 delay sending request 187 dt 4 ms to 0x001788011054E8DD, cluster 0x0006
23:03:52:225 delay sending request 187 dt 4 ms to 0x001788011054E8DD, cluster 0x0006
23:03:52:326 delay sending request 187 dt 4 ms to 0x001788011054E8DD, cluster 0x0006
23:03:52:425 delay sending request 187 dt 4 ms to 0x001788011054E8DD, cluster 0x0006
23:03:52:525 APS-DATA.request id: 187, addrmode: 0x03, addr: 0x001788011054e8dd, profile: 0x0104, cluster: 0x0006, ep: 0x0B queue: 1 len: 3
23:03:52:526 APS-DATA.request id: 204, addrmode: 0x02, addr: 0x0000, profile: 0x0000, cluster: 0x0031, ep: 0x00 queue: 2 len: 2
23:03:52:592 APS-DATA.confirm id: 204, status: 0x00 SUCCESS
23:03:52:592 APS-DATA.confirm request id: 204 -> confirmed, timeout 59920
23:03:52:625 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x0031, lqi: 0, rssi: 0
23:03:52:657 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x8031, lqi: 0, rssi: 0
23:03:52:657 APS-DATA.indication request id: 204 -> finished
23:03:52:657 APS-DATA.request id: 204 erase from queue
23:03:53:474 0x001788011054E8DD error APSDE-DATA.confirm: 0xA7 on task
23:03:53:474 APS-DATA.confirm id: 182, status: 0xA7 NO_ACK
23:03:57:805 APS-DATA.request id: 232, addrmode: 0x02, addr: 0x0000, profile: 0x0000, cluster: 0x0031, ep: 0x00 queue: 1 len: 2
23:03:57:847 APS-DATA.confirm id: 232, status: 0x00 SUCCESS
23:03:57:847 APS-DATA.confirm request id: 232 -> confirmed, timeout 59920
23:03:57:879 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x0031, lqi: 0, rssi: 0
23:03:57:911 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x8031, lqi: 0, rssi: 0
23:03:57:911 APS-DATA.indication request id: 232 -> finished
23:03:57:911 APS-DATA.request id: 232 erase from queue
23:04:03:086 APS-DATA.request id: 5, addrmode: 0x02, addr: 0x0000, profile: 0x0000, cluster: 0x0031, ep: 0x00 queue: 1 len: 2
23:04:03:118 APS-DATA.confirm id: 5, status: 0x00 SUCCESS
23:04:03:118 APS-DATA.confirm request id: 5 -> confirmed, timeout 59920
23:04:03:150 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x0031, lqi: 238, rssi: 0
23:04:03:182 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x8031, lqi: 238, rssi: 0
23:04:03:182 APS-DATA.indication request id: 5 -> finished
23:04:03:182 APS-DATA.request id: 5 erase from queue
23:04:07:651 0x001788011054E8DD error APSDE-DATA.confirm: 0xA7 on task
23:04:07:651 APS-DATA.confirm id: 187, status: 0xA7 NO_ACK
23:04:08:366 APS-DATA.request id: 33, addrmode: 0x02, addr: 0x0000, profile: 0x0000, cluster: 0x0031, ep: 0x00 queue: 0 len: 2
23:04:08:404 APS-DATA.confirm id: 33, status: 0x00 SUCCESS
23:04:08:404 APS-DATA.confirm request id: 33 -> confirmed, timeout 59920
23:04:08:436 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x0031, lqi: 0, rssi: 0
23:04:08:468 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x8031, lqi: 0, rssi: 0
23:04:08:468 APS-DATA.indication request id: 33 -> finished
23:04:08:468 APS-DATA.request id: 33 erase from queue
23:04:08:625 APS-DATA.request id: 37, addrmode: 0x03, addr: 0x000b57fffee89915, profile: 0x0104, cluster: 0x0006, ep: 0x01 queue: 0 len: 5
23:04:12:057 Current channel 15
23:04:12:073 CTRL got nwk update id 4
23:04:12:730 0x000B57FFFEE89915 error APSDE-DATA.confirm: 0xA7 on task
23:04:12:730 APS-DATA.confirm id: 37, status: 0xA7 NO_ACK
23:04:12:730 max transmit errors for node 0x000B57FFFEE89915, last seen by neighbors 14 s
23:04:12:826 APS-DATA.request id: 59, addrmode: 0x03, addr: 0x000b57fffee89915, profile: 0x0104, cluster: 0x0006, ep: 0x01 queue: 0 len: 5
23:04:13:646 APS-DATA.request id: 65, addrmode: 0x02, addr: 0x0000, profile: 0x0000, cluster: 0x0031, ep: 0x00 queue: 1 len: 2
23:04:13:691 APS-DATA.confirm id: 65, status: 0x00 SUCCESS
23:04:13:691 APS-DATA.confirm request id: 65 -> confirmed, timeout 59920
23:04:13:723 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x0031, lqi: 0, rssi: 0
23:04:13:755 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x8031, lqi: 0, rssi: 0
23:04:13:755 APS-DATA.indication request id: 65 -> finished
23:04:13:755 APS-DATA.request id: 65 erase from queue
23:04:16:703 0x000B57FFFEE89915 error APSDE-DATA.confirm: 0xA7 on task
23:04:16:703 APS-DATA.confirm id: 59, status: 0xA7 NO_ACK
23:04:16:703 max transmit errors for node 0x000B57FFFEE89915, last seen by neighbors 18 s
23:04:17:030 GW firmware version: 0x261e0500
23:04:17:030 GW firmware version is up to date: 0x261e0500
23:04:17:124 Poll APS request to 0x7CB03EAA000026A9 cluster: 0x0006 dropped, values are fresh enough
23:04:17:625 APS-DATA.request id: 91, addrmode: 0x03, addr: 0x001788011054d0e1, profile: 0x0104, cluster: 0x0006, ep: 0x0B queue: 0 len: 5
23:04:17:824 0x001788011054D0E1 error APSDE-DATA.confirm: 0xE1 on task
23:04:17:824 APS-DATA.confirm id: 91, status: 0xE1
23:04:17:824 unhandled APS-DATA.confirm id: 91 status 0xE1
23:04:18:325 APS-DATA.request id: 94, addrmode: 0x03, addr: 0x0017880102484071, profile: 0x0104, cluster: 0x0006, ep: 0x0B queue: 0 len: 5
23:04:18:481 0x0017880102484071 error APSDE-DATA.confirm: 0xE1 on task
23:04:18:481 APS-DATA.confirm id: 94, status: 0xE1
23:04:18:481 unhandled APS-DATA.confirm id: 94 status 0xE1
23:04:18:825 APS-DATA.request id: 99, addrmode: 0x03, addr: 0x0017880110409954, profile: 0x0104, cluster: 0x0006, ep: 0x0B queue: 0 len: 5
23:04:19:891 0x0017880110409954 error APSDE-DATA.confirm: 0xE1 on task
23:04:19:891 APS-DATA.confirm id: 99, status: 0xE1
23:04:19:891 unhandled APS-DATA.confirm id: 99 status 0xE1
23:04:20:225 APS-DATA.request id: 106, addrmode: 0x03, addr: 0x001788011054e8dd, profile: 0x0104, cluster: 0x0006, ep: 0x0B queue: 0 len: 5
23:04:24:344 0x001788011054E8DD error APSDE-DATA.confirm: 0xA7 on task
23:04:24:344 APS-DATA.confirm id: 106, status: 0xA7 NO_ACK
23:04:24:826 APS-DATA.request id: 131, addrmode: 0x03, addr: 0x00178801104c2e44, profile: 0x0104, cluster: 0x0006, ep: 0x0B queue: 0 len: 5
23:04:24:985 0x00178801104C2E44 error APSDE-DATA.confirm: 0xE1 on task
23:04:24:985 APS-DATA.confirm id: 131, status: 0xE1
23:04:24:985 unhandled APS-DATA.confirm id: 131 status 0xE1
23:04:25:818 APS-DATA.indication srcAddr: 0x7cb03eaa000026a9, dstAddrMode: 2, profile: 0x0104, cluster: 0x0006, lqi: 183, rssi: 0
23:04:25:818 ZCL attribute report 0x7CB03EAA000026A9 for cluster 0x0006, ep 0x03
23:04:25:818 0x7CB03EAA000026A9 onOff 0 --> 1
23:04:30:800 APS-DATA.indication srcAddr: 0x7cb03eaa000026a9, dstAddrMode: 2, profile: 0x0104, cluster: 0x0008, lqi: 183, rssi: 0
23:04:30:801 ZCL attribute report 0x7CB03EAA000026A9 for cluster 0x0008, ep 0x03
23:04:38:605 APS-DATA.request id: 201, addrmode: 0x02, addr: 0xfffd, profile: 0x0000, cluster: 0x0000, ep: 0x00 queue: 0 len: 11
23:04:38:859 APS-DATA.confirm id: 201, status: 0xE1
23:04:40:526 binding for cluster 0x0006 of 0x7CB03EAA000026A9 exists (verified by reporting)
23:04:40:526 skip configure report for cluster: 0x0006 attr: 0x0000 of node 0x7CB03EAA000026A9 (seems to be active)
23:04:40:526 binding for cluster 0x0008 of 0x7CB03EAA000026A9 exists (verified by reporting)
23:04:40:526 skip configure report for cluster: 0x0008 attr: 0x0000 of node 0x7CB03EAA000026A9 (seems to be active)
23:04:40:526 binding for cluster 0x0300 of 0x7CB03EAA000026A9 exists (verified by reporting)
23:04:40:526 skip configure report for cluster: 0x0300 attr: 0x0007 of node 0x7CB03EAA000026A9 (seems to be active)
23:04:40:526 skip configure report for cluster: 0x0300 attr: 0x0003 of node 0x7CB03EAA000026A9 (seems to be active)
23:04:40:526 skip configure report for cluster: 0x0300 attr: 0x0004 of node 0x7CB03EAA000026A9 (seems to be active)
23:04:40:526 skip configure report for cluster: 0x0300 attr: 0x0008 of node 0x7CB03EAA000026A9 (seems to be active)
23:04:40:526 skip binding for attribute reporting of cluster 0xFC00 (end-device might sleep)

[Kane610]

Some data when using the Philips hue remote, that 0x0000000000 doesn't look good

23:07:48:094 APS-DATA.request id: 208, addrmode: 0x01, addr: 0x0007, profile: 0x0104, cluster: 0x0008, ep: 0xFF queue: 4 len: 6
23:07:48:232 APS-DATA.indication srcAddr: 0x00178801020e32a3, dstAddrMode: 1, profile: 0x0104, cluster: 0x0008, lqi: 231, rssi: 0
23:07:48:264 APS-DATA.indication srcAddr: 0x00178801020e32a3, dstAddrMode: 2, profile: 0x0104, cluster: 0xFC00, lqi: 191, rssi: 0
23:07:48:264 button 3000 initial press
23:07:48:264 APS-DATA.request id: 193 shorten timeout to 449780
23:07:48:264 APS-DATA.request id: 194 shorten timeout to 449780
23:07:48:266 discard sensor state push for state/lastupdated (already pushed)
23:07:48:344 0x0000000000000000 error APSDE-DATA.confirm: 0xE1 on task
23:07:48:344 APS-DATA.confirm id: 208, status: 0xE1
23:07:48:376 APS-DATA.indication srcAddr: 0x00178801020e32a3, dstAddrMode: 2, profile: 0x0104, cluster: 0xFC00, lqi: 191, rssi: 0
23:07:48:376 button 3002 short release
23:07:48:376 APS-DATA.request id: 193 shorten timeout to 224810
23:07:48:376 APS-DATA.request id: 194 shorten timeout to 224810
23:07:48:378 discard sensor state push for state/lastupdated (already pushed)
23:07:48:381 APS-DATA.request id: 218, addrmode: 0x01, addr: 0x0007, profile: 0x0104, cluster: 0x0008, ep: 0xFF queue: 4 len: 6
23:07:48:424 0x00178801027A3DD1 error APSDE-DATA.confirm: 0xA7 on task
23:07:48:424 APS-DATA.confirm id: 150, status: 0xA7 NO_ACK
23:07:48:525 APS-DATA.request id: 220, addrmode: 0x03, addr: 0x00178801027a3dd1, profile: 0x0104, cluster: 0x0008, ep: 0x0B queue: 4 len: 5
23:07:48:616 APS-DATA.confirm id: 166, status: 0xA7 NO_ACK
23:07:48:632 0x0000000000000000 error APSDE-DATA.confirm: 0xE1 on task
23:07:48:632 APS-DATA.confirm id: 218, status: 0xE1
23:07:48:760 APS-DATA.indication srcAddr: 0x00178801020e32a3, dstAddrMode: 2, profile: 0x0104, cluster: 0xFC00, lqi: 127, rssi: 0
23:07:48:760 button 4000 initial press
23:07:48:760 APS-DATA.request id: 193 shorten timeout to 112245
23:07:48:760 APS-DATA.request id: 194 shorten timeout to 112245
23:07:48:763 discard sensor state push for state/lastupdated (already pushed)
23:07:48:792 APS-DATA.indication srcAddr: 0x00178801020e32a3, dstAddrMode: 1, profile: 0x0104, cluster: 0x0006, lqi: 231, rssi: 0
23:07:48:968 APS-DATA.indication srcAddr: 0x00178801020e32a3, dstAddrMode: 2, profile: 0x0104, cluster: 0xFC00, lqi: 191, rssi: 0
23:07:48:968 button 4002 short release
23:07:48:971 discard sensor state push for state/lastupdated (already pushed)
23:07:48:974 APS-DATA.request id: 229, addrmode: 0x01, addr: 0x0007, profile: 0x0104, cluster: 0x0006, ep: 0xFF queue: 3 len: 3
23:07:49:225 0x0000000000000000 error APSDE-DATA.confirm: 0xE1 on task
23:07:49:225 APS-DATA.confirm id: 229, status: 0xE1
23:07:50:346 APS-DATA.indication srcAddr: 0x00178801020e32a3, dstAddrMode: 2, profile: 0x0104, cluster: 0xFC00, lqi: 183, rssi: 0
23:07:50

[Kane610]

I removed the battery from the remote from last night when I created this issue until earlier tonight, the lights seemed a bit more responsive while it was missing from the mesh

[Kane610]

And now half of the lights became unavailable... time to sleep

[Kane610]

Are there more things I should look for in the logs to share? Or something I should try?

[manup]

The above logs are already helpful, I'm going to check what happens later today especially with the 0xE1 status.
If can provide a more verbose log it might be helpful too: warning this gets verbose :)

$ deCONZ --http-port=80 --dbg-info=2 --dbg-aps=2 --dbg-zdp=1

[Kane610]

@manup that sounds good. Will add the extra logging tonight. Are there more stuff I can enable so we don't need to iterate on the logs you need?

[manup]

Currently not, for debugging the ZigBee issues this is pretty much the most verbose logging possible.

[Kane610]

Great! Then I will have more data tonight then.

[Kane610]

Request to turn off an Ikea gu10 tunable white

17:28:13:597 aps request id: 83 prf: 0x0000 cl: 0x0000 timeout (confirmed: 1) to 0x0017880110409954 (0xFFFD)
17:28:13:677 aps request id: 83 finished, erase from queue
17:28:14:077 Node 0x00178801104C2E44 is known by 2 neighbors, last seen 5 s
17:28:14:557 Node 0x001788010116E301 is known by 1 neighbors, last seen 0 s
17:28:15:027 add task 996 type 14 to 0x000B57FFFEE89915 cluster 0x0006 req.id 170
17:28:15:027 ~ResourceItem() attr/name -- str 0x13ab580
17:28:15:027 ~ResourceItem() attr/name -- str 0x1778670
17:28:15:027 ~ResourceItem() state/all_on -- str (nil)
17:28:15:027 ~ResourceItem() attr/name -- str 0x160b390
17:28:15:027 ~ResourceItem() state/all_on -- str (nil)
17:28:15:027 ~ResourceItem() state/any_on -- str (nil)
17:28:15:027 ~ResourceItem() attr/type -- str 0x160b390
17:28:15:027 ~ResourceItem() attr/name -- str 0x15c0880
17:28:15:027 ~ResourceItem() state/all_on -- str (nil)
17:28:15:027 ~ResourceItem() state/any_on -- str (nil)
17:28:15:027 ~ResourceItem() attr/type -- str 0x178c330
17:28:15:027 ~ResourceItem() attr/class -- str 0x160b390
17:28:15:027 ~ResourceItem() attr/name -- str 0x1726d00
17:28:15:027 ~ResourceItem() state/all_on -- str (nil)
17:28:15:027 ~ResourceItem() state/any_on -- str (nil)
17:28:15:027 ~ResourceItem() attr/type -- str 0x1583ef0
17:28:15:027 ~ResourceItem() attr/class -- str 0x1719a40
17:28:15:027 APS-DATA.request id: 170, addrmode: 0x03, addr: 0x000b57fffee89915, profile: 0x0104, cluster: 0x0006, ep: 0x01 queue: 0 len: 3
17:28:15:038 Node 0x000B57FFFE92CCED is known by 1 neighbors, last seen 158 s
17:28:15:518 ZDP skip fetch, node 0xB57FFFEE89915 has unconfirmed requests [1]
17:28:15:518 Node 0x0017880110409954 is known by 1 neighbors, last seen 8 s
17:28:15:997 Node 0x7CB03EAA000026A9 is known by 1 neighbors, last seen 15 s
17:28:16:477 Node 0x000B57FFFEE89915 is known by 2 neighbors, last seen 24 s
17:28:16:957 Node 0x001788011054E8DD is known by 1 neighbors, last seen 7 s
17:28:17:038 ZDP skip fetch, node 0xB57FFFEE89915 has unconfirmed requests [1]
17:28:17:437 Node 0x00178801027A3DD1 is known by 1 neighbors, last seen 0 s
17:28:17:677 MGTM_Lqi_req zdpSeq: 5 to 0x00212EFFFF011015 start index 0
17:28:17:677 APS-DATA.request id: 184, addrmode: 0x02, addr: 0x0000, profile: 0x0000, cluster: 0x0031, ep: 0x00 queue: 1 len: 2
17:28:17:719 APS-DATA.confirm id: 184, status: 0x00 SUCCESS
17:28:17:719 APS-DATA.confirm request id: 184 -> confirmed, timeout 59920
17:28:17:751 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x0031, lqi: 0, rssi: 0
17:28:17:751 asdu: 0500
17:28:17:751 ZDP status = 0x00 -> SUCCESS
17:28:17:783 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x8031, lqi: 0, rssi: 0
17:28:17:783 asdu: 0500040001151001ffff2e2100a9260000aa3eb07c5df4350100df
17:28:17:783 APS-DATA.indication request id: 184 -> finished
17:28:17:783 APS-DATA.request id: 184 erase from queue
17:28:17:783 ZDP status = 0x00 -> SUCCESS
17:28:17:783 ZDP Mgmt_Lqi_rsp zdpSeq: 5 from 0x00212EFFFF011015 total: 4, startIndex: 0, listCount: 1
17:28:17:783 * neighbor: 0x7CB03EAA000026A9 (0xF45D), LQI: 223, relation: 0x01 rxOnWHenIdle: 1
17:28:17:917 Node 0x00178801104C2E44 is known by 2 neighbors, last seen 9 s
17:28:18:397 Node 0x001788010116E301 is known by 1 neighbors, last seen 0 s
17:28:18:477 ZDP skip fetch, node 0xB57FFFEE89915 has unconfirmed requests [1]
17:28:18:878 Node 0x000B57FFFE92CCED is known by 1 neighbors, last seen 162 s
17:28:18:889 0x000B57FFFEE89915 error APSDE-DATA.confirm: 0xA7 on task
17:28:18:889 Erase task req-id: 170, type: 14 zcl seqno: 78 send time 3, profileId: 0x0104, clusterId: 0x0006
17:28:18:889 APS-DATA.confirm id: 170, status: 0xA7 NO_ACK
17:28:19:357 Node 0x0017880110409954 is known by 1 neighbors, last seen 12 s
17:28:19:837 Node 0x7CB03EAA000026A9 is known by 1 neighbors, last seen 18 s
17:28:20:317 Node 0x000B57FFFEE89915 is known by 2 neighbors, last seen 28 s
17:28:20:797 Node 0x001788011054E8DD is known by 1 neighbors, last seen 11 s
17:28:21:278 Node 0x00178801027A3DD1 is known by 1 neighbors, last seen 0 s
17:28:21:758 Node 0x00178801104C2E44 is known by 2 neighbors, last seen 13 s
17:28:22:237 Node 0x001788010116E301 is known by 1 neighbors, last seen 0 s
17:28:22:717 Node 0x000B57FFFE92CCED is known by 1 neighbors, last seen 166 s
17:28:22:957 MGTM_Lqi_req zdpSeq: 17 to 0x00212EFFFF011015 start index 1
17:28:22:957 APS-DATA.request id: 219, addrmode: 0x02, addr: 0x0000, profile: 0x0000, cluster: 0x0031, ep: 0x00 queue: 0 len: 2
17:28:23:006 APS-DATA.confirm id: 219, status: 0x00 SUCCESS
17:28:23:006 APS-DATA.confirm request id: 219 -> confirmed, timeout 59920
17:28:23:038 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x0031, lqi: 0, rssi: 0
17:28:23:038 asdu: 1101
17:28:23:038 ZDP status = 0x00 -> SUCCESS
17:28:23:070 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x8031, lqi: 0, rssi: 0
17:28:23:070 asdu: 1100040101151001ffff2e21001599e8feff570b0095d2350100fc
17:28:23:070 APS-DATA.indication request id: 219 -> finished
17:28:23:070 APS-DATA.request id: 219 erase from queue
17:28:23:070 ZDP status = 0x00 -> SUCCESS
17:28:23:070 ZDP Mgmt_Lqi_rsp zdpSeq: 17 from 0x00212EFFFF011015 total: 4, startIndex: 1, listCount: 1
17:28:23:070 * neighbor: 0x000B57FFFEE89915 (0xD295), LQI: 252, relation: 0x01 rxOnWHenIdle: 1
17:28:23:198 Node 0x0017880110409954 is known by 1 neighbors, last seen 16 s
17:28:23:678 Node 0x7CB03EAA000026A9 is known by 1 neighbors, last seen 22 s
17:28:24:157 Node 0x000B57FFFEE89915 is known by 2 neighbors, last seen 32 s
17:28:24:637 Node 0x001788011054E8DD is known by 1 neighbors, last seen 15 s
17:28:25:117 Node 0x00178801027A3DD1 is known by 1 neighbors, last seen 0 s
17:28:25:598 Node 0x00178801104C2E44 is known by 2 neighbors, last seen 17 s
17:28:26:026 int zmMaster::readParameter(ZM_DataId_t) 0x0A
17:28:26:026 int zmMaster::readParameter(ZM_DataId_t) 0x1C
17:28:26:026 int zmMaster::readParameter(ZM_DataId_t) 0x24
17:28:26:066 Current channel 15
17:28:26:077 Node 0x001788010116E301 is known by 1 neighbors, last seen 0 s
17:28:26:082 CTRL got nwk update id 4
17:28:26:557 Node 0x000B57FFFE92CCED is known by 1 neighbors, last seen 170 s
17:28:27:038 Node 0x0017880110409954 is known by 1 neighbors, last seen 19 s
17:28:27:518 Node 0x7CB03EAA000026A9 is known by 1 neighbors, last seen 26 s
17:28:27:997 Node 0x000B57FFFEE89915 is known by 2 neighbors, last seen 36 s
17:28:28:237 MGTM_Lqi_req zdpSeq: 29 to 0x00212EFFFF011015 start index 2
17:28:28:237 APS-DATA.request id: 254, addrmode: 0x02, addr: 0x0000, profile: 0x0000, cluster: 0x0031, ep: 0x00 queue: 0 len: 2
17:28:28:276 APS-DATA.confirm id: 254, status: 0x00 SUCCESS
17:28:28:276 APS-DATA.confirm request id: 254 -> confirmed, timeout 59920
17:28:28:308 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x0031, lqi: 0, rssi: 0
17:28:28:308 asdu: 1d02
17:28:28:308 ZDP status = 0x00 -> SUCCESS
17:28:28:340 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x8031, lqi: 0, rssi: 0
17:28:28:340 asdu: 1d00040201151001ffff2e2100dde85410018817002625350100ac
17:28:28:340 APS-DATA.indication request id: 254 -> finished
17:28:28:340 APS-DATA.request id: 254 erase from queue
17:28:28:340 ZDP status = 0x00 -> SUCCESS
17:28:28:340 ZDP Mgmt_Lqi_rsp zdpSeq: 29 from 0x00212EFFFF011015 total: 4, startIndex: 2, listCount: 1
17:28:28:340 * neighbor: 0x001788011054E8DD (0x2526), LQI: 172, relation: 0x01 rxOnWHenIdle: 1
17:28:28:477 Node 0x001788011054E8DD is known by 1 neighbors, last seen 19 s
17:28:28:957 Node 0x00178801027A3DD1 is known by 1 neighbors, last seen 0 s
17:28:29:437 Node 0x00178801104C2E44 is known by 2 neighbors, last seen 21 s
17:28:29:917 Node 0x001788010116E301 is known by 1 neighbors, last seen 0 s
17:28:30:397 Node 0x000B57FFFE92CCED is known by 1 neighbors, last seen 174 s
17:28:30:877 Node 0x0017880110409954 is known by 1 neighbors, last seen 23 s
17:28:31:029 COM: /dev/ttyS0 :
17:28:31:029 COM: /dev/ttyUSB0 : FT230X Basic UART
17:28:31:029 GW firmware update select USB device
17:28:31:029 GW firmware version: 0x261e0500
17:28:31:029 GW firmware version is up to date: 0x261e0500
17:28:31:357 Node 0x7CB03EAA000026A9 is known by 1 neighbors, last seen 30 s
17:28:31:837 Node 0x000B57FFFEE89915 is known by 2 neighbors, last seen 40 s
17:28:32:318 Node 0x001788011054E8DD is known by 1 neighbors, last seen 23 s
17:28:32:797 Node 0x00178801027A3DD1 is known by 1 neighbors, last seen 0 s
17:28:33:278 Node 0x00178801104C2E44 is known by 2 neighbors, last seen 24 s
17:28:33:518 MGTM_Lqi_req zdpSeq: 41 to 0x00212EFFFF011015 start index 3
17:28:33:518 APS-DATA.request id: 33, addrmode: 0x02, addr: 0x0000, profile: 0x0000, cluster: 0x0031, ep: 0x00 queue: 0 len: 2
17:28:33:563 APS-DATA.confirm id: 33, status: 0x00 SUCCESS
17:28:33:563 APS-DATA.confirm request id: 33 -> confirmed, timeout 59920
17:28:33:595 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x0031, lqi: 238, rssi: 0
17:28:33:595 asdu: 2903
17:28:33:595 ZDP status = 0x00 -> SUCCESS
17:28:33:627 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x8031, lqi: 238, rssi: 0
17:28:33:627 asdu: 2900040301151001ffff2e2100442e4c100188170074af350100b1
17:28:33:627 APS-DATA.indication request id: 33 -> finished
17:28:33:627 APS-DATA.request id: 33 erase from queue
17:28:33:627 ZDP status = 0x00 -> SUCCESS
17:28:33:627 void deCONZ::zmNode::setFetched(deCONZ::RequestId, bool) fetched item: 8, node: 0x0000
17:28:33:627 ZDP Mgmt_Lqi_rsp zdpSeq: 41 from 0x00212EFFFF011015 total: 4, startIndex: 3, listCount: 1
17:28:33:627 * neighbor: 0x00178801104C2E44 (0xAF74), LQI: 177, relation: 0x01 rxOnWHenIdle: 1
17:28:33:757 Node 0x001788010116E301 is known by 1 neighbors, last seen 0 s
17:28:34:237 Node 0x000B57FFFE92CCED is known by 1 neighbors, last seen 178 s
17:28:34:718 Node 0x0017880110409954 is known by 1 neighbors, last seen 27 s
17:28:35:197 Node 0x7CB03EAA000026A9 is known by 1 neighbors, last seen 34 s
17:28:35:677 Node 0x000B57FFFEE89915 is known by 2 neighbors, last seen 43 s
17:28:36:025 Idle timer triggered
17:28:36:025 create binding for attribute reporting of cluster 0x0006
17:28:36:025 queue binding task for 0x7CB03EAA000026A9, cluster 0x0006
17:28:36:025 create binding for attribute reporting of cluster 0x0008
17:28:36:025 queue binding task for 0x7CB03EAA000026A9, cluster 0x0008
17:28:36:025 binding for cluster 0x0300 of 0x7CB03EAA000026A9 exists (verified by reporting)
17:28:36:025 skip configure report for cluster: 0x0300 attr: 0x0007 of node 0x7CB03EAA000026A9 (seems to be active)
17:28:36:025 skip configure report for cluster: 0x0300 attr: 0x0003 of node 0x7CB03EAA000026A9 (seems to be active)
17:28:36:025 skip configure report for cluster: 0x0300 attr: 0x0004 of node 0x7CB03EAA000026A9 (seems to be active)
17:28:36:025 skip configure report for cluster: 0x0300 attr: 0x0008 of node 0x7CB03EAA000026A9 (seems to be active)
17:28:36:025 Force binding of attribute reporting for node Flex RGBW
17:28:36:027 read attributes of 0x7CB03EAA000026A9 cluster: 0x0006: [ 17:28:36:027 0x0000 17:28:36:027 ]
17:28:36:027 add task 1081 type 19 to 0x7CB03EAA000026A9 cluster 0x0006 req.id 50
17:28:36:027 Poll APS request 50 to 0x7CB03EAA000026A9 cluster: 0x0006
17:28:36:125 APS-DATA.request id: 50, addrmode: 0x03, addr: 0x7cb03eaa000026a9, profile: 0x0104, cluster: 0x0006, ep: 0x03 queue: 0 len: 5
17:28:36:157 Node 0x001788011054E8DD is known by 1 neighbors, last seen 27 s
17:28:36:350 Poll APS confirm 50 status: 0xE1

[Kane610]

Request to group with all lights in that actually passed

17:31:18:398 Node 0x00178801104C2E44 is known by 2 neighbors, last seen 97 s
17:31:18:637 ZDP skip fetch, node 0x1788010116E301 has unconfirmed requests [1]
17:31:18:877 Node 0x001788010116E301 is known by 1 neighbors, last seen 121 s
17:31:19:358 Node 0x000B57FFFE92CCED is known by 1 neighbors, last seen 343 s
17:31:19:755 Poll APS confirm 63 status: 0xA7
17:31:19:755 0x001788010116E301 error APSDE-DATA.confirm: 0xA7 on task
17:31:19:755 Erase task req-id: 63, type: 19 zcl seqno: 152 send time 5, profileId: 0x0104, clusterId: 0x0006
17:31:19:755 APS-DATA.confirm id: 63, status: 0xA7 NO_ACK
17:31:19:837 Node 0x0017880110409954 is known by 1 neighbors, last seen 94 s
17:31:19:948 read attributes of 0x001788010116E301 cluster: 0x0300: [ 17:31:19:948 0x0008 17:31:19:948 0x4001 17:31:19:948 0x400A 17:31:19:948 0x400B 17:31:19:948 0x400C 17:31:19:948 ]
17:31:19:948 add task 1831 type 19 to 0x001788010116E301 cluster 0x0300 req.id 98
17:31:19:948 Poll APS request 98 to 0x001788010116E301 cluster: 0x0300
17:31:20:025 APS-DATA.request id: 98, addrmode: 0x03, addr: 0x001788010116e301, profile: 0x0104, cluster: 0x0300, ep: 0x0B queue: 0 len: 13
17:31:20:317 Node 0x7CB03EAA000026A9 is known by 2 neighbors, last seen 51 s
17:31:20:397 ZDP skip fetch, node 0x1788010116E301 has unconfirmed requests [1]
17:31:20:797 Node 0x000B57FFFEE89915 is known by 3 neighbors, last seen 87 s
17:31:21:162 add task 1838 type 14 to group 0x0007 cluster 0x0006 req.id 106
17:31:21:162 APS-DATA.request id: 106, addrmode: 0x01, addr: 0x0007, profile: 0x0104, cluster: 0x0006, ep: 0xFF queue: 1 len: 3
17:31:21:278 Node 0x001788011054E8DD is known by 1 neighbors, last seen 163 s
17:31:21:405 0x001788011054E8DD force poll
17:31:21:406 0x00178801027A3DD1 force poll
17:31:21:406 0x00178801104C2E44 force poll
17:31:21:406 0x001788010116E301 force poll
17:31:21:406 0x0017880110409954 force poll
17:31:21:406 Erase task req-id: 106, type: 14 zcl seqno: 154 send time 0, profileId: 0x0104, clusterId: 0x0006
17:31:21:406 APS-DATA.confirm id: 106, status: 0x00 SUCCESS
17:31:21:406 APS-DATA.confirm request id: 106 -> erase from queue
17:31:21:437 aps request id: 106 finished, erase from queue
17:31:21:437 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 1, profile: 0x0104, cluster: 0x0006, lqi: 238, rssi: 0
17:31:21:437 asdu: 119a00
17:31:21:518 APS-DATA.indication srcAddr: 0x7cb03eaa000026a9, dstAddrMode: 2, profile: 0x0104, cluster: 0x0008, lqi: 122, rssi: 0
17:31:21:518 asdu: 18fd0a000020b2
17:31:21:518 ZCL attribute report 0x7CB03EAA000026A9 for cluster 0x0008, ep 0x03
17:31:21:518 payload: 000020b2
17:31:21:518 Node data 0x7cb03eaa000026a9 profileId: 0x0104, clusterId: 0x0008
17:31:21:518 update ZCL value 0x0008/0x0000 for 0x7CB03EAA000026A9 after 120 s
17:31:21:757 Node 0x00178801027A3DD1 is known by 1 neighbors, last seen 25 s
17:31:21:774 APS-DATA.indication srcAddr: 0x000b57fffee89915, dstAddrMode: 2, profile: 0x0104, cluster: 0x0006, lqi: 255, rssi: 0
17:31:21:774 asdu: 08260a00001000
17:31:21:774 ZCL attribute report 0x000B57FFFEE89915 for cluster 0x0006, ep 0x01
17:31:21:774 payload: 00001000
17:31:21:774 APS-DATA.request id: 116, addrmode: 0x03, addr: 0x000b57fffee89915, profile: 0x0104, cluster: 0x0006, ep: 0x01 queue: 1 len: 5
17:31:21:774 Node data 0x000b57fffee89915 profileId: 0x0104, clusterId: 0x0006
17:31:21:774 update ZCL value 0x0006/0x0000 for 0x000B57FFFEE89915 after 209 s
17:31:22:158 ZDP skip fetch, node 0x1788010116E301 has unconfirmed requests [1]
17:31:22:238 Node 0x00178801104C2E44 is known by 2 neighbors, last seen 101 s
17:31:22:717 Node 0x001788010116E301 is known by 1 neighbors, last seen 124 s
17:31:23:118 ZDP skip fetch, node 0xB57FFFEE89915 has unconfirmed requests [1]
17:31:23:197 Node 0x000B57FFFE92CCED is known by 1 neighbors, last seen 347 s
17:31:23:677 ZDP skip fetch, node 0x1788010116E301 has unconfirmed requests [1]
17:31:23:677 Node 0x0017880110409954 is known by 1 neighbors, last seen 98 s
17:31:24:157 Node 0x7CB03EAA000026A9 is known by 2 neighbors, last seen 2 s
17:31:24:637 ZDP skip fetch, node 0xB57FFFEE89915 has unconfirmed requests [1]
17:31:24:638 Node 0x000B57FFFEE89915 is known by 3 neighbors, last seen 2 s
17:31:25:117 Node 0x001788011054E8DD is known by 1 neighbors, last seen 167 s
17:31:25:197 ZDP skip fetch, node 0x1788010116E301 has unconfirmed requests [1]
17:31:25:597 Node 0x00178801027A3DD1 is known by 1 neighbors, last seen 28 s
17:31:25:939 APS-DATA.confirm id: 116, status: 0xA7 NO_ACK
17:31:25:955 Poll APS confirm 98 status: 0xA7
17:31:25:955 0x001788010116E301 error APSDE-DATA.confirm: 0xA7 on task
17:31:25:955 Erase task req-id: 98, type: 19 zcl seqno: 153 send time 5, profileId: 0x0104, clusterId: 0x0300
17:31:25:955 APS-DATA.confirm id: 98, status: 0xA7 NO_ACK
17:31:25:955 max transmit errors for node 0x001788010116E301, last seen by neighbors 420 s
17:31:25:957 read attributes of 0x001788010116E301 cluster: 0x0006: [ 17:31:25:957 0x0000 17:31:25:957 ]
17:31:25:957 add task 1861 type 19 to 0x001788010116E301 cluster 0x0006 req.id 140
17:31:25:957 Poll APS request 140 to 0x001788010116E301 cluster: 0x0006
17:31:25:987 APS-DATA.indication srcAddr: 0x7cb03eaa000026a9, dstAddrMode: 2, profile: 0x0104, cluster: 0x0008, lqi: 183, rssi: 0
17:31:25:987 asdu: 18fe0a000020b2
17:31:25:987 ZCL attribute report 0x7CB03EAA000026A9 for cluster 0x0008, ep 0x03
17:31:25:987 payload: 000020b2
17:31:25:987 Node data 0x7cb03eaa000026a9 profileId: 0x0104, clusterId: 0x0008
17:31:25:987 update ZCL value 0x0008/0x0000 for 0x7CB03EAA000026A9 after 4 s
17:31:26:025 int zmMaster::readParameter(ZM_DataId_t) 0x0A
17:31:26:025 int zmMaster::readParameter(ZM_DataId_t) 0x1C
17:31:26:025 int zmMaster::readParameter(ZM_DataId_t) 0x24
17:31:26:025 APS-DATA.request id: 140, addrmode: 0x03, addr: 0x001788010116e301, profile: 0x0104, cluster: 0x0006, ep: 0x0B queue: 0 len: 5
17:31:26:067 Current channel 15
17:31:26:078 Node 0x00178801104C2E44 is known by 2 neighbors, last seen 104 s
17:31:26:083 CTRL got nwk update id 4
17:31:26:557 Node 0x001788010116E301 is known by 1 neighbors, last seen 128 s
17:31:26:718 ZDP skip fetch, node 0x1788010116E301 has unconfirmed requests [1]
17:31:27:037 Node 0x000B57FFFE92CCED is known by 1 neighbors, last seen 350 s
17:31:27:517 Node 0x0017880110409954 is known by 1 neighbors, last seen 102 s
17:31:27:997 Node 0x7CB03EAA000026A9 is known by 2 neighbors, last seen 2 s
17:31:28:237 ZDP skip fetch, node 0x1788010116E301 has unconfirmed requests [1]
17:31:28:477 Node 0x000B57FFFEE89915 is known by 3 neighbors, last seen 6 s
17:31:28:958 Node 0x001788011054E8DD is known by 1 neighbors, last seen 171 s
17:31:29:437 Node 0x00178801027A3DD1 is known by 1 neighbors, last seen 32 s
17:31:29:677 MGTM_Lqi_req zdpSeq: 71 to 0x7CB03EAA000026A9 start index 6
17:31:29:677 APS-DATA.request id: 164, addrmode: 0x02, addr: 0xf45d, profile: 0x0000, cluster: 0x0031, ep: 0x00 queue: 1 len: 2
17:31:29:757 ZDP skip fetch, node 0x1788010116E301 has unconfirmed requests [1]
17:31:29:832 APS-DATA.confirm id: 164, status: 0xE1
17:31:29:832 unhandled APS-DATA.confirm id: 164 status 0xE1
17:31:29:918 Node 0x00178801104C2E44 is known by 2 neighbors, last seen 108 s
17:31:30:398 Node 0x001788010116E301 is known by 1 neighbors, last seen 132 s
17:31:30:877 Node 0x000B57FFFE92CCED is known by 1 neighbors, last seen 354 s
17:31:31:037 ZDP skip fetch, node 0x1788010116E301 has unconfirmed requests [1]
17:31:31:357 Node 0x0017880110409954 is known by 1 neighbors, last seen 105 s
17:31:31:838 Node 0x7CB03EAA000026A9 is known by 2 neighbors, last seen 5 s

[Kane610]

Also passed

17:35:40:477 Node 0x000B57FFFE92CCED is known by 1 neighbors, last seen 604 s
17:35:40:957 Node 0x0017880110409954 is known by 1 neighbors, last seen 41 s
17:35:41:437 Node 0x7CB03EAA000026A9 is known by 2 neighbors, last seen 16 s
17:35:41:917 Node 0x000B57FFFEE89915 is known by 3 neighbors, last seen 47 s
17:35:42:398 Node 0x001788011054E8DD is known by 1 neighbors, last seen 19 s
17:35:42:877 Node 0x00178801027A3DD1 is known by 1 neighbors, last seen 20 s
17:35:43:069 add task 3110 type 14 to group 0x0007 cluster 0x0006 req.id 45
17:35:43:069 APS-DATA.request id: 45, addrmode: 0x01, addr: 0x0007, profile: 0x0104, cluster: 0x0006, ep: 0xFF queue: 0 len: 3
17:35:43:269 0x001788011054E8DD force poll
17:35:43:269 0x00178801027A3DD1 force poll
17:35:43:269 0x00178801104C2E44 force poll
17:35:43:269 0x001788010116E301 force poll
17:35:43:269 0x0017880110409954 force poll
17:35:43:269 Erase task req-id: 45, type: 14 zcl seqno: 40 send time 0, profileId: 0x0104, clusterId: 0x0006
17:35:43:269 APS-DATA.confirm id: 45, status: 0x00 SUCCESS
17:35:43:269 APS-DATA.confirm request id: 45 -> erase from queue
17:35:43:277 aps request id: 45 finished, erase from queue
17:35:43:302 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 1, profile: 0x0104, cluster: 0x0006, lqi: 0, rssi: 0
17:35:43:302 asdu: 112800
17:35:43:334 APS-DATA.indication srcAddr: 0x7cb03eaa000026a9, dstAddrMode: 2, profile: 0x0104, cluster: 0x0006, lqi: 191, rssi: 0
17:35:43:334 asdu: 180b0a00001000
17:35:43:334 ZCL attribute report 0x7CB03EAA000026A9 for cluster 0x0006, ep 0x03
17:35:43:334 payload: 00001000
17:35:43:334 Node data 0x7cb03eaa000026a9 profileId: 0x0104, clusterId: 0x0006
17:35:43:334 update ZCL value 0x0006/0x0000 for 0x7CB03EAA000026A9 after 141 s
17:35:43:357 Node 0x00178801104C2E44 is known by 2 neighbors, last seen 71 s
17:35:43:366 APS-DATA.indication srcAddr: 0x7cb03eaa000026a9, dstAddrMode: 2, profile: 0x0104, cluster: 0x0008, lqi: 199, rssi: 0
17:35:43:366 asdu: 180c0a000020da
17:35:43:366 ZCL attribute report 0x7CB03EAA000026A9 for cluster 0x0008, ep 0x03
17:35:43:366 payload: 000020da
17:35:43:366 Node data 0x7cb03eaa000026a9 profileId: 0x0104, clusterId: 0x0008
17:35:43:366 update ZCL value 0x0008/0x0000 for 0x7CB03EAA000026A9 after 71 s
17:35:43:574 APS-DATA.indication srcAddr: 0x000b57fffee89915, dstAddrMode: 2, profile: 0x0104, cluster: 0x0006, lqi: 255, rssi: 0
17:35:43:574 asdu: 082f0a00001000
17:35:43:574 ZCL attribute report 0x000B57FFFEE89915 for cluster 0x0006, ep 0x01
17:35:43:574 payload: 00001000
17:35:43:574 APS-DATA.request id: 56, addrmode: 0x03, addr: 0x000b57fffee89915, profile: 0x0104, cluster: 0x0006, ep: 0x01 queue: 0 len: 5
17:35:43:574 Node data 0x000b57fffee89915 profileId: 0x0104, clusterId: 0x0006
17:35:43:574 update ZCL value 0x0006/0x0000 for 0x000B57FFFEE89915 after 141 s
17:35:43:622 APS-DATA.confirm id: 56, status: 0x00 SUCCESS
17:35:43:622 APS-DATA.confirm request id: 56 -> erase from queue
17:35:43:677 aps request id: 56 finished, erase from queue
17:35:43:837 Node 0x001788010116E301 is known by 0 neighbors, last seen 43 s
17:35:44:077 MGTM_Lqi_req zdpSeq: 159 to 0x00212EFFFF011015 start index 2
17:35:44:077 APS-DATA.request id: 62, addrmode: 0x02, addr: 0x0000, profile: 0x0000, cluster: 0x0031, ep: 0x00 queue: 0 len: 2
17:35:44:119 APS-DATA.confirm id: 62, status: 0x00 SUCCESS
17:35:44:119 APS-DATA.confirm request id: 62 -> confirmed, timeout 59920
17:35:44:151 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x0031, lqi: 0, rssi: 0
17:35:44:151 asdu: 9f02
17:35:44:151 ZDP status = 0x00 -> SUCCESS
17:35:44:183 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x8031, lqi: 0, rssi: 0
17:35:44:183 asdu: 9f00040201151001ffff2e2100dde85410018817002625350100ac
17:35:44:183 APS-DATA.indication request id: 62 -> finished
17:35:44:183 APS-DATA.request id: 62 erase from queue
17:35:44:183 ZDP status = 0x00 -> SUCCESS
17:35:44:183 ZDP Mgmt_Lqi_rsp zdpSeq: 159 from 0x00212EFFFF011015 total: 4, startIndex: 2, listCount: 1
17:35:44:183 * neighbor: 0x001788011054E8DD (0x2526), LQI: 172, relation: 0x01 rxOnWHenIdle: 1
17:35:44:317 Node 0x000B57FFFE92CCED is known by 1 neighbors, last seen 608 s
17:35:44:797 Node 0x0017880110409954 is known by 1 neighbors, last seen 45 s
17:35:45:278 Node 0x7CB03EAA000026A9 is known by 2 neighbors, last seen 1 s
17:35:45:757 Node 0x000B57FFFEE89915 is known by 3 neighbors, last seen 2 s
17:35:46:238 Node 0x001788011054E8DD is known by 1 neighbors, last seen 23 s
17:35:46:270 read attributes of 0x001788011054E8DD cluster: 0x0006: [ 17:35:46:270 0x0000 17:35:46:270 ]
17:35:46:270 add task 3127 type 19 to 0x001788011054E8DD cluster 0x0006 req.id 78
17:35:46:270 Poll APS request 78 to 0x001788011054E8DD cluster: 0x0006
17:35:46:325 APS-DATA.request id: 78, addrmode: 0x03, addr: 0x001788011054e8dd, profile: 0x0104, cluster: 0x0006, ep: 0x0B queue: 0 len: 5
17:35:46:425 Poll APS confirm 78 status: 0x00
17:35:46:425 Erase task req-id: 78, type: 19 zcl seqno: 41 send time 0, profileId: 0x0104, clusterId: 0x0006
17:35:46:425 APS-DATA.confirm id: 78, status: 0x00 SUCCESS
17:35:46:425 APS-DATA.confirm request id: 78 -> erase from queue
17:35:46:457 APS-DATA.indication srcAddr: 0x001788011054e8dd, dstAddrMode: 2, profile: 0x0104, cluster: 0x0006, lqi: 191, rssi: 0
17:35:46:457 asdu: 1829010000001000
17:35:46:457 APS-DATA.request id: 78 erase from queue
17:35:46:457 Node data 0x001788011054e8dd profileId: 0x0104, clusterId: 0x0006
17:35:46:458 update ZCL value 0x0006/0x0000 for 0x001788011054E8DD after 23 s
17:35:46:717 Node 0x00178801027A3DD1 is known by 1 neighbors, last seen 24 s
17:35:46:825 read attributes of 0x0017880110409954 cluster: 0x0006: [ 17:35:46:825 0x0000 17:35:46:825 ]
17:35:46:825 add task 3132 type 19 to 0x0017880110409954 cluster 0x0006 req.id 85
17:35:46:825 Poll APS request 85 to 0x0017880110409954 cluster: 0x0006
17:35:46:925 APS-DATA.request id: 85, addrmode: 0x03, addr: 0x0017880110409954, profile: 0x0104, cluster: 0x0006, ep: 0x0B queue: 0 len: 5

[Kane610]

A couple of the lights go between available and unavailable now as well

[Kane610]

Command that didn't pass

17:37:46:026 Idle timer triggered
17:37:46:026 binding for cluster 0x0006 of 0x000B57FFFEE89915 exists (verified by reporting)
17:37:46:026 skip configure report for cluster: 0x0006 attr: 0x0000 of node 0x000B57FFFEE89915 (seems to be active)
17:37:46:026 binding for cluster 0x0008 of 0x000B57FFFEE89915 exists (verified by reporting)
17:37:46:026 skip configure report for cluster: 0x0008 attr: 0x0000 of node 0x000B57FFFEE89915 (seems to be active)
17:37:46:026 binding for cluster 0x0300 of 0x000B57FFFEE89915 exists (verified by reporting)
17:37:46:026 skip configure report for cluster: 0x0300 attr: 0x0007 of node 0x000B57FFFEE89915 (seems to be active)
17:37:46:026 skip configure report for cluster: 0x0300 attr: 0x0003 of node 0x000B57FFFEE89915 (wait reading or unsupported)
17:37:46:026 skip configure report for cluster: 0x0300 attr: 0x0004 of node 0x000B57FFFEE89915 (wait reading or unsupported)
17:37:46:026 skip configure report for cluster: 0x0300 attr: 0x0008 of node 0x000B57FFFEE89915 (seems to be active)
17:37:46:026 Force binding of attribute reporting for node Trådfri GU10 WS
17:37:46:027 Poll APS request to 0x7CB03EAA000026A9 cluster: 0x0006 dropped, values are fresh enough
17:37:46:238 Node 0x00178801104C2E44 is known by 2 neighbors, last seen 30 s
17:37:46:525 Poll APS request to 0x000B57FFFEE89915 cluster: 0x0006 dropped, values are fresh enough
17:37:46:699 add task 3645 type 14 to group 0x0007 cluster 0x0006 req.id 43
17:37:46:699 APS-DATA.request id: 43, addrmode: 0x01, addr: 0x0007, profile: 0x0104, cluster: 0x0006, ep: 0xFF queue: 0 len: 3
17:37:46:717 Node 0x001788010116E301 is known by 0 neighbors, last seen 166 s
17:37:46:725 Poll APS request to 0x000B57FFFEE89915 cluster: 0x0008 dropped, values are fresh enough
17:37:46:825 Poll APS request to 0x000B57FFFEE89915 cluster: 0x0300 dropped, values are fresh enough
17:37:46:912 0x0000000000000000 error APSDE-DATA.confirm: 0xE1 on task
17:37:46:913 Erase task req-id: 43, type: 14 zcl seqno: 66 send time 0, profileId: 0x0104, clusterId: 0x0006
17:37:46:913 APS-DATA.confirm id: 43, status: 0xE1
17:37:47:197 Node 0x000B57FFFE92CCED is known by 1 neighbors, last seen 731 s
17:37:47:677 Node 0x0017880110409954 is known by 1 neighbors, last seen 30 s
17:37:48:158 Node 0x7CB03EAA000026A9 is known by 2 neighbors, last seen 120 s
17:37:48:637 Node 0x000B57FFFEE89915 is known by 3 neighbors, last seen 40 s
17:37:49:117 Node 0x001788011054E8DD is known by 1 neighbors, last seen 103 s
17:37:49:597 Node 0x00178801027A3DD1 is known by 1 neighbors, last seen 70 s
17:37:50:077 Node 0x00178801104C2E44 is known by 2 neighbors, last seen 33 s
17:37:50:558 Node 0x001788010116E301 is known by 0 neighbors, last seen 170 s
17:37:51:037 Node 0x000B57FFFE92CCED is known by 1 neighbors, last seen 734 s
17:37:51:518 Node 0x0017880110409954 is known by 1 neighbors, last seen 34 s
17:37:51:997 Node 0x7CB03EAA000026A9 is known by 2 neighbors, last seen 123 s
17:37:52:478 Node 0x000B57FFFEE89915 is known by 3 neighbors, last seen 44 s
17:37:52:957 Node 0x001788011054E8DD is known by 1 neighbors, last seen 107 s
17:37:53:064 APS-DATA.indication srcAddr: 0x7cb03eaa000026a9, dstAddrMode: 2, profile: 0x0104, cluster: 0x0300, lqi: 231, rssi: 0
17:37:53:064 asdu: 180e0a0700216e01
17:37:53:064 ZCL attribute report 0x7CB03EAA000026A9 for cluster 0x0300, ep 0x03
17:37:53:064 payload: 0700216e01
17:37:53:064 Node data 0x7cb03eaa000026a9 profileId: 0x0104, clusterId: 0x0300
17:37:53:064 update ZCL value 0x0300/0x0007 for 0x7CB03EAA000026A9 after 173 s

[Kane610]

Spamming the on button went through after a while

17:38:35:945 add task 3851 type 14 to group 0x0007 cluster 0x0006 req.id 125
17:38:35:945 APS-DATA.request id: 125, addrmode: 0x01, addr: 0x0007, profile: 0x0104, cluster: 0x0006, ep: 0xFF queue: 0 len: 3
17:38:36:157 Node 0x00178801104C2E44 is known by 2 neighbors, last seen 79 s
17:38:36:158 APS-DATA.indication srcAddr: 0x7cb03eaa000026a9, dstAddrMode: 2, profile: 0x0104, cluster: 0x0008, lqi: 231, rssi: 0
17:38:36:158 asdu: 180f0a000020da
17:38:36:158 ZCL attribute report 0x7CB03EAA000026A9 for cluster 0x0008, ep 0x03
17:38:36:158 payload: 000020da
17:38:36:158 Node data 0x7cb03eaa000026a9 profileId: 0x0104, clusterId: 0x0008
17:38:36:158 update ZCL value 0x0008/0x0000 for 0x7CB03EAA000026A9 after 168 s
17:38:36:190 APS-DATA.indication srcAddr: 0x7cb03eaa000026a9, dstAddrMode: 2, profile: 0x0104, cluster: 0x0006, lqi: 231, rssi: 0
17:38:36:190 asdu: 18100a00001001
17:38:36:190 ZCL attribute report 0x7CB03EAA000026A9 for cluster 0x0006, ep 0x03
17:38:36:190 payload: 00001001
17:38:36:190 Node data 0x7cb03eaa000026a9 profileId: 0x0104, clusterId: 0x0006
17:38:36:190 update ZCL value 0x0006/0x0000 for 0x7CB03EAA000026A9 after 172 s
17:38:36:254 APS-DATA.indication srcAddr: 0x000b57fffee89915, dstAddrMode: 2, profile: 0x0104, cluster: 0x0006, lqi: 255, rssi: 0
17:38:36:254 asdu: 08310a00001001
17:38:36:254 ZCL attribute report 0x000B57FFFEE89915 for cluster 0x0006, ep 0x01
17:38:36:254 payload: 00001001
17:38:36:254 APS-DATA.request id: 133, addrmode: 0x03, addr: 0x000b57fffee89915, profile: 0x0104, cluster: 0x0006, ep: 0x01 queue: 1 len: 5
17:38:36:254 Node data 0x000b57fffee89915 profileId: 0x0104, clusterId: 0x0006
17:38:36:254 update ZCL value 0x0006/0x0000 for 0x000B57FFFEE89915 after 172 s
17:38:36:446 APS-DATA.confirm id: 133, status: 0xE1
17:38:36:446 unhandled APS-DATA.confirm id: 133 status 0xE1
17:38:36:637 Node 0x001788010116E301 is known by 0 neighbors, last seen 29 s
17:38:36:799 0x001788011054E8DD force poll
17:38:36:799 0x00178801027A3DD1 force poll
17:38:36:799 0x00178801104C2E44 force poll
17:38:36:799 0x001788010116E301 force poll
17:38:36:799 0x0017880110409954 force poll
17:38:36:799 Erase task req-id: 125, type: 14 zcl seqno: 71 send time 1, profileId: 0x0104, clusterId: 0x0006
17:38:36:799 APS-DATA.confirm id: 125, status: 0x00 SUCCESS
17:38:36:799 APS-DATA.confirm request id: 125 -> erase from queue
17:38:36:831 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 1, profile: 0x0104, cluster: 0x0006, lqi: 255, rssi: 0
17:38:36:831 asdu: 114701
17:38:36:831 APS-DATA.request id: 125 erase from queue
17:38:37:118 Node 0x000B57FFFE92CCED is known by 1 neighbors, last seen 781 s
17:38:37:598 Node 0x0017880110409954 is known by 1 neighbors, last seen 80 s
17:38:38:077 Node 0x7CB03EAA000026A9 is known by 2 neighbors, last seen 1 s
17:38:38:557 Node 0x000B57FFFEE89915 is known by 3 neighbors, last seen 2 s
17:38:39:038 Node 0x001788011054E8DD is known by 1 neighbors, last seen 153 s
17:38:39:517 Node 0x00178801027A3DD1 is known by 1 neighbors, last seen 33 s
17:38:39:757 MGTM_Lqi_req zdpSeq: 241 to 0x7CB03EAA000026A9 start index 6
17:38:39:757 APS-DATA.request id: 160, addrmode: 0x02, addr: 0xf45d, profile: 0x0000, cluster: 0x0031, ep: 0x00 queue: 0 len: 2
17:38:39:798 read attributes of 0x0017880110409954 cluster: 0x0006: [ 17:38:39:798 0x0000 17:38:39:798 ]
17:38:39:798 add task 3872 type 19 to 0x0017880110409954 cluster 0x0006 req.id 162
17:38:39:798 Poll APS request 162 to 0x0017880110409954 cluster: 0x0006
17:38:39:825 APS-DATA.request id: 162, addrmode: 0x03, addr: 0x0017880110409954, profile: 0x0104, cluster: 0x0006, ep: 0x0B queue: 1 len: 5
17:38:39:939 APS-DATA.confirm id: 160, status: 0x00 SUCCESS
17:38:39:939 APS-DATA.confirm request id: 160 -> confirmed, timeout 59760
17:38:39:997 Node 0x00178801104C2E44 is known by 2 neighbors, last seen 83 s
17:38:39:002 APS-DATA.indication srcAddr: 0x7cb03eaa000026a9, dstAddrMode: 2, profile: 0x0000, cluster: 0x8031, lqi: 231, rssi: 0
17:38:39:002 asdu: f1000a0603151001ffff2e2100d13d7a020188170091b025010124151001ffff2e2100dde854100188170026252501011a151001ffff2e2100e1d0541001881700345c2501013c
17:38:39:002 APS-DATA.indication request id: 160 -> finished
17:38:39:002 APS-DATA.request id: 160 erase from queue
17:38:39:002 ZDP status = 0x00 -> SUCCESS
17:38:39:002 ZDP Mgmt_Lqi_rsp zdpSeq: 241 from 0x7CB03EAA000026A9 total: 10, startIndex: 6, listCount: 3
17:38:39:002 * neighbor: 0x00178801027A3DD1 (0xB091), LQI: 36, relation: 0x02 rxOnWHenIdle: 1
17:38:39:002 * neighbor: 0x001788011054E8DD (0x2526), LQI: 26, relation: 0x02 rxOnWHenIdle: 1
17:38:39:002 * neighbor: 0x001788011054D0E1 (0x5C34), LQI: 60, relation: 0x02 rxOnWHenIdle: 1
17:38:40:237 CTRL restore cached node 0x001788011054d0e1
17:38:40:238 void deCONZ::zmNode::setFetched(deCONZ::RequestId, bool) fetched item: 2, node: 0x5C34
17:38:40:238 void deCONZ::zmNode::setFetched(deCONZ::RequestId, bool) fetched item: 1, node: 0x5C34
17:38:40:238 new node - ext: 0x001788011054d0e1, nwk: 0x5C34
17:38:40:238 ~ResourceItem() state/on -- str (nil)
17:38:40:238 ~ResourceItem() state/on -- str (nil)
17:38:40:238 ~ResourceItem() state/alert -- str 0x1725d50
17:38:40:238 ~ResourceItem() state/on -- str (nil)
17:38:40:238 ~ResourceItem() state/alert -- str 0x147e990
17:38:40:238 ~ResourceItem() state/reachable -- str (nil)
17:38:40:238 ~ResourceItem() attr/name -- str 0x147e990
17:38:40:238 ~ResourceItem() state/on -- str (nil)
17:38:40:238 ~ResourceItem() state/alert -- str 0x15c54b0
17:38:40:238 ~ResourceItem() state/reachable -- str (nil)
17:38:40:238 ~ResourceItem() attr/name -- str 0x14155c0
17:38:40:238 ~ResourceItem() attr/modelid -- str 0x147e990
17:38:40:238 ~ResourceItem() attr/type -- str 0x147e990
17:38:40:238 ~ResourceItem() state/bri -- str (nil)
17:38:40:238 ~ResourceItem() state/colormode -- str 0x147e990
17:38:40:238 ~ResourceItem() state/on -- str (nil)
17:38:40:238 ~ResourceItem() state/alert -- str 0x1555d30
17:38:40:238 ~ResourceItem() state/reachable -- str (nil)
17:38:40:238 ~ResourceItem() attr/name -- str 0x1576a30
17:38:40:238 ~ResourceItem() attr/modelid -- str 0x1574cd0
17:38:40:238 ~ResourceItem() attr/type -- str 0x15c54b0
17:38:40:238 ~ResourceItem() state/bri -- str (nil)
17:38:40:238 ~ResourceItem() state/colormode -- str 0x1360190
17:38:40:238 ~ResourceItem() state/ct -- str (nil)
17:38:40:238 ~ResourceItem() state/x -- str (nil)
17:38:40:238 ~ResourceItem() state/y -- str (nil)
17:38:40:238 ~ResourceItem() state/hue -- str (nil)
17:38:40:238 ~ResourceItem() state/sat -- str (nil)
17:38:40:238 sql exec SELECT * FROM nodes WHERE mac='00:17:88:01:10:54:d0:e1-0b' COLLATE NOCASE
17:38:40:238 don't close database yet, keep open for 900 seconds
17:38:40:238 LightNode 10: RGB Lamp 3 added
17:38:40:238 ~ResourceItem() state/on -- str (nil)
17:38:40:238 ~ResourceItem() state/alert -- str 0x17b3ae0
17:38:40:238 ~ResourceItem() state/reachable -- str (nil)
17:38:40:238 ~ResourceItem() attr/name -- str 0x17b44c0
17:38:40:238 ~ResourceItem() attr/modelid -- str 0x13601b0
17:38:40:238 ~ResourceItem() attr/type -- str 0x157b6c0
17:38:40:238 ~ResourceItem() state/bri -- str (nil)
17:38:40:238 ~ResourceItem() state/colormode -- str 0x17b1040
17:38:40:238 ~ResourceItem() state/ct -- str (nil)
17:38:40:238 ~ResourceItem() state/x -- str (nil)
17:38:40:238 ~ResourceItem() state/y -- str (nil)
17:38:40:238 ~ResourceItem() state/hue -- str (nil)
17:38:40:238 ~ResourceItem() state/sat -- str (nil)
17:38:40:238 ~ResourceItem() state/on -- str (nil)
17:38:40:238 ~ResourceItem() state/on -- str (nil)
17:38:40:238 ~ResourceItem() state/alert -- str 0x17b3ae0
17:38:40:238 ~ResourceItem() state/on -- str (nil)
17:38:40:238 ~ResourceItem() state/alert -- str 0x155be20
17:38:40:238 ~ResourceItem() state/reachable -- str (nil)
17:38:40:238 ~ResourceItem() attr/name -- str 0x155be20
17:38:40:238 ~ResourceItem() state/on -- str (nil)
17:38:40:238 ~ResourceItem() state/alert -- str 0x16222b0
17:38:40:238 ~ResourceItem() state/reachable -- str (nil)
17:38:40:238 ~ResourceItem() attr/name -- str 0x16237d0
17:38:40:238 ~ResourceItem() attr/modelid -- str 0x155be20
17:38:40:238 ~ResourceItem() attr/type -- str 0x155be20
17:38:40:238 ~ResourceItem() state/on -- str (nil)
17:38:40:238 ~ResourceItem() state/alert -- str 0x16255d0
17:38:40:238 ~ResourceItem() state/reachable -- str (nil)
17:38:40:238 ~ResourceItem() attr/name -- str 0x1624040
17:38:40:238 ~ResourceItem() attr/modelid -- str 0x1623610
17:38:40:238 ~ResourceItem() attr/type -- str 0x16222b0
17:38:40:238 ~ResourceItem() state/on -- str (nil)
17:38:40:238 ~ResourceItem() state/on -- str (nil)
17:38:40:238 ~ResourceItem() state/alert -- str 0x1624040
17:38:40:238 ~ResourceItem() state/on -- str (nil)
17:38:40:238 ~ResourceItem() state/alert -- str 0x13601b0
17:38:40:238 ~ResourceItem() state/reachable -- str (nil)
17:38:40:238 ~ResourceItem() attr/name -- str 0x13601b0
17:38:40:238 ~ResourceItem() state/on -- str (nil)
17:38:40:238 ~ResourceItem() state/alert -- str 0x1568960
17:38:40:238 ~ResourceItem() state/reachable -- str (nil)
17:38:40:238 ~ResourceItem() attr/name -- str 0x1615a40
17:38:40:238 ~ResourceItem() attr/modelid -- str 0x13601b0
17:38:40:238 ~ResourceItem() attr/type -- str 0x13601b0
17:38:40:238 ~ResourceItem() state/on -- str (nil)
17:38:40:238 ~ResourceItem() state/alert -- str 0x16266f0
17:38:40:238 ~ResourceItem() state/reachable -- str (nil)
17:38:40:238 ~ResourceItem() attr/name -- str 0x1700690
17:38:40:238 ~ResourceItem() attr/modelid -- str 0x16270a0
17:38:40:238 ~ResourceItem() attr/type -- str 0x1568960
17:38:40:238 ~ResourceItem() state/on -- str (nil)
17:38:40:238 ~ResourceItem() state/on -- str (nil)
17:38:40:238 ~ResourceItem() state/alert -- str 0x1700690
17:38:40:238 ~ResourceItem() state/on -- str (nil)
17:38:40:238 ~ResourceItem() state/alert -- str 0x16222b0
17:38:40:238 ~ResourceItem() state/reachable -- str (nil)
17:38:40:238 ~ResourceItem() attr/name -- str 0x16222b0
17:38:40:238 ~ResourceItem() state/on -- str (nil)
17:38:40:238 ~ResourceItem() state/alert -- str 0x16255d0
17:38:40:238 ~ResourceItem() state/reachable -- str (nil)
17:38:40:238 ~ResourceItem() attr/name -- str 0x1783fe0
17:38:40:238 ~ResourceItem() attr/modelid -- str 0x16222b0
17:38:40:238 ~ResourceItem() attr/type -- str 0x16222b0
17:38:40:238 ~ResourceItem() state/on -- str (nil)
17:38:40:238 ~ResourceItem() state/alert -- str 0x1790e40
17:38:40:238 ~ResourceItem() state/reachable -- str (nil)
17:38:40:238 ~ResourceItem() attr/name -- str 0x1583fd0
17:38:40:238 ~ResourceItem() attr/modelid -- str 0x1784000
17:38:40:238 ~ResourceItem() attr/type -- str 0x16255d0
17:38:40:238 ~ResourceItem() state/on -- str (nil)
17:38:40:238 ~ResourceItem() state/on -- str (nil)
17:38:40:238 ~ResourceItem() state/alert -- str 0x1583fd0
17:38:40:238 ~ResourceItem() state/on -- str (nil)
17:38:40:238 ~ResourceItem() state/alert -- str 0x16266f0
17:38:40:238 ~ResourceItem() state/reachable -- str (nil)
17:38:40:238 ~ResourceItem() attr/name -- str 0x16266f0
17:38:40:238 ~ResourceItem() state/on -- str (nil)
17:38:40:238 ~ResourceItem() state/alert -- str 0x1568960
17:38:40:238 ~ResourceItem() state/reachable -- str (nil)
17:38:40:238 ~ResourceItem() attr/name -- str 0x1579da0
17:38:40:238 ~ResourceItem() attr/modelid -- str 0x16266f0
17:38:40:238 ~ResourceItem() attr/type -- str 0x16266f0
17:38:40:238 ~ResourceItem() state/on -- str (nil)
17:38:40:238 ~ResourceItem() state/alert -- str 0x15c44b0
17:38:40:238 ~ResourceItem() state/reachable -- str (nil)
17:38:40:238 ~ResourceItem() attr/name -- str 0x1775150
17:38:40:238 ~ResourceItem() attr/modelid -- str 0x161cc60
17:38:40:238 ~ResourceItem() attr/type -- str 0x1568960
17:38:40:238 ~ResourceItem() state/on -- str (nil)
17:38:40:238 ~ResourceItem() state/on -- str (nil)
17:38:40:238 ~ResourceItem() state/alert -- str 0x1775150
17:38:40:238 ~ResourceItem() state/on -- str (nil)
17:38:40:238 ~ResourceItem() state/alert -- str 0x16255d0
17:38:40:238 ~ResourceItem() state/reachable -- str (nil)
17:38:40:238 ~ResourceItem() attr/name -- str 0x16255d0
17:38:40:238 ~ResourceItem() state/on -- str (nil)
17:38:40:238 ~ResourceItem() state/alert -- str 0x1790e40
17:38:40:238 ~ResourceItem() state/reachable -- str (nil)
17:38:40:238 ~ResourceItem() attr/name -- str 0x1723380
17:38:40:238 ~ResourceItem() attr/modelid -- str 0x16255d0
17:38:40:238 ~ResourceItem() attr/type -- str 0x16255d0
17:38:40:238 ~ResourceItem() state/on -- str (nil)
17:38:40:238 ~ResourceItem() state/alert -- str 0x17afba0
17:38:40:238 ~ResourceItem() state/reachable -- str (nil)
17:38:40:238 ~ResourceItem() attr/name -- str 0x17afbe0
17:38:40:238 ~ResourceItem() attr/modelid -- str 0x17233a0
17:38:40:238 ~ResourceItem() attr/type -- str 0x1790e40
17:38:40:238 skip device discover, node 0x001788011054D0E1 wasn't seen by neighbors since 854 s
17:38:40:718 MGTM_Lqi_req zdpSeq: 243 to 0x7CB03EAA000026A9 start index 9
17:38:40:718 APS-DATA.request id: 168, addrmode: 0x02, addr: 0xf45d, profile: 0x0000, cluster: 0x0031, ep: 0x00 queue: 1 len: 2
17:38:40:797 reuse dead link (dead link container size now 0)
QGraphicsScene::addItem: item has already been added to this scene
17:38:40:819 APS-DATA.confirm id: 168, status: 0xE1
17:38:40:819 unhandled APS-DATA.confirm id: 168 status 0xE1
17:38:40:851 Poll APS confirm 162 status: 0xE1
17:38:40:851 0x0017880110409954 error APSDE-DATA.confirm: 0xE1 on task
17:38:40:851 Erase task req-id: 162, type: 19 zcl seqno: 72 send time 1, profileId: 0x0104, clusterId: 0x0006
17:38:40:851 APS-DATA.confirm id: 162, status: 0xE1
17:38:40:851 unhandled APS-DATA.confirm id: 162 status 0xE1
17:38:40:947 read attributes of 0x0017880110409954 cluster: 0x0008: [ 17:38:40:947 0x0000 17:38:40:947 ]
17:38:40:947 add task 3877 type 19 to 0x0017880110409954 cluster 0x0008 req.id 171
17:38:40:947 Poll APS request 171 to 0x0017880110409954 cluster: 0x0008
17:38:41:025 APS-DATA.request id: 171, addrmode: 0x03, addr: 0x0017880110409954, profile: 0x0104, cluster: 0x0008, ep: 0x0B queue: 0 len: 5
17:38:41:075 APS-DATA.indication srcAddr: 0x7cb03eaa000026a9, dstAddrMode: 2, profile: 0x0104, cluster: 0x0008, lqi: 231, rssi: 0
17:38:41:075 asdu: 18110a000020da
17:38:41:075 ZCL attribute report 0x7CB03EAA000026A9 for cluster 0x0008, ep 0x03
17:38:41:075 payload: 000020da
17:38:41:075 Node data 0x7cb03eaa000026a9 profileId: 0x0104, clusterId: 0x0008
17:38:41:075 update ZCL value 0x0008/0x0000 for 0x7CB03EAA000026A9 after 4 s
17:38:41:917 ZDP skip fetch, node 0x17880110409954 has unconfirmed requests [1]
17:38:42:068 Poll APS confirm 171 status: 0xE1
17:38:42:068 0x0017880110409954 error APSDE-DATA.confirm: 0xE1 on task
17:38:42:068 Erase task req-id: 171, type: 19 zcl seqno: 73 send time 1, profileId: 0x0104, clusterId: 0x0008
17:38:42:068 APS-DATA.confirm id: 171, status: 0xE1
17:38:42:068 unhandled APS-DATA.confirm id: 171 status 0xE1
17:38:42:166 read attributes of 0x001788011054D0E1 cluster: 0x0006: [ 17:38:42:166 0x0000 17:38:42:166 ]
17:38:42:166 add task 3884 type 19 to 0x001788011054D0E1 cluster 0x0006 req.id 182
17:38:42:166 Poll APS request 182 to 0x001788011054D0E1 cluster: 0x0006
17:38:42:225 APS-DATA.request id: 182, addrmode: 0x03, addr: 0x001788011054d0e1, profile: 0x0104, cluster: 0x0006, ep: 0x0B queue: 0 len: 5
17:38:43:286 Poll APS confirm 182 status: 0xE1
17:38:43:286 0x001788011054D0E1 error APSDE-DATA.confirm: 0xE1 on task
17:38:43:286 Erase task req-id: 182, type: 19 zcl seqno: 74 send time 1, profileId: 0x0104, clusterId: 0x0006
17:38:43:286 APS-DATA.confirm id: 182, status: 0xE1
17:38:43:286 unhandled APS-DATA.confirm id: 182 status 0xE1
17:38:43:497 read attributes of 0x001788011054D0E1 cluster: 0x0300: [ 17:38:43:497 0x0008 17:38:43:497 0x4001 17:38:43:497 0x400A 17:38:43:497 0x400B 17:38:43:497 0x400C 17:38:43:497 ]
17:38:43:497 add task 3890 type 19 to 0x001788011054D0E1 cluster 0x0300 req.id 191
17:38:43:497 Poll APS request 191 to 0x001788011054D0E1 cluster: 0x0300
17:38:43:526 APS-DATA.request id: 191, addrmode: 0x03, addr: 0x001788011054d0e1, profile: 0x0104, cluster: 0x0300, ep: 0x0B queue: 0 len: 13
17:38:44:317 ZDP skip fetch, node 0x1788011054D0E1 has unconfirmed requests [1]
17:38:46:026 Close socket port: 36800
17:38:46:477 MGTM_Lqi_req zdpSeq: 2 to 0x001788011054E8DD start index 0
17:38:46:477 APS-DATA.request id: 211, addrmode: 0x02, addr: 0x2526, profile: 0x0000, cluster: 0x0031, ep: 0x00 queue: 1 len: 2
17:38:46:638 ZDP skip fetch, node 0x1788011054D0E1 has unconfirmed requests [1]
17:38:46:666 APS-DATA.confirm id: 211, status: 0x00 SUCCESS
17:38:46:666 APS-DATA.confirm request id: 211 -> confirmed, timeout 59760
17:38:46:890 APS-DATA.indication srcAddr: 0x001788011054e8dd, dstAddrMode: 2, profile: 0x0000, cluster: 0x8031, lqi: 191, rssi: 0
17:38:46:890 asdu: 02000a0002151001ffff2e2100a9260000aa3eb07c5df4350001fc151001ffff2e2100d13d7a020188170091b0050102fc
17:38:46:891 APS-DATA.indication request id: 211 -> finished
17:38:46:891 APS-DATA.request id: 211 erase from queue
17:38:46:891 ZDP status = 0x00 -> SUCCESS
17:38:46:891 MGTM_Lqi_req zdpSeq: 3 to 0x001788011054E8DD start index 2
17:38:46:891 APS-DATA.request id: 215, addrmode: 0x02, addr: 0x2526, profile: 0x0000, cluster: 0x0031, ep: 0x00 queue: 1 len: 2
17:38:46:891 ZDP Mgmt_Lqi_rsp zdpSeq: 2 from 0x001788011054E8DD total: 10, startIndex: 0, listCount: 2
17:38:46:891 * neighbor: 0x7CB03EAA000026A9 (0xF45D), LQI: 252, relation: 0x01 rxOnWHenIdle: 1
17:38:46:891 * neighbor: 0x00178801027A3DD1 (0xB091), LQI: 252, relation: 0x00 rxOnWHenIdle: 1
17:38:47:051 APS-DATA.confirm id: 215, status: 0xE1
17:38:47:051 unhandled APS-DATA.confirm id: 215 status 0xE1
17:38:48:717 ZDP skip fetch, node 0x1788011054D0E1 has unconfirmed requests [1]
17:38:50:797 ZDP skip fetch, node 0x1788011054D0E1 has unconfirmed requests [1]
17:38:51:456 APS-DATA.indication srcAddr: 0x001788011054e8dd, dstAddrMode: 2, profile: 0x0000, cluster: 0x8031, lqi: 183, rssi: 0
17:38:51:456 asdu: 02000a0002151001ffff2e2100a9260000aa3eb07c5df4350001fc151001ffff2e2100d13d7a020188170091b0050102fc
17:38:51:456 ZDP status = 0x00 -> SUCCESS
17:38:51:456 void zmController::onApsdeDataIndication(const deCONZ::ApsDataIndication&),3164: assertion 'apsReq.state() == deCONZ::FinishState' failed
17:38:51:456 MGTM_Lqi_req zdpSeq: 12 to 0x001788011054E8DD start index 4
17:38:51:456 APS-DATA.request id: 243, addrmode: 0x02, addr: 0x2526, profile: 0x0000, cluster: 0x0031, ep: 0x00 queue: 1 len: 2
17:38:51:456 ZDP Mgmt_Lqi_rsp zdpSeq: 2 from 0x001788011054E8DD total: 10, startIndex: 0, listCount: 2
17:38:51:456 * neighbor: 0x7CB03EAA000026A9 (0xF45D), LQI: 252, relation: 0x01 rxOnWHenIdle: 1
17:38:51:456 * neighbor: 0x00178801027A3DD1 (0xB091), LQI: 252, relation: 0x00 rxOnWHenIdle: 1
17:38:51:584 APS-DATA.confirm id: 243, status: 0xE1
17:38:51:584 unhandled APS-DATA.confirm id: 243 status 0xE1
17:38:52:877 ZDP skip fetch, node 0x1788011054D0E1 has unconfirmed requests [1]
17:38:53:747 Poll APS confirm 191 status: 0xE1
17:38:53:747 0x001788011054D0E1 error APSDE-DATA.confirm: 0xE1 on task
17:38:53:747 Erase task req-id: 191, type: 19 zcl seqno: 75 send time 10, profileId: 0x0104, clusterId: 0x0300
17:38:53:747 APS-DATA.confirm id: 191, status: 0xE1
17:38:53:747 unhandled APS-DATA.confirm id: 191 status 0xE1
17:38:53:843 read attributes of 0x001788011054E8DD cluster: 0x0006: [ 17:38:53:843 0x0000 17:38:53:843 ]
17:38:53:843 add task 3933 type 19 to 0x001788011054E8DD cluster 0x0006 req.id 3
17:38:53:843 Poll APS request 3 to 0x001788011054E8DD cluster: 0x0006
17:38:53:926 APS-DATA.request id: 3, addrmode: 0x03, addr: 0x001788011054e8dd, profile: 0x0104, cluster: 0x0006, ep: 0x0B queue: 0 len: 5
17:38:54:115 Poll APS confirm 3 status: 0x00
17:38:54:115 Erase task req-id: 3, type: 19 zcl seqno: 76 send time 1, profileId: 0x0104, clusterId: 0x0006
17:38:54:116 APS-DATA.confirm id: 3, status: 0x00 SUCCESS
17:38:54:116 APS-DATA.confirm request id: 3 -> erase from queue
17:38:54:148 APS-DATA.indication srcAddr: 0x001788011054e8dd, dstAddrMode: 2, profile: 0x0104, cluster: 0x0006, lqi: 191, rssi: 0
17:38:54:148 asdu: 184c010000001001
17:38:54:148 APS-DATA.request id: 3 erase from queue
17:38:54:148 Node data 0x001788011054e8dd profileId: 0x0104, clusterId: 0x0006
17:38:54:148 update ZCL value 0x0006/0x0000 for 0x001788011054E8DD after 168 s

[manup]

By looking at the firmware source 0xE1 error stands for mac channel access error. Here are a few things to check:

• Is ConBee located near interfering WiFi, Bluetooth devices?
• WiFi streaming or WiFi on interfering channels
• Also rf doesn't like metal, I don't think this is the cause here

What may help:

• Bring some distance to such devices via USB extension cable
• Change ZigBee channel in Phoscon App (not deCONZ directly)

[Kane610]

My wifi AP is 2m away. Before when running from my Pi it was 30cm away. Right now I'm using channel 15 for zigbee and 11 for 2.4ghz wifi. No Bluetooth.

There are thin and with lots of holes metal shelving in the same room but there are lights above and below so mesh shouldn't be affected right?

I can't use phoscon yet since the other issue with phoscon not finding the deConz instance.

[Kane610]

I double checked and my 2.4ghz is on channel 1, so I moved to channel 25 for deconz using phoscon. I just shut of the ordinary service for port 80 to get this going. And all devices disappeared, but just now during the evening movie they seemed to pop up alive again. What is the difference from doing it in phoscon compared to deconz?

Still seeing the unhandled APS-DATA.confirm id: 46 status 0xE1.

[Kane610]

I also see these 0x0000000000000000 error APSDE-DATA.confirm: 0xE1 on task, the 00000000 address to me sounds like a bigger issue?

[Kane610]

Some data directly on deconz start

22:46:03:030 GW firmware version: 0x261e0500
22:46:03:030 GW firmware version is up to date: 0x261e0500
22:46:03:166 device discover rotate, node 0x00178801027a3dd1 is in wait state
22:46:03:410 Announced to internet
22:46:03:486 ZDP skip fetch, node 0x178801027A3DD1 has unconfirmed requests [1]
22:46:03:646 device discover rotate, node 0x00178801104c2e44 is in wait state
22:46:03:678 Poll APS confirm 37 status: 0xE1
22:46:03:678 0x00178801027A3DD1 error APSDE-DATA.confirm: 0xE1 on task
22:46:03:678 Erase task req-id: 37, type: 19 zcl seqno: 81 send time 1, profileId: 0x0104, clusterId: 0x0300
22:46:03:678 APS-DATA.confirm id: 37, status: 0xE1
22:46:03:678 unhandled APS-DATA.confirm id: 37 status 0xE1
22:46:03:784 read attributes of 0x00178801104C2E44 cluster: 0x0006: [ 22:46:03:784 0x0000 22:46:03:784 ]
22:46:03:784 add task 14 type 19 to 0x00178801104C2E44 cluster 0x0006 req.id 43
22:46:03:784 Poll APS request 43 to 0x00178801104C2E44 cluster: 0x0006
22:46:03:825 APS-DATA.request id: 43, addrmode: 0x03, addr: 0x00178801104c2e44, profile: 0x0104, cluster: 0x0006, ep: 0x0B queue: 0 len: 5
22:46:04:126 ZDP skip fetch, node 0x178801104C2E44 has unconfirmed requests [1]
22:46:04:126 MGTM_Lqi_req zdpSeq: 12 to 0x00212EFFFF011015 start index 0
22:46:04:126 APS-DATA.request id: 45, addrmode: 0x02, addr: 0x0000, profile: 0x0000, cluster: 0x0031, ep: 0x00 queue: 1 len: 2
22:46:04:159 APS-DATA.confirm id: 45, status: 0x00 SUCCESS
22:46:04:159 APS-DATA.confirm request id: 45 -> confirmed, timeout 59920
22:46:04:190 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x0031, lqi: 0, rssi: 0
22:46:04:191 asdu: 0c00
22:46:04:191 ZDP status = 0x00 -> SUCCESS
22:46:04:223 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x8031, lqi: 0, rssi: 0
22:46:04:223 asdu: 0c00020001151001ffff2e2100d13d7a020188170091b035010074
22:46:04:223 APS-DATA.indication request id: 45 -> finished
22:46:04:223 APS-DATA.request id: 45 erase from queue
22:46:04:223 ZDP status = 0x00 -> SUCCESS
22:46:04:223 MGTM_Lqi_req zdpSeq: 13 to 0x00212EFFFF011015 start index 1
22:46:04:223 APS-DATA.request id: 48, addrmode: 0x02, addr: 0x0000, profile: 0x0000, cluster: 0x0031, ep: 0x00 queue: 1 len: 2
22:46:04:223 ZDP Mgmt_Lqi_rsp zdpSeq: 12 from 0x00212EFFFF011015 total: 2, startIndex: 0, listCount: 1
22:46:04:223 * neighbor: 0x00178801027A3DD1 (0xB091), LQI: 116, relation: 0x01 rxOnWHenIdle: 1
22:46:04:271 APS-DATA.confirm id: 48, status: 0x00 SUCCESS
22:46:04:271 APS-DATA.confirm request id: 48 -> confirmed, timeout 60000
22:46:04:303 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x0031, lqi: 0, rssi: 0
22:46:04:303 asdu: 0d01
22:46:04:303 ZDP status = 0x00 -> SUCCESS
22:46:04:335 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x8031, lqi: 0, rssi: 0
22:46:04:335 asdu: 0d00020101151001ffff2e2100442e4c100188170074af35010075
22:46:04:335 APS-DATA.indication request id: 48 -> finished
22:46:04:335 APS-DATA.request id: 48 erase from queue
22:46:04:335 ZDP status = 0x00 -> SUCCESS
22:46:04:335 void deCONZ::zmNode::setFetched(deCONZ::RequestId, bool) fetched item: 8, node: 0x0000
22:46:04:335 ZDP Mgmt_Lqi_rsp zdpSeq: 13 from 0x00212EFFFF011015 total: 2, startIndex: 1, listCount: 1
22:46:04:335 * neighbor: 0x00178801104C2E44 (0xAF74), LQI: 117, relation: 0x01 rxOnWHenIdle: 1
22:46:04:605 device discover rotate, node 0x00178801027a3dd1 is in wait state
22:46:04:686 ZDP skip fetch, node 0x178801104C2E44 has unconfirmed requests [1]
22:46:04:895 Poll APS confirm 43 status: 0xE1
22:46:04:895 0x00178801104C2E44 error APSDE-DATA.confirm: 0xE1 on task
22:46:04:895 Erase task req-id: 43, type: 19 zcl seqno: 82 send time 1, profileId: 0x0104, clusterId: 0x0006
22:46:04:895 APS-DATA.confirm id: 43, status: 0xE1
22:46:04:895 unhandled APS-DATA.confirm id: 43 status 0xE1
22:46:05:086 device discover rotate, node 0x00178801104c2e44 is in wait state
22:46:05:109 read attributes of 0x00178801104C2E44 cluster: 0x0300: [ 22:46:05:109 0x0008 22:46:05:109 0x4001 22:46:05:109 0x400A 22:46:05:109 0x400B 22:46:05:109 0x400C 22:46:05:109 ]
22:46:05:109 add task 20 type 19 to 0x00178801104C2E44 cluster 0x0300 req.id 55
22:46:05:109 Poll APS request 55 to 0x00178801104C2E44 cluster: 0x0300
22:46:05:125 APS-DATA.request id: 55, addrmode: 0x03, addr: 0x00178801104c2e44, profile: 0x0104, cluster: 0x0300, ep: 0x0B queue: 0 len: 13
22:46:05:245 ZDP skip fetch, node 0x178801104C2E44 has unconfirmed requests [1]
22:46:05:565 MGTM_Lqi_req zdpSeq: 14 to 0x00212EFFFF011015 start index 0
22:46:05:565 APS-DATA.request id: 58, addrmode: 0x02, addr: 0x0000, profile: 0x0000, cluster: 0x0031, ep: 0x00 queue: 1 len: 2
22:46:05:600 APS-DATA.confirm id: 58, status: 0x00 SUCCESS
22:46:05:600 APS-DATA.confirm request id: 58 -> confirmed, timeout 59920
22:46:05:632 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x0031, lqi: 0, rssi: 0
22:46:05:632 asdu: 0e00
22:46:05:632 ZDP status = 0x00 -> SUCCESS
22:46:05:664 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x8031, lqi: 0, rssi: 0
22:46:05:664 asdu: 0e00020001151001ffff2e2100d13d7a020188170091b035010074
22:46:05:664 APS-DATA.indication request id: 58 -> finished
22:46:05:664 APS-DATA.request id: 58 erase from queue
22:46:05:664 ZDP status = 0x00 -> SUCCESS
22:46:05:664 MGTM_Lqi_req zdpSeq: 15 to 0x00212EFFFF011015 start index 1
22:46:05:664 APS-DATA.request id: 61, addrmode: 0x02, addr: 0x0000, profile: 0x0000, cluster: 0x0031, ep: 0x00 queue: 1 len: 2
22:46:05:664 ZDP Mgmt_Lqi_rsp zdpSeq: 14 from 0x00212EFFFF011015 total: 2, startIndex: 0, listCount: 1
22:46:05:664 * neighbor: 0x00178801027A3DD1 (0xB091), LQI: 116, relation: 0x01 rxOnWHenIdle: 1
22:46:05:712 APS-DATA.confirm id: 61, status: 0x00 SUCCESS
22:46:05:712 APS-DATA.confirm request id: 61 -> confirmed, timeout 60000
22:46:05:744 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x0031, lqi: 0, rssi: 0
22:46:05:744 asdu: 0f01
22:46:05:744 ZDP status = 0x00 -> SUCCESS
22:46:05:776 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x8031, lqi: 0, rssi: 0
22:46:05:776 asdu: 0f00020101151001ffff2e2100442e4c100188170074af35010075
22:46:05:777 APS-DATA.indication request id: 61 -> finished
22:46:05:777 APS-DATA.request id: 61 erase from queue
22:46:05:777 ZDP status = 0x00 -> SUCCESS
22:46:05:777 void deCONZ::zmNode::setFetched(deCONZ::RequestId, bool) fetched item: 8, node: 0x0000
22:46:05:777 ZDP Mgmt_Lqi_rsp zdpSeq: 15 from 0x00212EFFFF011015 total: 2, startIndex: 1, listCount: 1
22:46:05:777 * neighbor: 0x00178801104C2E44 (0xAF74), LQI: 117, relation: 0x01 rxOnWHenIdle: 1
22:46:05:805 ZDP skip fetch, node 0x178801104C2E44 has unconfirmed requests [1]
22:46:06:046 device discover rotate, node 0x00178801027a3dd1 is in wait state
22:46:06:193 Poll APS confirm 55 status: 0xE1
22:46:06:193 0x00178801104C2E44 error APSDE-DATA.confirm: 0xE1 on task
22:46:06:193 Erase task req-id: 55, type: 19 zcl seqno: 83 send time 1, profileId: 0x0104, clusterId: 0x0300
22:46:06:193 APS-DATA.confirm id: 55, status: 0xE1
22:46:06:193 unhandled APS-DATA.confirm id: 55 status 0xE1
22:46:06:525 device discover rotate, node 0x00178801104c2e44 is in wait state
22:46:07:006 MGTM_Lqi_req zdpSeq: 16 to 0x00212EFFFF011015 start index 0
22:46:07:006 APS-DATA.request id: 69, addrmode: 0x02, addr: 0x0000, profile: 0x0000, cluster: 0x0031, ep: 0x00 queue: 0 len: 2
22:46:07:074 APS-DATA.confirm id: 69, status: 0x00 SUCCESS
22:46:07:074 APS-DATA.confirm request id: 69 -> confirmed, timeout 59920
22:46:07:106 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x0031, lqi: 238, rssi: 0
22:46:07:106 asdu: 1000
22:46:07:106 ZDP status = 0x00 -> SUCCESS
22:46:07:138 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x8031, lqi: 238, rssi: 0
22:46:07:138 asdu: 1000020001151001ffff2e2100d13d7a020188170091b035010074
22:46:07:138 APS-DATA.indication request id: 69 -> finished
22:46:07:138 APS-DATA.request id: 69 erase from queue
22:46:07:138 ZDP status = 0x00 -> SUCCESS
22:46:07:138 MGTM_Lqi_req zdpSeq: 17 to 0x00212EFFFF011015 start index 1
22:46:07:138 APS-DATA.request id: 73, addrmode: 0x02, addr: 0x0000, profile: 0x0000, cluster: 0x0031, ep: 0x00 queue: 0 len: 2
22:46:07:138 ZDP Mgmt_Lqi_rsp zdpSeq: 16 from 0x00212EFFFF011015 total: 2, startIndex: 0, listCount: 1
22:46:07:138 * neighbor: 0x00178801027A3DD1 (0xB091), LQI: 116, relation: 0x01 rxOnWHenIdle: 1
22:46:07:165 ZDP skip fetch, node 0x212EFFFF011015 has unconfirmed requests [1]
22:46:07:186 APS-DATA.confirm id: 73, status: 0x00 SUCCESS
22:46:07:186 APS-DATA.confirm request id: 73 -> confirmed, timeout 59920
22:46:07:218 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x0031, lqi: 238, rssi: 0
22:46:07:218 asdu: 1101
22:46:07:218 ZDP status = 0x00 -> SUCCESS
22:46:07:250 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x8031, lqi: 238, rssi: 0
22:46:07:250 asdu: 1100020101151001ffff2e2100442e4c100188170074af35010075
22:46:07:250 APS-DATA.indication request id: 73 -> finished
22:46:07:250 APS-DATA.request id: 73 erase from queue
22:46:07:250 ZDP status = 0x00 -> SUCCESS
22:46:07:250 void deCONZ::zmNode::setFetched(deCONZ::RequestId, bool) fetched item: 8, node: 0x0000
22:46:07:250 ZDP Mgmt_Lqi_rsp zdpSeq: 17 from 0x00212EFFFF011015 total: 2, startIndex: 1, listCount: 1
22:46:07:250 * neighbor: 0x00178801104C2E44 (0xAF74), LQI: 117, relation: 0x01 rxOnWHenIdle: 1
22:46:07:485 device discover rotate, node 0x00178801027a3dd1 is in wait state
22:46:07:965 device discover rotate, node 0x00178801104c2e44 is in wait state
22:46:08:445 MGTM_Lqi_req zdpSeq: 18 to 0x00212EFFFF011015 start index 0
22:46:08:445 APS-DATA.request id: 81, addrmode: 0x02, addr: 0x0000, profile: 0x0000, cluster: 0x0031, ep: 0x00 queue: 0 len: 2
22:46:08:484 APS-DATA.confirm id: 81, status: 0x00 SUCCESS
22:46:08:484 APS-DATA.confirm request id: 81 -> confirmed, timeout 59920
22:46:08:516 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x0031, lqi: 238, rssi: 0
22:46:08:516 asdu: 1200
22:46:08:516 ZDP status = 0x00 -> SUCCESS
22:46:08:548 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x8031, lqi: 238, rssi: 0
22:46:08:548 asdu: 1200020001151001ffff2e2100d13d7a020188170091b035010074
22:46:08:548 APS-DATA.indication request id: 81 -> finished
22:46:08:548 APS-DATA.request id: 81 erase from queue
22:46:08:548 ZDP status = 0x00 -> SUCCESS
22:46:08:548 MGTM_Lqi_req zdpSeq: 19 to 0x00212EFFFF011015 start index 1
22:46:08:548 APS-DATA.request id: 85, addrmode: 0x02, addr: 0x0000, profile: 0x0000, cluster: 0x0031, ep: 0x00 queue: 0 len: 2
22:46:08:548 ZDP Mgmt_Lqi_rsp zdpSeq: 18 from 0x00212EFFFF011015 total: 2, startIndex: 0, listCount: 1
22:46:08:548 * neighbor: 0x00178801027A3DD1 (0xB091), LQI: 116, relation: 0x01 rxOnWHenIdle: 1
22:46:08:596 APS-DATA.confirm id: 85, status: 0x00 SUCCESS
22:46:08:596 APS-DATA.confirm request id: 85 -> confirmed, timeout 60000
22:46:08:628 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x0031, lqi: 238, rssi: 0
22:46:08:628 asdu: 1301
22:46:08:628 ZDP status = 0x00 -> SUCCESS
22:46:08:660 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x8031, lqi: 238, rssi: 0
22:46:08:660 asdu: 1300020101151001ffff2e2100442e4c100188170074af35010075
22:46:08:660 APS-DATA.indication request id: 85 -> finished
22:46:08:660 APS-DATA.request id: 85 erase from queue
22:46:08:660 ZDP status = 0x00 -> SUCCESS
22:46:08:660 void deCONZ::zmNode::setFetched(deCONZ::RequestId, bool) fetched item: 8, node: 0x0000
22:46:08:660 ZDP Mgmt_Lqi_rsp zdpSeq: 19 from 0x00212EFFFF011015 total: 2, startIndex: 1, listCount: 1
22:46:08:660 * neighbor: 0x00178801104C2E44 (0xAF74), LQI: 117, relation: 0x01 rxOnWHenIdle: 1
22:46:08:926 device discover rotate, node 0x00178801027a3dd1 is in wait state
22:46:09:405 device discover rotate, node 0x00178801104c2e44 is in wait state
22:46:09:886 MGTM_Lqi_req zdpSeq: 21 to 0x00212EFFFF011015 start index 0
22:46:09:886 APS-DATA.request id: 94, addrmode: 0x02, addr: 0x0000, profile: 0x0000, cluster: 0x0031, ep: 0x00 queue: 0 len: 2
22:46:09:926 APS-DATA.confirm id: 94, status: 0x00 SUCCESS
22:46:09:926 APS-DATA.confirm request id: 94 -> confirmed, timeout 59920
22:46:09:958 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x0031, lqi: 238, rssi: 0
22:46:09:958 asdu: 1500
22:46:09:958 ZDP status = 0x00 -> SUCCESS
22:46:09:990 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x8031, lqi: 238, rssi: 0
22:46:09:990 asdu: 1500020001151001ffff2e2100d13d7a020188170091b035010074
22:46:09:990 APS-DATA.indication request id: 94 -> finished
22:46:09:990 APS-DATA.request id: 94 erase from queue
22:46:09:990 ZDP status = 0x00 -> SUCCESS
22:46:09:990 MGTM_Lqi_req zdpSeq: 22 to 0x00212EFFFF011015 start index 1
22:46:09:990 APS-DATA.request id: 97, addrmode: 0x02, addr: 0x0000, profile: 0x0000, cluster: 0x0031, ep: 0x00 queue: 0 len: 2
22:46:09:990 ZDP Mgmt_Lqi_rsp zdpSeq: 21 from 0x00212EFFFF011015 total: 2, startIndex: 0, listCount: 1
22:46:09:990 * neighbor: 0x00178801027A3DD1 (0xB091), LQI: 116, relation: 0x01 rxOnWHenIdle: 1
22:46:10:038 APS-DATA.confirm id: 97, status: 0x00 SUCCESS
22:46:10:038 APS-DATA.confirm request id: 97 -> confirmed, timeout 60000
22:46:10:070 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x0031, lqi: 238, rssi: 0
22:46:10:070 asdu: 1601
22:46:10:070 ZDP status = 0x00 -> SUCCESS
22:46:10:102 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x8031, lqi: 238, rssi: 0
22:46:10:102 asdu: 1600020101151001ffff2e2100442e4c100188170074af35010075
22:46:10:102 APS-DATA.indication request id: 97 -> finished
22:46:10:102 APS-DATA.request id: 97 erase from queue
22:46:10:102 ZDP status = 0x00 -> SUCCESS
22:46:10:102 void deCONZ::zmNode::setFetched(deCONZ::RequestId, bool) fetched item: 8, node: 0x0000
22:46:10:102 ZDP Mgmt_Lqi_rsp zdpSeq: 22 from 0x00212EFFFF011015 total: 2, startIndex: 1, listCount: 1
22:46:10:102 * neighbor: 0x00178801104C2E44 (0xAF74), LQI: 117, relation: 0x01 rxOnWHenIdle: 1
22:46:10:366 device discover rotate, node 0x00178801027a3dd1 is in wait state
22:46:10:846 device discover rotate, node 0x00178801104c2e44 is in wait state
22:46:11:325 MGTM_Lqi_req zdpSeq: 23 to 0x00212EFFFF011015 start index 0
22:46:11:325 APS-DATA.request id: 106, addrmode: 0x02, addr: 0x0000, profile: 0x0000, cluster: 0x0031, ep: 0x00 queue: 0 len: 2
22:46:11:367 APS-DATA.confirm id: 106, status: 0x00 SUCCESS
22:46:11:367 APS-DATA.confirm request id: 106 -> confirmed, timeout 59920
22:46:11:399 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x0031, lqi: 238, rssi: 0
22:46:11:399 asdu: 1700
22:46:11:400 ZDP status = 0x00 -> SUCCESS
22:46:11:432 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x8031, lqi: 238, rssi: 0
22:46:11:432 asdu: 1700020001151001ffff2e2100d13d7a020188170091b035010074
22:46:11:432 APS-DATA.indication request id: 106 -> finished
22:46:11:432 APS-DATA.request id: 106 erase from queue
22:46:11:432 ZDP status = 0x00 -> SUCCESS
22:46:11:432 MGTM_Lqi_req zdpSeq: 24 to 0x00212EFFFF011015 start index 1
22:46:11:432 APS-DATA.request id: 109, addrmode: 0x02, addr: 0x0000, profile: 0x0000, cluster: 0x0031, ep: 0x00 queue: 0 len: 2
22:46:11:432 ZDP Mgmt_Lqi_rsp zdpSeq: 23 from 0x00212EFFFF011015 total: 2, startIndex: 0, listCount: 1
22:46:11:432 * neighbor: 0x00178801027A3DD1 (0xB091), LQI: 116, relation: 0x01 rxOnWHenIdle: 1
22:46:11:480 APS-DATA.confirm id: 109, status: 0x00 SUCCESS
22:46:11:480 APS-DATA.confirm request id: 109 -> confirmed, timeout 60000
22:46:11:512 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x0031, lqi: 238, rssi: 0
22:46:11:512 asdu: 1801
22:46:11:512 ZDP status = 0x00 -> SUCCESS
22:46:11:544 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x8031, lqi: 238, rssi: 0
22:46:11:544 asdu: 1800020101151001ffff2e2100442e4c100188170074af35010075
22:46:11:544 APS-DATA.indication request id: 109 -> finished
22:46:11:544 APS-DATA.request id: 109 erase from queue
22:46:11:544 ZDP status = 0x00 -> SUCCESS
22:46:11:544 void deCONZ::zmNode::setFetched(deCONZ::RequestId, bool) fetched item: 8, node: 0x0000
22:46:11:544 ZDP Mgmt_Lqi_rsp zdpSeq: 24 from 0x00212EFFFF011015 total: 2, startIndex: 1, listCount: 1
22:46:11:544 * neighbor: 0x00178801104C2E44 (0xAF74), LQI: 117, relation: 0x01 rxOnWHenIdle: 1
22:46:11:805 device discover rotate, node 0x00178801027a3dd1 is in wait state
22:46:12:286 device discover rotate, node 0x00178801104c2e44 is in wait state
22:46:12:766 MGTM_Lqi_req zdpSeq: 25 to 0x00212EFFFF011015 start index 0
22:46:12:766 APS-DATA.request id: 117, addrmode: 0x02, addr: 0x0000, profile: 0x0000, cluster: 0x0031, ep: 0x00 queue: 0 len: 2
22:46:12:809 APS-DATA.confirm id: 117, status: 0x00 SUCCESS
22:46:12:809 APS-DATA.confirm request id: 117 -> confirmed, timeout 59920
22:46:12:841 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x0031, lqi: 238, rssi: 0
22:46:12:841 asdu: 1900
22:46:12:841 ZDP status = 0x00 -> SUCCESS
22:46:12:873 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x8031, lqi: 238, rssi: 0
22:46:12:873 asdu: 1900020001151001ffff2e2100d13d7a020188170091b035010074
22:46:12:873 APS-DATA.indication request id: 117 -> finished
22:46:12:873 APS-DATA.request id: 117 erase from queue
22:46:12:873 ZDP status = 0x00 -> SUCCESS
22:46:12:873 MGTM_Lqi_req zdpSeq: 26 to 0x00212EFFFF011015 start index 1
22:46:12:873 APS-DATA.request id: 121, addrmode: 0x02, addr: 0x0000, profile: 0x0000, cluster: 0x0031, ep: 0x00 queue: 0 len: 2
22:46:12:873 ZDP Mgmt_Lqi_rsp zdpSeq: 25 from 0x00212EFFFF011015 total: 2, startIndex: 0, listCount: 1
22:46:12:873 * neighbor: 0x00178801027A3DD1 (0xB091), LQI: 116, relation: 0x01 rxOnWHenIdle: 1
22:46:12:921 APS-DATA.confirm id: 121, status: 0x00 SUCCESS
22:46:12:922 APS-DATA.confirm request id: 121 -> confirmed, timeout 60000
22:46:12:953 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x0031, lqi: 238, rssi: 0
22:46:12:953 asdu: 1a01
22:46:12:953 ZDP status = 0x00 -> SUCCESS
22:46:12:985 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x8031, lqi: 238, rssi: 0
22:46:12:986 asdu: 1a00020101151001ffff2e2100442e4c100188170074af35010075
22:46:12:986 APS-DATA.indication request id: 121 -> finished
22:46:12:986 APS-DATA.request id: 121 erase from queue
22:46:12:986 ZDP status = 0x00 -> SUCCESS
22:46:12:986 void deCONZ::zmNode::setFetched(deCONZ::RequestId, bool) fetched item: 8, node: 0x0000
22:46:12:986 ZDP Mgmt_Lqi_rsp zdpSeq: 26 from 0x00212EFFFF011015 total: 2, startIndex: 1, listCount: 1
22:46:12:986 * neighbor: 0x00178801104C2E44 (0xAF74), LQI: 117, relation: 0x01 rxOnWHenIdle: 1
22:46:13:245 device discover rotate, node 0x00178801027a3dd1 is in wait state
22:46:13:725 device discover rotate, node 0x00178801104c2e44 is in wait state
22:46:14:205 MGTM_Lqi_req zdpSeq: 27 to 0x00212EFFFF011015 start index 0
22:46:14:205 APS-DATA.request id: 129, addrmode: 0x02, addr: 0x0000, profile: 0x0000, cluster: 0x0031, ep: 0x00 queue: 0 len: 2
22:46:14:251 APS-DATA.confirm id: 129, status: 0x00 SUCCESS
22:46:14:251 APS-DATA.confirm request id: 129 -> confirmed, timeout 59920
22:46:14:283 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x0031, lqi: 238, rssi: 0
22:46:14:283 asdu: 1b00
22:46:14:283 ZDP status = 0x00 -> SUCCESS
22:46:14:315 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x8031, lqi: 238, rssi: 0
22:46:14:315 asdu: 1b00020001151001ffff2e2100d13d7a020188170091b035010074
22:46:14:315 APS-DATA.indication request id: 129 -> finished
22:46:14:315 APS-DATA.request id: 129 erase from queue
22:46:14:315 ZDP status = 0x00 -> SUCCESS
22:46:14:315 MGTM_Lqi_req zdpSeq: 28 to 0x00212EFFFF011015 start index 1
22:46:14:315 APS-DATA.request id: 133, addrmode: 0x02, addr: 0x0000, profile: 0x0000, cluster: 0x0031, ep: 0x00 queue: 0 len: 2
22:46:14:315 ZDP Mgmt_Lqi_rsp zdpSeq: 27 from 0x00212EFFFF011015 total: 2, startIndex: 0, listCount: 1
22:46:14:315 * neighbor: 0x00178801027A3DD1 (0xB091), LQI: 116, relation: 0x01 rxOnWHenIdle: 1
22:46:14:363 APS-DATA.confirm id: 133, status: 0x00 SUCCESS
22:46:14:363 APS-DATA.confirm request id: 133 -> confirmed, timeout 60000
22:46:14:395 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x0031, lqi: 238, rssi: 0
22:46:14:395 asdu: 1c01
22:46:14:395 ZDP status = 0x00 -> SUCCESS
22:46:14:427 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x8031, lqi: 238, rssi: 0
22:46:14:427 asdu: 1c00020101151001ffff2e2100442e4c100188170074af35010075
22:46:14:427 APS-DATA.indication request id: 133 -> finished
22:46:14:427 APS-DATA.request id: 133 erase from queue
22:46:14:427 ZDP status = 0x00 -> SUCCESS
22:46:14:427 void deCONZ::zmNode::setFetched(deCONZ::RequestId, bool) fetched item: 8, node: 0x0000
22:46:14:427 ZDP Mgmt_Lqi_rsp zdpSeq: 28 from 0x00212EFFFF011015 total: 2, startIndex: 1, listCount: 1
22:46:14:427 * neighbor: 0x00178801104C2E44 (0xAF74), LQI: 117, relation: 0x01 rxOnWHenIdle: 1
22:46:14:685 device discover rotate, node 0x00178801027a3dd1 is in wait state
22:46:15:165 device discover rotate, node 0x00178801104c2e44 is in wait state
22:46:15:646 MGTM_Lqi_req zdpSeq: 29 to 0x00212EFFFF011015 start index 0
22:46:15:646 APS-DATA.request id: 141, addrmode: 0x02, addr: 0x0000, profile: 0x0000, cluster: 0x0031, ep: 0x00 queue: 0 len: 2
22:46:15:693 APS-DATA.confirm id: 141, status: 0x00 SUCCESS
22:46:15:693 APS-DATA.confirm request id: 141 -> confirmed, timeout 59920
22:46:15:725 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x0031, lqi: 238, rssi: 0
22:46:15:725 asdu: 1d00
22:46:15:725 ZDP status = 0x00 -> SUCCESS
22:46:15:757 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x8031, lqi: 238, rssi: 0
22:46:15:757 asdu: 1d00020001151001ffff2e2100d13d7a020188170091b035010074
22:46:15:757 APS-DATA.indication request id: 141 -> finished
22:46:15:757 APS-DATA.request id: 141 erase from queue
22:46:15:757 ZDP status = 0x00 -> SUCCESS
22:46:15:757 MGTM_Lqi_req zdpSeq: 30 to 0x00212EFFFF011015 start index 1
22:46:15:757 APS-DATA.request id: 144, addrmode: 0x02, addr: 0x0000, profile: 0x0000, cluster: 0x0031, ep: 0x00 queue: 0 len: 2
22:46:15:757 ZDP Mgmt_Lqi_rsp zdpSeq: 29 from 0x00212EFFFF011015 total: 2, startIndex: 0, listCount: 1
22:46:15:757 * neighbor: 0x00178801027A3DD1 (0xB091), LQI: 116, relation: 0x01 rxOnWHenIdle: 1
22:46:15:805 APS-DATA.confirm id: 144, status: 0x00 SUCCESS
22:46:15:805 APS-DATA.confirm request id: 144 -> confirmed, timeout 60000
22:46:15:837 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x0031, lqi: 238, rssi: 0
22:46:15:837 asdu: 1e01
22:46:15:837 ZDP status = 0x00 -> SUCCESS
22:46:15:869 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x8031, lqi: 238, rssi: 0
22:46:15:869 asdu: 1e00020101151001ffff2e2100442e4c100188170074af35010075
22:46:15:869 APS-DATA.indication request id: 144 -> finished
22:46:15:869 APS-DATA.request id: 144 erase from queue
22:46:15:869 ZDP status = 0x00 -> SUCCESS
22:46:15:869 void deCONZ::zmNode::setFetched(deCONZ::RequestId, bool) fetched item: 8, node: 0x0000
22:46:15:869 ZDP Mgmt_Lqi_rsp zdpSeq: 30 from 0x00212EFFFF011015 total: 2, startIndex: 1, listCount: 1
22:46:15:869 * neighbor: 0x00178801104C2E44 (0xAF74), LQI: 117, relation: 0x01 rxOnWHenIdle: 1
22:46:16:125 device discover rotate, node 0x00178801027a3dd1 is in wait state
22:46:16:606 device discover rotate, node 0x00178801104c2e44 is in wait state
22:46:17:085 MGTM_Lqi_req zdpSeq: 32 to 0x00212EFFFF011015 start index 0
22:46:17:085 APS-DATA.request id: 154, addrmode: 0x02, addr: 0x0000, profile: 0x0000, cluster: 0x0031, ep: 0x00 queue: 0 len: 2
22:46:17:119 APS-DATA.confirm id: 154, status: 0x00 SUCCESS
22:46:17:119 APS-DATA.confirm request id: 154 -> confirmed, timeout 59920
22:46:17:151 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x0031, lqi: 0, rssi: 0
22:46:17:151 asdu: 2000
22:46:17:151 ZDP status = 0x00 -> SUCCESS
22:46:17:183 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x8031, lqi: 0, rssi: 0
22:46:17:183 asdu: 2000020001151001ffff2e2100d13d7a020188170091b035010074
22:46:17:183 APS-DATA.indication request id: 154 -> finished
22:46:17:183 APS-DATA.request id: 154 erase from queue
22:46:17:183 ZDP status = 0x00 -> SUCCESS
22:46:17:183 MGTM_Lqi_req zdpSeq: 33 to 0x00212EFFFF011015 start index 1
22:46:17:183 APS-DATA.request id: 157, addrmode: 0x02, addr: 0x0000, profile: 0x0000, cluster: 0x0031, ep: 0x00 queue: 0 len: 2
22:46:17:183 ZDP Mgmt_Lqi_rsp zdpSeq: 32 from 0x00212EFFFF011015 total: 2, startIndex: 0, listCount: 1
22:46:17:183 * neighbor: 0x00178801027A3DD1 (0xB091), LQI: 116, relation: 0x01 rxOnWHenIdle: 1
22:46:17:231 APS-DATA.confirm id: 157, status: 0x00 SUCCESS
22:46:17:231 APS-DATA.confirm request id: 157 -> confirmed, timeout 60000
22:46:17:263 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x0031, lqi: 0, rssi: 0
22:46:17:263 asdu: 2101
22:46:17:263 ZDP status = 0x00 -> SUCCESS
22:46:17:295 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x8031, lqi: 0, rssi: 0
22:46:17:295 asdu: 2100020101151001ffff2e2100442e4c100188170074af35010075
22:46:17:295 APS-DATA.indication request id: 157 -> finished
22:46:17:295 APS-DATA.request id: 157 erase from queue
22:46:17:295 ZDP status = 0x00 -> SUCCESS
22:46:17:295 void deCONZ::zmNode::setFetched(deCONZ::RequestId, bool) fetched item: 8, node: 0x0000
22:46:17:295 ZDP Mgmt_Lqi_rsp zdpSeq: 33 from 0x00212EFFFF011015 total: 2, startIndex: 1, listCount: 1
22:46:17:295 * neighbor: 0x00178801104C2E44 (0xAF74), LQI: 117, relation: 0x01 rxOnWHenIdle: 1
22:46:17:565 device discover rotate, node 0x00178801027a3dd1 is in wait state
22:46:18:025 Wait 4s till query finished
22:46:18:045 device discover rotate, node 0x00178801104c2e44 is in wait state
22:46:18:525 MGTM_Lqi_req zdpSeq: 34 to 0x00212EFFFF011015 start index 0
22:46:18:525 APS-DATA.request id: 166, addrmode: 0x02, addr: 0x0000, profile: 0x0000, cluster: 0x0031, ep: 0x00 queue: 0 len: 2
22:46:18:561 APS-DATA.confirm id: 166, status: 0x00 SUCCESS
22:46:18:561 APS-DATA.confirm request id: 166 -> confirmed, timeout 59920
22:46:18:593 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x0031, lqi: 0, rssi: 0
22:46:18:593 asdu: 2200
22:46:18:593 ZDP status = 0x00 -> SUCCESS
22:46:18:625 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x8031, lqi: 0, rssi: 0
22:46:18:625 asdu: 2200020001151001ffff2e2100d13d7a020188170091b035010074
22:46:18:625 APS-DATA.indication request id: 166 -> finished
22:46:18:625 APS-DATA.request id: 166 erase from queue
22:46:18:625 ZDP status = 0x00 -> SUCCESS
22:46:18:625 MGTM_Lqi_req zdpSeq: 35 to 0x00212EFFFF011015 start index 1
22:46:18:625 APS-DATA.request id: 169, addrmode: 0x02, addr: 0x0000, profile: 0x0000, cluster: 0x0031, ep: 0x00 queue: 0 len: 2
22:46:18:625 ZDP Mgmt_Lqi_rsp zdpSeq: 34 from 0x00212EFFFF011015 total: 2, startIndex: 0, listCount: 1
22:46:18:625 * neighbor: 0x00178801027A3DD1 (0xB091), LQI: 116, relation: 0x01 rxOnWHenIdle: 1
22:46:18:673 APS-DATA.confirm id: 169, status: 0x00 SUCCESS
22:46:18:673 APS-DATA.confirm request id: 169 -> confirmed, timeout 60000
22:46:18:705 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x0031, lqi: 0, rssi: 0
22:46:18:705 asdu: 2301
22:46:18:705 ZDP status = 0x00 -> SUCCESS
22:46:18:737 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x8031, lqi: 0, rssi: 0
22:46:18:737 asdu: 2300020101151001ffff2e2100442e4c100188170074af35010075
22:46:18:737 APS-DATA.indication request id: 169 -> finished
22:46:18:737 APS-DATA.request id: 169 erase from queue
22:46:18:737 ZDP status = 0x00 -> SUCCESS
22:46:18:737 void deCONZ::zmNode::setFetched(deCONZ::RequestId, bool) fetched item: 8, node: 0x0000
22:46:18:737 ZDP Mgmt_Lqi_rsp zdpSeq: 35 from 0x00212EFFFF011015 total: 2, startIndex: 1, listCount: 1
22:46:18:737 * neighbor: 0x00178801104C2E44 (0xAF74), LQI: 117, relation: 0x01 rxOnWHenIdle: 1
22:46:19:005 device discover rotate, node 0x00178801027a3dd1 is in wait state
22:46:19:025 Wait 3s till query finished
22:46:19:485 device discover rotate, node 0x00178801104c2e44 is in wait state
22:46:19:966 MGTM_Lqi_req zdpSeq: 36 to 0x00212EFFFF011015 start index 0
22:46:19:966 APS-DATA.request id: 177, addrmode: 0x02, addr: 0x0000, profile: 0x0000, cluster: 0x0031, ep: 0x00 queue: 0 len: 2
22:46:19:002 APS-DATA.confirm id: 177, status: 0x00 SUCCESS
22:46:19:002 APS-DATA.confirm request id: 177 -> confirmed, timeout 59920
22:46:20:025 Wait 2s till query finished
22:46:20:034 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x0031, lqi: 0, rssi: 0
22:46:20:034 asdu: 2400
22:46:20:034 ZDP status = 0x00 -> SUCCESS
22:46:20:067 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x8031, lqi: 0, rssi: 0
22:46:20:067 asdu: 2400020001151001ffff2e2100d13d7a020188170091b035010074
22:46:20:067 APS-DATA.indication request id: 177 -> finished
22:46:20:067 APS-DATA.request id: 177 erase from queue
22:46:20:067 ZDP status = 0x00 -> SUCCESS
22:46:20:067 MGTM_Lqi_req zdpSeq: 37 to 0x00212EFFFF011015 start index 1
22:46:20:067 APS-DATA.request id: 181, addrmode: 0x02, addr: 0x0000, profile: 0x0000, cluster: 0x0031, ep: 0x00 queue: 0 len: 2
22:46:20:067 ZDP Mgmt_Lqi_rsp zdpSeq: 36 from 0x00212EFFFF011015 total: 2, startIndex: 0, listCount: 1
22:46:20:067 * neighbor: 0x00178801027A3DD1 (0xB091), LQI: 116, relation: 0x01 rxOnWHenIdle: 1
22:46:20:114 APS-DATA.confirm id: 181, status: 0x00 SUCCESS
22:46:20:115 APS-DATA.confirm request id: 181 -> confirmed, timeout 60000
22:46:20:146 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x0031, lqi: 0, rssi: 0
22:46:20:147 asdu: 2501
22:46:20:147 ZDP status = 0x00 -> SUCCESS
22:46:20:178 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x8031, lqi: 0, rssi: 0
22:46:20:178 asdu: 2500020101151001ffff2e2100442e4c100188170074af35010075
22:46:20:179 APS-DATA.indication request id: 181 -> finished
22:46:20:179 APS-DATA.request id: 181 erase from queue
22:46:20:179 ZDP status = 0x00 -> SUCCESS
22:46:20:179 void deCONZ::zmNode::setFetched(deCONZ::RequestId, bool) fetched item: 8, node: 0x0000
22:46:20:179 ZDP Mgmt_Lqi_rsp zdpSeq: 37 from 0x00212EFFFF011015 total: 2, startIndex: 1, listCount: 1
22:46:20:179 * neighbor: 0x00178801104C2E44 (0xAF74), LQI: 117, relation: 0x01 rxOnWHenIdle: 1
22:46:20:445 device discover rotate, node 0x00178801027a3dd1 is in wait state
22:46:20:925 device discover rotate, node 0x00178801104c2e44 is in wait state
22:46:21:025 Wait 1s till query finished
22:46:21:406 MGTM_Lqi_req zdpSeq: 38 to 0x00212EFFFF011015 start index 0
22:46:21:406 APS-DATA.request id: 189, addrmode: 0x02, addr: 0x0000, profile: 0x0000, cluster: 0x0031, ep: 0x00 queue: 0 len: 2
22:46:21:444 APS-DATA.confirm id: 189, status: 0x00 SUCCESS
22:46:21:444 APS-DATA.confirm request id: 189 -> confirmed, timeout 59920
22:46:21:476 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x0031, lqi: 0, rssi: 0
22:46:21:476 asdu: 2600
22:46:21:476 ZDP status = 0x00 -> SUCCESS
22:46:21:508 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x8031, lqi: 0, rssi: 0
22:46:21:508 asdu: 2600020001151001ffff2e2100d13d7a020188170091b035010074
22:46:21:508 APS-DATA.indication request id: 189 -> finished
22:46:21:508 APS-DATA.request id: 189 erase from queue
22:46:21:508 ZDP status = 0x00 -> SUCCESS
22:46:21:508 MGTM_Lqi_req zdpSeq: 39 to 0x00212EFFFF011015 start index 1
22:46:21:508 APS-DATA.request id: 192, addrmode: 0x02, addr: 0x0000, profile: 0x0000, cluster: 0x0031, ep: 0x00 queue: 0 len: 2
22:46:21:508 ZDP Mgmt_Lqi_rsp zdpSeq: 38 from 0x00212EFFFF011015 total: 2, startIndex: 0, listCount: 1
22:46:21:508 * neighbor: 0x00178801027A3DD1 (0xB091), LQI: 116, relation: 0x01 rxOnWHenIdle: 1
22:46:21:556 APS-DATA.confirm id: 192, status: 0x00 SUCCESS
22:46:21:556 APS-DATA.confirm request id: 192 -> confirmed, timeout 60000
22:46:21:588 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x0031, lqi: 0, rssi: 0
22:46:21:588 asdu: 2701
22:46:21:588 ZDP status = 0x00 -> SUCCESS
22:46:21:620 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x8031, lqi: 0, rssi: 0
22:46:21:620 asdu: 2700020101151001ffff2e2100442e4c100188170074af35010075
22:46:21:620 APS-DATA.indication request id: 192 -> finished
22:46:21:620 APS-DATA.request id: 192 erase from queue
22:46:21:620 ZDP status = 0x00 -> SUCCESS
22:46:21:620 void deCONZ::zmNode::setFetched(deCONZ::RequestId, bool) fetched item: 8, node: 0x0000
22:46:21:620 ZDP Mgmt_Lqi_rsp zdpSeq: 39 from 0x00212EFFFF011015 total: 2, startIndex: 1, listCount: 1
22:46:21:620 * neighbor: 0x00178801104C2E44 (0xAF74), LQI: 117, relation: 0x01 rxOnWHenIdle: 1
22:46:21:885 device discover rotate, node 0x00178801027a3dd1 is in wait state
22:46:22:025 Wait 0s till query finished
22:46:22:366 device discover rotate, node 0x00178801104c2e44 is in wait state
22:46:22:846 MGTM_Lqi_req zdpSeq: 40 to 0x00212EFFFF011015 start index 0
22:46:22:846 APS-DATA.request id: 201, addrmode: 0x02, addr: 0x0000, profile: 0x0000, cluster: 0x0031, ep: 0x00 queue: 0 len: 2
22:46:22:886 APS-DATA.confirm id: 201, status: 0x00 SUCCESS
22:46:22:886 APS-DATA.confirm request id: 201 -> confirmed, timeout 59920
22:46:22:918 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x0031, lqi: 0, rssi: 0
22:46:22:918 asdu: 2800
22:46:22:918 ZDP status = 0x00 -> SUCCESS
22:46:22:950 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x8031, lqi: 0, rssi: 0
22:46:22:950 asdu: 2800020001151001ffff2e2100d13d7a020188170091b035010074
22:46:22:950 APS-DATA.indication request id: 201 -> finished
22:46:22:950 APS-DATA.request id: 201 erase from queue
22:46:22:950 ZDP status = 0x00 -> SUCCESS
22:46:22:950 MGTM_Lqi_req zdpSeq: 41 to 0x00212EFFFF011015 start index 1
22:46:22:950 APS-DATA.request id: 204, addrmode: 0x02, addr: 0x0000, profile: 0x0000, cluster: 0x0031, ep: 0x00 queue: 0 len: 2
22:46:22:950 ZDP Mgmt_Lqi_rsp zdpSeq: 40 from 0x00212EFFFF011015 total: 2, startIndex: 0, listCount: 1
22:46:22:950 * neighbor: 0x00178801027A3DD1 (0xB091), LQI: 116, relation: 0x01 rxOnWHenIdle: 1
22:46:22:998 APS-DATA.confirm id: 204, status: 0x00 SUCCESS
22:46:22:998 APS-DATA.confirm request id: 204 -> confirmed, timeout 60000
22:46:23:026 Idle timer triggered
22:46:23:026 enable support for CIE 1931 XY color mode for groups
22:46:23:030 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x0031, lqi: 0, rssi: 0
22:46:23:030 asdu: 2901
22:46:23:030 ZDP status = 0x00 -> SUCCESS
22:46:23:062 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x8031, lqi: 0, rssi: 0
22:46:23:062 asdu: 2900020101151001ffff2e2100442e4c100188170074af35010075
22:46:23:062 APS-DATA.indication request id: 204 -> finished
22:46:23:062 APS-DATA.request id: 204 erase from queue
22:46:23:062 ZDP status = 0x00 -> SUCCESS
22:46:23:062 void deCONZ::zmNode::setFetched(deCONZ::RequestId, bool) fetched item: 8, node: 0x0000
22:46:23:062 ZDP Mgmt_Lqi_rsp zdpSeq: 41 from 0x00212EFFFF011015 total: 2, startIndex: 1, listCount: 1
22:46:23:062 * neighbor: 0x00178801104C2E44 (0xAF74), LQI: 117, relation: 0x01 rxOnWHenIdle: 1
22:46:23:325 device discover rotate, node 0x00178801027a3dd1 is in wait state
22:46:23:526 scan skip host .10
22:46:23:805 device discover rotate, node 0x00178801104c2e44 is in wait state
22:46:24:285 MGTM_Lqi_req zdpSeq: 43 to 0x00212EFFFF011015 start index 0
22:46:24:285 APS-DATA.request id: 214, addrmode: 0x02, addr: 0x0000, profile: 0x0000, cluster: 0x0031, ep: 0x00 queue: 0 len: 2
22:46:24:328 APS-DATA.confirm id: 214, status: 0x00 SUCCESS
22:46:24:328 APS-DATA.confirm request id: 214 -> confirmed, timeout 59920
22:46:24:360 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x0031, lqi: 0, rssi: 0
22:46:24:360 asdu: 2b00
22:46:24:360 ZDP status = 0x00 -> SUCCESS
22:46:24:392 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x8031, lqi: 0, rssi: 0
22:46:24:392 asdu: 2b00020001151001ffff2e2100d13d7a020188170091b035010074
22:46:24:392 APS-DATA.indication request id: 214 -> finished
22:46:24:392 APS-DATA.request id: 214 erase from queue
22:46:24:392 ZDP status = 0x00 -> SUCCESS
22:46:24:392 MGTM_Lqi_req zdpSeq: 44 to 0x00212EFFFF011015 start index 1
22:46:24:392 APS-DATA.request id: 217, addrmode: 0x02, addr: 0x0000, profile: 0x0000, cluster: 0x0031, ep: 0x00 queue: 0 len: 2
22:46:24:392 ZDP Mgmt_Lqi_rsp zdpSeq: 43 from 0x00212EFFFF011015 total: 2, startIndex: 0, listCount: 1
22:46:24:392 * neighbor: 0x00178801027A3DD1 (0xB091), LQI: 116, relation: 0x01 rxOnWHenIdle: 1
22:46:24:440 APS-DATA.confirm id: 217, status: 0x00 SUCCESS
22:46:24:440 APS-DATA.confirm request id: 217 -> confirmed, timeout 60000
22:46:24:472 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x0031, lqi: 0, rssi: 0
22:46:24:472 asdu: 2c01
22:46:24:472 ZDP status = 0x00 -> SUCCESS
22:46:24:504 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x8031, lqi: 0, rssi: 0
22:46:24:504 asdu: 2c00020101151001ffff2e2100442e4c100188170074af35010075
22:46:24:504 APS-DATA.indication request id: 217 -> finished
22:46:24:504 APS-DATA.request id: 217 erase from queue
22:46:24:504 ZDP status = 0x00 -> SUCCESS
22:46:24:504 void deCONZ::zmNode::setFetched(deCONZ::RequestId, bool) fetched item: 8, node: 0x0000
22:46:24:504 ZDP Mgmt_Lqi_rsp zdpSeq: 44 from 0x00212EFFFF011015 total: 2, startIndex: 1, listCount: 1
22:46:24:504 * neighbor: 0x00178801104C2E44 (0xAF74), LQI: 117, relation: 0x01 rxOnWHenIdle: 1
22:46:24:765 device discover rotate, node 0x00178801027a3dd1 is in wait state
22:46:25:245 device discover rotate, node 0x00178801104c2e44 is in wait state
22:46:25:725 MGTM_Lqi_req zdpSeq: 45 to 0x00212EFFFF011015 start index 0
22:46:25:725 APS-DATA.request id: 225, addrmode: 0x02, addr: 0x0000, profile: 0x0000, cluster: 0x0031, ep: 0x00 queue: 0 len: 2
22:46:25:769 APS-DATA.confirm id: 225, status: 0x00 SUCCESS
22:46:25:769 APS-DATA.confirm request id: 225 -> confirmed, timeout 59920
22:46:25:801 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x0031, lqi: 0, rssi: 0
22:46:25:801 asdu: 2d00
22:46:25:801 ZDP status = 0x00 -> SUCCESS
22:46:25:833 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x8031, lqi: 0, rssi: 0
22:46:25:833 asdu: 2d00020001151001ffff2e2100d13d7a020188170091b035010074
22:46:25:833 APS-DATA.indication request id: 225 -> finished
22:46:25:833 APS-DATA.request id: 225 erase from queue
22:46:25:833 ZDP status = 0x00 -> SUCCESS
22:46:25:833 MGTM_Lqi_req zdpSeq: 46 to 0x00212EFFFF011015 start index 1
22:46:25:833 APS-DATA.request id: 229, addrmode: 0x02, addr: 0x0000, profile: 0x0000, cluster: 0x0031, ep: 0x00 queue: 0 len: 2
22:46:25:833 ZDP Mgmt_Lqi_rsp zdpSeq: 45 from 0x00212EFFFF011015 total: 2, startIndex: 0, listCount: 1
22:46:25:833 * neighbor: 0x00178801027A3DD1 (0xB091), LQI: 116, relation: 0x01 rxOnWHenIdle: 1
22:46:25:881 APS-DATA.confirm id: 229, status: 0x00 SUCCESS
22:46:25:881 APS-DATA.confirm request id: 229 -> confirmed, timeout 60000
22:46:25:913 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x0031, lqi: 0, rssi: 0
22:46:25:913 asdu: 2e01
22:46:25:913 ZDP status = 0x00 -> SUCCESS
22:46:25:945 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x8031, lqi: 0, rssi: 0
22:46:25:945 asdu: 2e00020101151001ffff2e2100442e4c100188170074af35010075
22:46:25:945 APS-DATA.indication request id: 229 -> finished
22:46:25:945 APS-DATA.request id: 229 erase from queue
22:46:25:945 ZDP status = 0x00 -> SUCCESS
22:46:25:945 void deCONZ::zmNode::setFetched(deCONZ::RequestId, bool) fetched item: 8, node: 0x0000
22:46:25:945 ZDP Mgmt_Lqi_rsp zdpSeq: 46 from 0x00212EFFFF011015 total: 2, startIndex: 1, listCount: 1
22:46:25:945 * neighbor: 0x00178801104C2E44 (0xAF74), LQI: 117, relation: 0x01 rxOnWHenIdle: 1
22:46:26:205 device discover rotate, node 0x00178801027a3dd1 is in wait state
22:46:26:685 device discover rotate, node 0x00178801104c2e44 is in wait state
22:46:27:165 MGTM_Lqi_req zdpSeq: 47 to 0x00212EFFFF011015 start index 0
22:46:27:165 APS-DATA.request id: 237, addrmode: 0x02, addr: 0x0000, profile: 0x0000, cluster: 0x0031, ep: 0x00 queue: 0 len: 2
22:46:27:211 APS-DATA.confirm id: 237, status: 0x00 SUCCESS
22:46:27:211 APS-DATA.confirm request id: 237 -> confirmed, timeout 59920
22:46:27:243 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x0031, lqi: 0, rssi: 0
22:46:27:243 asdu: 2f00
22:46:27:243 ZDP status = 0x00 -> SUCCESS
22:46:27:275 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x8031, lqi: 0, rssi: 0
22:46:27:275 asdu: 2f00020001151001ffff2e2100d13d7a020188170091b035010074
22:46:27:275 APS-DATA.indication request id: 237 -> finished
22:46:27:275 APS-DATA.request id: 237 erase from queue
22:46:27:275 ZDP status = 0x00 -> SUCCESS
22:46:27:275 MGTM_Lqi_req zdpSeq: 48 to 0x00212EFFFF011015 start index 1
22:46:27:275 APS-DATA.request id: 240, addrmode: 0x02, addr: 0x0000, profile: 0x0000, cluster: 0x0031, ep: 0x00 queue: 0 len: 2
22:46:27:275 ZDP Mgmt_Lqi_rsp zdpSeq: 47 from 0x00212EFFFF011015 total: 2, startIndex: 0, listCount: 1
22:46:27:275 * neighbor: 0x00178801027A3DD1 (0xB091), LQI: 116, relation: 0x01 rxOnWHenIdle: 1
22:46:27:323 APS-DATA.confirm id: 240, status: 0x00 SUCCESS
22:46:27:323 APS-DATA.confirm request id: 240 -> confirmed, timeout 60000
22:46:27:355 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x0031, lqi: 0, rssi: 0
22:46:27:355 asdu: 3001
22:46:27:355 ZDP status = 0x00 -> SUCCESS
22:46:27:387 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x8031, lqi: 0, rssi: 0
22:46:27:387 asdu: 3000020101151001ffff2e2100442e4c100188170074af35010075
22:46:27:387 APS-DATA.indication request id: 240 -> finished
22:46:27:387 APS-DATA.request id: 240 erase from queue
22:46:27:387 ZDP status = 0x00 -> SUCCESS
22:46:27:387 void deCONZ::zmNode::setFetched(deCONZ::RequestId, bool) fetched item: 8, node: 0x0000
22:46:27:387 ZDP Mgmt_Lqi_rsp zdpSeq: 48 from 0x00212EFFFF011015 total: 2, startIndex: 1, listCount: 1
22:46:27:387 * neighbor: 0x00178801104C2E44 (0xAF74), LQI: 117, relation: 0x01 rxOnWHenIdle: 1
22:46:27:646 device discover rotate, node 0x00178801027a3dd1 is in wait state
22:46:28:126 device discover rotate, node 0x00178801104c2e44 is in wait state
22:46:28:605 MGTM_Lqi_req zdpSeq: 49 to 0x00212EFFFF011015 start index 0
22:46:28:605 APS-DATA.request id: 249, addrmode: 0x02, addr: 0x0000, profile: 0x0000, cluster: 0x0031, ep: 0x00 queue: 0 len: 2
22:46:28:652 APS-DATA.confirm id: 249, status: 0x00 SUCCESS
22:46:28:652 APS-DATA.confirm request id: 249 -> confirmed, timeout 59920
22:46:28:684 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x0031, lqi: 238, rssi: 0
22:46:28:684 asdu: 3100
22:46:28:684 ZDP status = 0x00 -> SUCCESS
22:46:28:717 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x8031, lqi: 238, rssi: 0
22:46:28:717 asdu: 3100020001151001ffff2e2100d13d7a020188170091b035010074
22:46:28:717 APS-DATA.indication request id: 249 -> finished
22:46:28:717 APS-DATA.request id: 249 erase from queue
22:46:28:717 ZDP status = 0x00 -> SUCCESS
22:46:28:717 MGTM_Lqi_req zdpSeq: 50 to 0x00212EFFFF011015 start index 1
22:46:28:717 APS-DATA.request id: 252, addrmode: 0x02, addr: 0x0000, profile: 0x0000, cluster: 0x0031, ep: 0x00 queue: 0 len: 2
22:46:28:717 ZDP Mgmt_Lqi_rsp zdpSeq: 49 from 0x00212EFFFF011015 total: 2, startIndex: 0, listCount: 1
22:46:28:717 * neighbor: 0x00178801027A3DD1 (0xB091), LQI: 116, relation: 0x01 rxOnWHenIdle: 1
22:46:28:765 APS-DATA.confirm id: 252, status: 0x00 SUCCESS
22:46:28:765 APS-DATA.confirm request id: 252 -> confirmed, timeout 60000
22:46:28:797 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x0031, lqi: 238, rssi: 0
22:46:28:797 asdu: 3201
22:46:28:797 ZDP status = 0x00 -> SUCCESS
22:46:28:829 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x8031, lqi: 238, rssi: 0
22:46:28:829 asdu: 3200020101151001ffff2e2100442e4c100188170074af35010075
22:46:28:829 APS-DATA.indication request id: 252 -> finished
22:46:28:829 APS-DATA.request id: 252 erase from queue
22:46:28:829 ZDP status = 0x00 -> SUCCESS
22:46:28:829 void deCONZ::zmNode::setFetched(deCONZ::RequestId, bool) fetched item: 8, node: 0x0000
22:46:28:829 ZDP Mgmt_Lqi_rsp zdpSeq: 50 from 0x00212EFFFF011015 total: 2, startIndex: 1, listCount: 1
22:46:28:829 * neighbor: 0x00178801104C2E44 (0xAF74), LQI: 117, relation: 0x01 rxOnWHenIdle: 1
22:46:29:085 device discover rotate, node 0x00178801027a3dd1 is in wait state
22:46:29:566 device discover rotate, node 0x00178801104c2e44 is in wait state
22:46:30:045 MGTM_Lqi_req zdpSeq: 51 to 0x00212EFFFF011015 start index 0
22:46:30:045 APS-DATA.request id: 5, addrmode: 0x02, addr: 0x0000, profile: 0x0000, cluster: 0x0031, ep: 0x00 queue: 0 len: 2
22:46:30:078 APS-DATA.confirm id: 5, status: 0x00 SUCCESS
22:46:30:078 APS-DATA.confirm request id: 5 -> confirmed, timeout 59920
22:46:30:110 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x0031, lqi: 238, rssi: 0
22:46:30:110 asdu: 3300
22:46:30:110 ZDP status = 0x00 -> SUCCESS
22:46:30:142 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x8031, lqi: 238, rssi: 0
22:46:30:142 asdu: 3300020001151001ffff2e2100d13d7a020188170091b035010074
22:46:30:142 APS-DATA.indication request id: 5 -> finished
22:46:30:142 APS-DATA.request id: 5 erase from queue
22:46:30:143 ZDP status = 0x00 -> SUCCESS
22:46:30:143 MGTM_Lqi_req zdpSeq: 52 to 0x00212EFFFF011015 start index 1
22:46:30:143 APS-DATA.request id: 8, addrmode: 0x02, addr: 0x0000, profile: 0x0000, cluster: 0x0031, ep: 0x00 queue: 0 len: 2
22:46:30:143 ZDP Mgmt_Lqi_rsp zdpSeq: 51 from 0x00212EFFFF011015 total: 2, startIndex: 0, listCount: 1
22:46:30:143 * neighbor: 0x00178801027A3DD1 (0xB091), LQI: 116, relation: 0x01 rxOnWHenIdle: 1
22:46:30:190 APS-DATA.confirm id: 8, status: 0x00 SUCCESS
22:46:30:190 APS-DATA.confirm request id: 8 -> confirmed, timeout 60000
22:46:30:222 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x0031, lqi: 238, rssi: 0
22:46:30:222 asdu: 3401
22:46:30:222 ZDP status = 0x00 -> SUCCESS
22:46:30:255 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x8031, lqi: 238, rssi: 0
22:46:30:255 asdu: 3400020101151001ffff2e2100442e4c100188170074af35010075
22:46:30:255 APS-DATA.indication request id: 8 -> finished
22:46:30:255 APS-DATA.request id: 8 erase from queue
22:46:30:255 ZDP status = 0x00 -> SUCCESS
22:46:30:255 void deCONZ::zmNode::setFetched(deCONZ::RequestId, bool) fetched item: 8, node: 0x0000
22:46:30:255 ZDP Mgmt_Lqi_rsp zdpSeq: 52 from 0x00212EFFFF011015 total: 2, startIndex: 1, listCount: 1
22:46:30:255 * neighbor: 0x00178801104C2E44 (0xAF74), LQI: 117, relation: 0x01 rxOnWHenIdle: 1
22:46:30:525 device discover rotate, node 0x00178801027a3dd1 is in wait state
22:46:31:006 device discover rotate, node 0x00178801104c2e44 is in wait state
22:46:31:486 MGTM_Lqi_req zdpSeq: 54 to 0x00212EFFFF011015 start index 0
22:46:31:486 APS-DATA.request id: 17, addrmode: 0x02, addr: 0x0000, profile: 0x0000, cluster: 0x0031, ep: 0x00 queue: 0 len: 2
22:46:31:520 APS-DATA.confirm id: 17, status: 0x00 SUCCESS
22:46:31:520 APS-DATA.confirm request id: 17 -> confirmed, timeout 59920
22:46:31:552 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x0031, lqi: 238, rssi: 0
22:46:31:552 asdu: 3600
22:46:31:552 ZDP status = 0x00 -> SUCCESS
22:46:31:584 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x8031, lqi: 238, rssi: 0
22:46:31:584 asdu: 3600020001151001ffff2e2100d13d7a020188170091b035010074
22:46:31:584 APS-DATA.indication request id: 17 -> finished
22:46:31:584 APS-DATA.request id: 17 erase from queue
22:46:31:584 ZDP status = 0x00 -> SUCCESS
22:46:31:584 MGTM_Lqi_req zdpSeq: 55 to 0x00212EFFFF011015 start index 1
22:46:31:584 APS-DATA.request id: 21, addrmode: 0x02, addr: 0x0000, profile: 0x0000, cluster: 0x0031, ep: 0x00 queue: 0 len: 2
22:46:31:584 ZDP Mgmt_Lqi_rsp zdpSeq: 54 from 0x00212EFFFF011015 total: 2, startIndex: 0, listCount: 1
22:46:31:584 * neighbor: 0x00178801027A3DD1 (0xB091), LQI: 116, relation: 0x01 rxOnWHenIdle: 1
22:46:31:632 APS-DATA.confirm id: 21, status: 0x00 SUCCESS
22:46:31:632 APS-DATA.confirm request id: 21 -> confirmed, timeout 60000
22:46:31:664 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x0031, lqi: 238, rssi: 0
22:46:31:664 asdu: 3701
22:46:31:664 ZDP status = 0x00 -> SUCCESS
22:46:31:696 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x8031, lqi: 238, rssi: 0
22:46:31:696 asdu: 3700020101151001ffff2e2100442e4c100188170074af35010075
22:46:31:696 APS-DATA.indication request id: 21 -> finished
22:46:31:696 APS-DATA.request id: 21 erase from queue
22:46:31:696 ZDP status = 0x00 -> SUCCESS
22:46:31:696 void deCONZ::zmNode::setFetched(deCONZ::RequestId, bool) fetched item: 8, node: 0x0000
22:46:31:696 ZDP Mgmt_Lqi_rsp zdpSeq: 55 from 0x00212EFFFF011015 total: 2, startIndex: 1, listCount: 1
22:46:31:696 * neighbor: 0x00178801104C2E44 (0xAF74), LQI: 117, relation: 0x01 rxOnWHenIdle: 1
22:46:31:965 device discover rotate, node 0x00178801027a3dd1 is in wait state
22:46:32:446 device discover rotate, node 0x00178801104c2e44 is in wait state
22:46:32:926 MGTM_Lqi_req zdpSeq: 56 to 0x00212EFFFF011015 start index 0
22:46:32:926 APS-DATA.request id: 29, addrmode: 0x02, addr: 0x0000, profile: 0x0000, cluster: 0x0031, ep: 0x00 queue: 0 len: 2
22:46:32:962 APS-DATA.confirm id: 29, status: 0x00 SUCCESS
22:46:32:962 APS-DATA.confirm request id: 29 -> confirmed, timeout 59920
22:46:32:994 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x0031, lqi: 238, rssi: 0
22:46:32:994 asdu: 3800
22:46:32:994 ZDP status = 0x00 -> SUCCESS
22:46:33:026 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x8031, lqi: 238, rssi: 0
22:46:33:026 asdu: 3800020001151001ffff2e2100d13d7a020188170091b035010074
22:46:33:026 APS-DATA.indication request id: 29 -> finished
22:46:33:026 APS-DATA.request id: 29 erase from queue
22:46:33:026 ZDP status = 0x00 -> SUCCESS
22:46:33:026 MGTM_Lqi_req zdpSeq: 57 to 0x00212EFFFF011015 start index 1
22:46:33:026 APS-DATA.request id: 33, addrmode: 0x02, addr: 0x0000, profile: 0x0000, cluster: 0x0031, ep: 0x00 queue: 0 len: 2
22:46:33:026 ZDP Mgmt_Lqi_rsp zdpSeq: 56 from 0x00212EFFFF011015 total: 2, startIndex: 0, listCount: 1
22:46:33:026 * neighbor: 0x00178801027A3DD1 (0xB091), LQI: 116, relation: 0x01 rxOnWHenIdle: 1
22:46:33:074 APS-DATA.confirm id: 33, status: 0x00 SUCCESS
22:46:33:074 APS-DATA.confirm request id: 33 -> confirmed, timeout 60000
22:46:33:106 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x0031, lqi: 238, rssi: 0
22:46:33:106 asdu: 3901
22:46:33:106 ZDP status = 0x00 -> SUCCESS
22:46:33:138 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x8031, lqi: 238, rssi: 0
22:46:33:138 asdu: 3900020101151001ffff2e2100442e4c100188170074af35010075
22:46:33:138 APS-DATA.indication request id: 33 -> finished
22:46:33:138 APS-DATA.request id: 33 erase from queue
22:46:33:138 ZDP status = 0x00 -> SUCCESS
22:46:33:138 void deCONZ::zmNode::setFetched(deCONZ::RequestId, bool) fetched item: 8, node: 0x0000
22:46:33:138 ZDP Mgmt_Lqi_rsp zdpSeq: 57 from 0x00212EFFFF011015 total: 2, startIndex: 1, listCount: 1
22:46:33:138 * neighbor: 0x00178801104C2E44 (0xAF74), LQI: 117, relation: 0x01 rxOnWHenIdle: 1
22:46:33:406 device discover rotate, node 0x00178801027a3dd1 is in wait state
22:46:33:885 device discover rotate, node 0x00178801104c2e44 is in wait state
22:46:34:365 MGTM_Lqi_req zdpSeq: 58 to 0x00212EFFFF011015 start index 0
22:46:34:365 APS-DATA.request id: 41, addrmode: 0x02, addr: 0x0000, profile: 0x0000, cluster: 0x0031, ep: 0x00 queue: 0 len: 2
22:46:34:404 APS-DATA.confirm id: 41, status: 0x00 SUCCESS
22:46:34:404 APS-DATA.confirm request id: 41 -> confirmed, timeout 59920
22:46:34:436 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x0031, lqi: 238, rssi: 0
22:46:34:436 asdu: 3a00
22:46:34:436 ZDP status = 0x00 -> SUCCESS
22:46:34:468 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x8031, lqi: 238, rssi: 0
22:46:34:468 asdu: 3a00020001151001ffff2e2100d13d7a020188170091b035010074
22:46:34:468 APS-DATA.indication request id: 41 -> finished
22:46:34:468 APS-DATA.request id: 41 erase from queue
22:46:34:468 ZDP status = 0x00 -> SUCCESS
22:46:34:468 MGTM_Lqi_req zdpSeq: 59 to 0x00212EFFFF011015 start index 1
22:46:34:468 APS-DATA.request id: 44, addrmode: 0x02, addr: 0x0000, profile: 0x0000, cluster: 0x0031, ep: 0x00 queue: 0 len: 2
22:46:34:468 ZDP Mgmt_Lqi_rsp zdpSeq: 58 from 0x00212EFFFF011015 total: 2, startIndex: 0, listCount: 1
22:46:34:468 * neighbor: 0x00178801027A3DD1 (0xB091), LQI: 116, relation: 0x01 rxOnWHenIdle: 1
22:46:34:516 APS-DATA.confirm id: 44, status: 0x00 SUCCESS
22:46:34:516 APS-DATA.confirm request id: 44 -> confirmed, timeout 60000
22:46:34:548 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x0031, lqi: 238, rssi: 0
22:46:34:548 asdu: 3b01
22:46:34:548 ZDP status = 0x00 -> SUCCESS
22:46:34:580 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x8031, lqi: 238, rssi: 0
22:46:34:580 asdu: 3b00020101151001ffff2e2100442e4c100188170074af35010075
22:46:34:580 APS-DATA.indication request id: 44 -> finished
22:46:34:580 APS-DATA.request id: 44 erase from queue
22:46:34:580 ZDP status = 0x00 -> SUCCESS
22:46:34:580 void deCONZ::zmNode::setFetched(deCONZ::RequestId, bool) fetched item: 8, node: 0x0000
22:46:34:580 ZDP Mgmt_Lqi_rsp zdpSeq: 59 from 0x00212EFFFF011015 total: 2, startIndex: 1, listCount: 1
22:46:34:580 * neighbor: 0x00178801104C2E44 (0xAF74), LQI: 117, relation: 0x01 rxOnWHenIdle: 1
22:46:34:845 device discover rotate, node 0x00178801027a3dd1 is in wait state
22:46:35:325 device discover rotate, node 0x00178801104c2e44 is in wait state
22:46:35:328 scan finished
22:46:35:805 MGTM_Lqi_req zdpSeq: 60 to 0x00212EFFFF011015 start index 0
22:46:35:805 APS-DATA.request id: 53, addrmode: 0x02, addr: 0x0000, profile: 0x0000, cluster: 0x0031, ep: 0x00 queue: 0 len: 2
22:46:35:846 APS-DATA.confirm id: 53, status: 0x00 SUCCESS
22:46:35:846 APS-DATA.confirm request id: 53 -> confirmed, timeout 59920
22:46:35:877 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x0031, lqi: 238, rssi: 0
22:46:35:877 asdu: 3c00
22:46:35:878 ZDP status = 0x00 -> SUCCESS
22:46:35:910 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x8031, lqi: 238, rssi: 0
22:46:35:910 asdu: 3c00020001151001ffff2e2100d13d7a020188170091b035010074
22:46:35:910 APS-DATA.indication request id: 53 -> finished
22:46:35:910 APS-DATA.request id: 53 erase from queue
22:46:35:910 ZDP status = 0x00 -> SUCCESS
22:46:35:910 MGTM_Lqi_req zdpSeq: 61 to 0x00212EFFFF011015 start index 1
22:46:35:910 APS-DATA.request id: 56, addrmode: 0x02, addr: 0x0000, profile: 0x0000, cluster: 0x0031, ep: 0x00 queue: 0 len: 2
22:46:35:910 ZDP Mgmt_Lqi_rsp zdpSeq: 60 from 0x00212EFFFF011015 total: 2, startIndex: 0, listCount: 1
22:46:35:910 * neighbor: 0x00178801027A3DD1 (0xB091), LQI: 116, relation: 0x01 rxOnWHenIdle: 1
22:46:35:958 APS-DATA.confirm id: 56, status: 0x00 SUCCESS
22:46:35:958 APS-DATA.confirm request id: 56 -> confirmed, timeout 60000
22:46:35:990 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x0031, lqi: 238, rssi: 0
22:46:35:990 asdu: 3d01
22:46:35:990 ZDP status = 0x00 -> SUCCESS
22:46:36:022 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x8031, lqi: 238, rssi: 0
22:46:36:022 asdu: 3d00020101151001ffff2e2100442e4c100188170074af35010075
22:46:36:022 APS-DATA.indication request id: 56 -> finished
22:46:36:022 APS-DATA.request id: 56 erase from queue
22:46:36:022 ZDP status = 0x00 -> SUCCESS
22:46:36:022 void deCONZ::zmNode::setFetched(deCONZ::RequestId, bool) fetched item: 8, node: 0x0000
22:46:36:022 ZDP Mgmt_Lqi_rsp zdpSeq: 61 from 0x00212EFFFF011015 total: 2, startIndex: 1, listCount: 1
22:46:36:022 * neighbor: 0x00178801104C2E44 (0xAF74), LQI: 117, relation: 0x01 rxOnWHenIdle: 1
22:46:36:286 device discover rotate, node 0x00178801027a3dd1 is in wait state
22:46:36:765 device discover rotate, node 0x00178801104c2e44 is in wait state
22:46:37:245 MGTM_Lqi_req zdpSeq: 62 to 0x00212EFFFF011015 start index 0
22:46:37:245 APS-DATA.request id: 64, addrmode: 0x02, addr: 0x0000, profile: 0x0000, cluster: 0x0031, ep: 0x00 queue: 0 len: 2
22:46:37:287 APS-DATA.confirm id: 64, status: 0x00 SUCCESS
22:46:37:287 APS-DATA.confirm request id: 64 -> confirmed, timeout 59920
22:46:37:319 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x0031, lqi: 238, rssi: 0
22:46:37:319 asdu: 3e00
22:46:37:319 ZDP status = 0x00 -> SUCCESS
22:46:37:351 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x8031, lqi: 238, rssi: 0
22:46:37:351 asdu: 3e00020001151001ffff2e2100d13d7a020188170091b035010074
22:46:37:351 APS-DATA.indication request id: 64 -> finished
22:46:37:351 APS-DATA.request id: 64 erase from queue
22:46:37:351 ZDP status = 0x00 -> SUCCESS
22:46:37:351 MGTM_Lqi_req zdpSeq: 63 to 0x00212EFFFF011015 start index 1
22:46:37:352 APS-DATA.request id: 68, addrmode: 0x02, addr: 0x0000, profile: 0x0000, cluster: 0x0031, ep: 0x00 queue: 0 len: 2
22:46:37:352 ZDP Mgmt_Lqi_rsp zdpSeq: 62 from 0x00212EFFFF011015 total: 2, startIndex: 0, listCount: 1
22:46:37:352 * neighbor: 0x00178801027A3DD1 (0xB091), LQI: 116, relation: 0x01 rxOnWHenIdle: 1
22:46:37:399 APS-DATA.confirm id: 68, status: 0x00 SUCCESS
22:46:37:399 APS-DATA.confirm request id: 68 -> confirmed, timeout 60000
22:46:37:431 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x0031, lqi: 238, rssi: 0
22:46:37:431 asdu: 3f01
22:46:37:431 ZDP status = 0x00 -> SUCCESS
22:46:37:464 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x8031, lqi: 238, rssi: 0
22:46:37:464 asdu: 3f00020101151001ffff2e2100442e4c100188170074af35010075
22:46:37:464 APS-DATA.indication request id: 68 -> finished
22:46:37:464 APS-DATA.request id: 68 erase from queue
22:46:37:464 ZDP status = 0x00 -> SUCCESS
22:46:37:464 void deCONZ::zmNode::setFetched(deCONZ::RequestId, bool) fetched item: 8, node: 0x0000
22:46:37:464 ZDP Mgmt_Lqi_rsp zdpSeq: 63 from 0x00212EFFFF011015 total: 2, startIndex: 1, listCount: 1
22:46:37:464 * neighbor: 0x00178801104C2E44 (0xAF74), LQI: 117, relation: 0x01 rxOnWHenIdle: 1
22:46:37:725 device discover rotate, node 0x00178801027a3dd1 is in wait state
22:46:38:205 device discover rotate, node 0x00178801104c2e44 is in wait state
22:46:38:686 MGTM_Lqi_req zdpSeq: 65 to 0x00212EFFFF011015 start index 0
22:46:38:686 APS-DATA.request id: 77, addrmode: 0x02, addr: 0x0000, profile: 0x0000, cluster: 0x0031, ep: 0x00 queue: 0 len: 2
22:46:38:745 APS-DATA.confirm id: 77, status: 0x00 SUCCESS
22:46:38:745 APS-DATA.confirm request id: 77 -> confirmed, timeout 59920
22:46:38:777 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x0031, lqi: 238, rssi: 0
22:46:38:777 asdu: 4100
22:46:38:777 ZDP status = 0x00 -> SUCCESS
22:46:38:809 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x8031, lqi: 238, rssi: 0
22:46:38:809 asdu: 4100020001151001ffff2e2100d13d7a020188170091b035010074
22:46:38:809 APS-DATA.indication request id: 77 -> finished
22:46:38:809 APS-DATA.request id: 77 erase from queue
22:46:38:809 ZDP status = 0x00 -> SUCCESS
22:46:38:809 MGTM_Lqi_req zdpSeq: 66 to 0x00212EFFFF011015 start index 1
22:46:38:809 APS-DATA.request id: 81, addrmode: 0x02, addr: 0x0000, profile: 0x0000, cluster: 0x0031, ep: 0x00 queue: 0 len: 2
22:46:38:809 ZDP Mgmt_Lqi_rsp zdpSeq: 65 from 0x00212EFFFF011015 total: 2, startIndex: 0, listCount: 1
22:46:38:809 * neighbor: 0x00178801027A3DD1 (0xB091), LQI: 116, relation: 0x01 rxOnWHenIdle: 1
22:46:38:845 ZDP skip fetch, node 0x212EFFFF011015 has unconfirmed requests [1]
22:46:38:857 APS-DATA.confirm id: 81, status: 0x00 SUCCESS
22:46:38:857 APS-DATA.confirm request id: 81 -> confirmed, timeout 59920
22:46:38:889 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x0031, lqi: 238, rssi: 0
22:46:38:889 asdu: 4201
22:46:38:889 ZDP status = 0x00 -> SUCCESS
22:46:38:921 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x8031, lqi: 238, rssi: 0
22:46:38:921 asdu: 4200020101151001ffff2e2100442e4c100188170074af35010075
22:46:38:921 APS-DATA.indication request id: 81 -> finished
22:46:38:921 APS-DATA.request id: 81 erase from queue
22:46:38:921 ZDP status = 0x00 -> SUCCESS
22:46:38:921 void deCONZ::zmNode::setFetched(deCONZ::RequestId, bool) fetched item: 8, node: 0x0000
22:46:38:921 ZDP Mgmt_Lqi_rsp zdpSeq: 66 from 0x00212EFFFF011015 total: 2, startIndex: 1, listCount: 1
22:46:38:921 * neighbor: 0x00178801104C2E44 (0xAF74), LQI: 117, relation: 0x01 rxOnWHenIdle: 1
22:46:39:165 device discover rotate, node 0x00178801027a3dd1 is in wait state
22:46:39:645 device discover rotate, node 0x00178801104c2e44 is in wait state
22:46:40:125 MGTM_Lqi_req zdpSeq: 67 to 0x00212EFFFF011015 start index 0
22:46:40:125 APS-DATA.request id: 89, addrmode: 0x02, addr: 0x0000, profile: 0x0000, cluster: 0x0031, ep: 0x00 queue: 0 len: 2
22:46:40:171 APS-DATA.confirm id: 89, status: 0x00 SUCCESS
22:46:40:171 APS-DATA.confirm request id: 89 -> confirmed, timeout 59920
22:46:40:203 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x0031, lqi: 238, rssi: 0
22:46:40:203 asdu: 4300
22:46:40:203 ZDP status = 0x00 -> SUCCESS
22:46:40:235 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x8031, lqi: 238, rssi: 0
22:46:40:235 asdu: 4300020001151001ffff2e2100d13d7a020188170091b035010074
22:46:40:235 APS-DATA.indication request id: 89 -> finished
22:46:40:235 APS-DATA.request id: 89 erase from queue
22:46:40:235 ZDP status = 0x00 -> SUCCESS
22:46:40:235 MGTM_Lqi_req zdpSeq: 68 to 0x00212EFFFF011015 start index 1
22:46:40:235 APS-DATA.request id: 92, addrmode: 0x02, addr: 0x0000, profile: 0x0000, cluster: 0x0031, ep: 0x00 queue: 0 len: 2
22:46:40:235 ZDP Mgmt_Lqi_rsp zdpSeq: 67 from 0x00212EFFFF011015 total: 2, startIndex: 0, listCount: 1
22:46:40:235 * neighbor: 0x00178801027A3DD1 (0xB091), LQI: 116, relation: 0x01 rxOnWHenIdle: 1
22:46:40:283 APS-DATA.confirm id: 92, status: 0x00 SUCCESS
22:46:40:283 APS-DATA.confirm request id: 92 -> confirmed, timeout 60000
22:46:40:315 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x0031, lqi: 238, rssi: 0
22:46:40:315 asdu: 4401
22:46:40:315 ZDP status = 0x00 -> SUCCESS
22:46:40:347 APS-DATA.indication srcAddr: 0x00212effff011015, dstAddrMode: 2, profile: 0x0000, cluster: 0x8031, lqi: 238, rssi: 0
22:46:40:347 asdu: 4400020101151001ffff2e2100442e4c100188170074af35010075
22:46:40:347 APS-DATA.indication request id: 92 -> finished
22:46:40:347 APS-DATA.request id: 92 erase from queue
22:46:40:347 ZDP status = 0x00 -> SUCCESS
22:46:40:347 void deCONZ::zmNode::setFetched(deCONZ::RequestId, bool) fetched item: 8, node: 0x0000
22:46:40:347 ZDP Mgmt_Lqi_rsp zdpSeq: 68 from 0x00212EFFFF011015 total: 2, startIndex: 1, listCount: 1
22:46:40:347 * neighbor: 0x00178801104C2E44 (0xAF74), LQI: 117, relation: 0x01 rxOnWHenIdle: 1
22:46:40:605 de

[manup]

I also see these 0x0000000000000000 error APSDE-DATA.confirm: 0xE1 on task, the 00000000 address to me sounds like a bigger issue?

That's fine the print statement should be updated to support nwk and mac addresses.

There are thin and with lots of holes metal shelving in the same room but there are lights above and below so mesh shouldn't be affected right?

The important part is that rf waves needs to travel, concrete and metal are very challenging if they are in between but if it worked with Raspberry before this doesn't seem the problem here.

I double checked and my 2.4ghz is on channel 1, so I moved to channel 25 for deconz using phoscon. I just shut of the ordinary service for port 80 to get this going. And all devices disappeared, but just now during the evening movie they seemed to pop up alive again. What is the difference from doing it in phoscon compared to deconz?

Still seeing the unhandled APS-DATA.confirm id: 46 status 0xE1.

WiFi 1 and ZigBee on 25 is a good choice, no overlapping here.

Do you have the chance to use a USB extension cable for the ConBee or chose a USB port on a other side of the PC? We have seen issues with few PCs when the USB dongle was connected directly, a little bit distance helped a lot.

0xE1 error means the radio module tried up to 7 times to send the packet on lowest MAC level but the channel was too busy. Hard to tell where it comes from — WiFi, interference from PC cassis, other 2.4 GHz devices...

You may also use a WiFi scanner app to see whats going on in the neighborhood but I would recommend to try the USB cable first.

[Kane610]

The placement is new so the raspberry wasn't in the same storage room as the new machine is now. The Wifi AP is lying on top of one of those shelves and there is no impact in wifi performance since I moved it at the same time as I moved the conbee to the new machine.

Great on network configuration, one less thing to take in to consideration.

Im gonna get an extension cable today to try to move the antenna around.

Im gonna have a look in unifi controller to see how other houses in the neighbourhood are configured, I know that when I set up my wifi, no-one else where using channel 1.

Ill get back on how the extension cable affected the situation tonight

[Kane610]

As soon as I plugged in the extension cord it started to work better. Im gonna give it 24 hours before accepting it was that simple. ;)

Thanks for your support @manup I hope you got some inspiration to improved debugging. Maybe the 0xE1 error message and similar could get some readable text to help improve the possibility to debug this issue for other users in the future.

[Kane610]

I'm satisfied to say that it still works as it should. I will now continue with my migration from Hue Bridge

Thanks for your support @manup