Some additional logging of these “microstutters” lasting 6-7s. During that time there is no L2 logging at all, and it coinciding exactly with the deconz ui temporarily hanging and high general memory usage of the container. Also no updates are coming through in the api. Deconz momentarily just freezes completely. Again: without the plugs & DDF I never noticed this behavior!
Anyone got a clue what could cause this? This can’t be caused by devices themselves, can it? It really feels like a deconz bug!
Just check these 2 log sections (6s gap indicated by *******************):
19:01:47:600 Poll APS request to 0xBC33ACFFFE2BF652 cluster: 0x0006 dropped, values are fresh enough
19:01:48:600 poll node 00:15:8d:00:05:20:f4:43-01
19:01:48:601 Poll light node Lamp JH
19:01:48:601 Idle timer triggered
19:01:48:602 Force read attributes for ZHATemperature SensorNode Diepvries T
19:01:48:602 don't create binding for attribute reporting of sensor Diepvries T
19:01:48:603 Force binding of attribute reporting for node Diepvries T
19:01:48:651 read attributes of 0x00158D000520F443 cluster: 0x0006: [
19:01:48:651 0x0000
19:01:48:652 ]
19:01:48:652 add task 40388 type 19 to 0x00158D000520F443 cluster 0x0006 req.id 23
19:01:48:652 Poll APS request 23 to 0x00158D000520F443 cluster: 0x0006
19:01:48:700 APS-DATA.request id: 23, addrmode: 0x03, addr: 0x00158d000520f443, profile: 0x0104, cluster: 0x0006, ep: 0x01 -> 0x01 queue: 0 len: 5 tx.options 0x00
19:01:48:700 asdu (length: 5): 10bf000000
19:01:48:714 Poll APS confirm 23 status: 0x00
19:01:48:715 Erase task req-id: 23, type: 19 zcl seqno: 191 send time 0, profileId: 0x0104, clusterId: 0x0006
19:01:48:715 APS-DATA.confirm id: 23, status: 0x00 SUCCESS
19:01:48:715 APS-DATA.confirm request id: 23 -> erase from queue
19:01:48:748 aps request id: 23 finished, erase from queue
19:01:48:766 APS-DATA.indication srcAddr: 0x27b3, srcEp: 0x01 dstAddrMode: 2, profile: 0x0104, cluster: 0x0006, lqi: 255, rssi: -71
19:01:48:766 asdu: 18bf010000001001
19:01:48:767 Node data 0x00158d000520f443 profileId: 0x0104, clusterId: 0x0006
19:01:48:767 0x00158D000520F443: update ZCL value 0x01/0x0006/0x0000 after 0 s
19:01:48:769 Websocket 172.17.0.1:59858 send message: {"attr":{"colorcapabilities":16,"ctmax":65279,"ctmin":null,"id":"28","lastannounced":"2022-02-01T06:11:04Z","lastseen":"2022-02-19T19:01Z","manufacturername":"LUMI","modelid":"lumi.light.aqcn02","name":"Lamp JH","swversion":"11-22-2018","type":"Color temperature light","uniqueid":"00:15:8d:00:05:20:f4:43-01"},"e":"changed","id":"28","r":"lights","t":"event","uniqueid":"00:15:8d:00:05:20:f4:43-01"} (ret = 400)
19:01:48:847 APS-DATA.indication srcAddr: 0xf25a, srcEp: 0x01 dstAddrMode: 2, profile: 0x0104, cluster: 0x0B04, lqi: 255, rssi: -83
19:01:48:848 asdu: 18500a080521f000
*******************
19:01:54:779 ZCL attribute report 0xA4C138D6A824F918 for cluster: 0x0B04, ep: 0x01, frame control: 0x18, mfcode: 0x0000
19:01:54:780 payload: 080521f000
19:01:54:783 Websocket 172.17.0.1:59858 send message: {"e":"changed","id":"284","r":"sensors","state":{"current":240,"lastupdated":"2022-02-19T19:01:48.850","power":39,"voltage":224},"t":"event","uniqueid":"a4:c1:38:d6:a8:24:f9:18-01-0b04"} (ret = 186)
19:01:54:784 read attributes of 0x00158D000520F443 cluster: 0x0008: [
19:01:54:785 0x0000
19:01:54:785 ]
19:01:54:785 add task 40390 type 19 to 0x00158D000520F443 cluster 0x0008 req.id 27
19:01:54:786 Poll APS request 27 to 0x00158D000520F443 cluster: 0x0008
19:01:54:787 Daylight now: nightStart, status: 230, daylight: 0, dark: 1
19:01:54:796 APS-DATA.indication srcAddr: 0xf25a, srcEp: 0x01 dstAddrMode: 2, profile: 0x0104, cluster: 0x0B04, lqi: 236, rssi: -85
19:01:54:797 asdu: 18510a0b05292500
19:01:55:166 ZCL attribute report 0xA4C138D6A824F918 for cluster: 0x0B04, ep: 0x01, frame control: 0x18, mfcode: 0x0000
19:01:55:166 payload: 0b05292500
19:01:55:168 Websocket 172.17.0.1:59858 send message: {"e":"changed","id":"284","r":"sensors","state":{"current":240,"lastupdated":"2022-02-19T19:01:54.799","power":37,"voltage":224},"t":"event","uniqueid":"a4:c1:38:d6:a8:24:f9:18-01-0b04"} (ret = 186)
19:01:55:170 APS-DATA.request id: 27, addrmode: 0x03, addr: 0x00158d000520f443, profile: 0x0104, cluster: 0x0008, ep: 0x01 -> 0x01 queue: 0 len: 5 tx.options 0x00
19:01:55:170 asdu (length: 5): 10c0000000
19:01:55:175 APS-DATA.indication srcAddr: 0xf25a, srcEp: 0x01 dstAddrMode: 2, profile: 0x0104, cluster: 0x0B04, lqi: 244, rssi: -85
19:01:55:175 asdu: 18520a0805210b01
19:01:56:037 ZCL attribute report 0xA4C138D6A824F918 for cluster: 0x0B04, ep: 0x01, frame control: 0x18, mfcode: 0x0000
19:01:56:037 payload: 0805210b01
19:01:56:038 Websocket 172.17.0.1:59858 send message: {"e":"changed","id":"284","r":"sensors","state":{"current":267,"lastupdated":"2022-02-19T19:01:55.177","power":37,"voltage":224},"t":"event","uniqueid":"a4:c1:38:d6:a8:24:f9:18-01-0b04"} (ret = 186)
19:01:56:041 Idle timer triggered
19:01:56:042 binding for attribute reporting SensorNode JH of cluster 0x0406 seems to be active
19:01:56:042 Force read attributes for ZHAPresence SensorNode JH
and:
19:02:00:667 add task 40408 type 19 to 0x00158D000520ABA2 cluster 0x0006 req.id 56
19:02:00:667 Poll APS request 56 to 0x00158D000520ABA2 cluster: 0x0006
19:02:00:709 APS-DATA.request id: 56, addrmode: 0x03, addr: 0x00158d000520aba2, profile: 0x0104, cluster: 0x0006, ep: 0x01 -> 0x01 queue: 1 len: 5 tx.options 0x00
19:02:00:710 asdu (length: 5): 10c3000000
19:02:00:723 Poll APS confirm 56 status: 0x00
19:02:00:724 Erase task req-id: 56, type: 19 zcl seqno: 195 send time 0, profileId: 0x0104, clusterId: 0x0006
19:02:00:724 APS-DATA.confirm id: 56, status: 0x00 SUCCESS
19:02:00:725 APS-DATA.confirm request id: 56 -> erase from queue
19:02:00:733 APS-DATA.indication srcAddr: 0x5c5d, srcEp: 0x01 dstAddrMode: 2, profile: 0x0104, cluster: 0x0006, lqi: 255, rssi: -43
19:02:00:734 asdu: 18c3010000001000
19:02:00:734 APS-DATA.request id: 56 erase from queue
19:02:00:734 Node data 0x00158d000520aba2 profileId: 0x0104, clusterId: 0x0006
19:02:00:735 0x00158D000520ABA2: update ZCL value 0x01/0x0006/0x0000 after 0 s
19:02:00:737 Websocket 172.17.0.1:59858 send message: {"attr":{"colorcapabilities":16,"ctmax":65279,"ctmin":null,"id":"36","lastannounced":"2021-07-14T10:40:29Z","lastseen":"2022-02-19T19:02Z","manufacturername":"LUMI","modelid":"lumi.light.aqcn02","name":"Lamp Hal Beneden","swversion":"1.23","type":"Color temperature light","uniqueid":"00:15:8d:00:05:20:ab:a2-01"},"e":"changed","id":"36","r":"lights","t":"event","uniqueid":"00:15:8d:00:05:20:ab:a2-01"} (ret = 403)
19:02:01:420 APS-DATA.indication srcAddr: 0xdd82, srcEp: 0x01 dstAddrMode: 2, profile: 0x0104, cluster: 0x000A, lqi: 255, rssi: -64
19:02:01:421 asdu: 102e000000
19:02:01:423 APS-DATA.request id: 62, addrmode: 0x02, addr: 0xdd82, profile: 0x0104, cluster: 0x000A, ep: 0x01 -> 0x01 queue: 1 len: 11 tx.options 0x00
19:02:01:423 asdu (length: 11): 182e01000000e229fba329
19:02:01:436 APS-DATA.confirm id: 62, status: 0x00 SUCCESS
19:02:01:437 APS-DATA.confirm request id: 62 -> erase from queue
19:02:01:500 aps request id: 62 finished, erase from queue
19:02:01:600 Daylight now: nightStart, status: 230, daylight: 0, dark: 1
19:02:01:675 poll node 00:15:8d:00:05:20:e7:c9-01
19:02:01:676 Poll light node Lamp Dasha
19:02:01:728 read attributes of 0x00158D000520E7C9 cluster: 0x0006: [
19:02:01:729 0x0000
19:02:01:729 ]
19:02:01:730 add task 40413 type 19 to 0x00158D000520E7C9 cluster 0x0006 req.id 64
19:02:01:730 Poll APS request 64 to 0x00158D000520E7C9 cluster: 0x0006
19:02:01:800 APS-DATA.request id: 64, addrmode: 0x03, addr: 0x00158d000520e7c9, profile: 0x0104, cluster: 0x0006, ep: 0x01 -> 0x01 queue: 1 len: 5 tx.options 0x00
19:02:01:800 asdu (length: 5): 10c4000000
19:02:01:815 Poll APS confirm 64 status: 0x00
19:02:01:816 Erase task req-id: 64, type: 19 zcl seqno: 196 send time 0, profileId: 0x0104, clusterId: 0x0006
19:02:01:816 APS-DATA.confirm id: 64, status: 0x00 SUCCESS
19:02:01:817 APS-DATA.confirm request id: 64 -> erase from queue
19:02:01:820 aps request id: 64 finished, erase from queue
19:02:01:859 APS-DATA.indication srcAddr: 0xf25a, srcEp: 0x01 dstAddrMode: 2, profile: 0x0104, cluster: 0x0B04, lqi: 255, rssi: -81
19:02:01:860 asdu: 18580a080521fe00
*******************
19:02:08:059 ZCL attribute report 0xA4C138D6A824F918 for cluster: 0x0B04, ep: 0x01, frame control: 0x18, mfcode: 0x0000
19:02:08:060 payload: 080521fe00
19:02:08:063 Websocket 172.17.0.1:59858 send message: {"e":"changed","id":"284","r":"sensors","state":{"current":254,"lastupdated":"2022-02-19T19:02:01.862","power":40,"voltage":224},"t":"event","uniqueid":"a4:c1:38:d6:a8:24:f9:18-01-0b04"} (ret = 186)
19:02:08:068 Idle timer triggered
19:02:08:071 Force read attributes for ZHAPower SensorNode Power 289
19:02:08:072 Force binding of attribute reporting for node Power 289
19:02:08:103 GW firmware version: 0x26720700
19:02:08:103 GW firmware version is up to date: 0x26720700
19:02:08:114 APS-DATA.indication srcAddr: 0x7c3a, srcEp: 0x01 dstAddrMode: 2, profile: 0x0104, cluster: 0x0006, lqi: 255, rssi: -83
19:02:08:115 asdu: 18c4010000001001
19:02:08:115 Node data 0x00158d000520e7c9 profileId: 0x0104, clusterId: 0x0006
19:02:08:121 0x00158D000520E7C9: update ZCL value 0x01/0x0006/0x0000 after 0 s
19:02:08:127 Websocket 172.17.0.1:59858 send message: {"attr":{"id":"285","lastannounced":null,"lastseen":"2022-02-19T19:02Z","manufacturername":"LUMI","modelid":"lumi.sen_ill.mgl01","name":"LightLevel 285","swversion":"1.23","type":"ZHALightLevel","uniqueid":"00:15:8d:00:05:20:e7:c9-01-0400"},"e":"changed","id":"285","r":"sensors","t":"event","uniqueid":"00:15:8d:00:05:20:e7:c9-01-0400"} (ret = 337)
19:02:08:129 Websocket 172.17.0.1:59858 send message: {"attr":{"id":"22","lastannounced":"2022-02-18T17:45:22Z","lastseen":"2022-02-19T19:02Z","manufacturername":"LUMI","modelid":"lumi.sen_ill.mgl01","name":"Lamp Dasha","swversion":"1.23","type":"Color dimmable light","uniqueid":"00:15:8d:00:05:20:e7:c9-01"},"e":"changed","id":"22","r":"lights","t":"event","uniqueid":"00:15:8d:00:05:20:e7:c9-01"} (ret = 345)
19:02:08:131 APS-DATA.indication srcAddr: 0xf25a, srcEp: 0x01 dstAddrMode: 2, profile: 0x0104, cluster: 0x0B04, lqi: 255, rssi: -82
19:02:08:132 asdu: 18590a0b05292500
19:02:08:701 ZCL attribute report 0xA4C138D6A824F918 for cluster: 0x0B04, ep: 0x01, frame control: 0x18, mfcode: 0x0000
19:02:08:702 payload: 0b05292500
19:02:08:703 Websocket 172.17.0.1:59858 send message: {"e":"changed","id":"284","r":"sensors","state":{"current":254,"lastupdated":"2022-02-19T19:02:08.134","power":37,"voltage":224},"t":"event","uniqueid":"a4:c1:38:d6:a8:24:f9:18-01-0b04"} (ret = 186)
19:02:08:705 read attributes of 0x00158D000520E7C9 cluster: 0x0008: [
19:02:08:706 0x0000
19:02:08:706 ]
19:02:08:707 add task 40416 type 19 to 0x00158D000520E7C9 cluster 0x0008 req.id 70
19:02:08:707 Poll APS request 70 to 0x00158D000520E7C9 cluster: 0x0008
19:02:08:707 DB save zll database items 0x00000081