logs démon plugin zigbee (1/2) :
0000|ON CONFLICT (ieee, endpoint_id, cluster, attrid)
0001|DO UPDATE SET
0002|value=excluded.value WHERE value != excluded.value', (00:15:8d:00:05:d2:a8:e0, 1, 1794, 256, 12448624))
0003|[2022-09-02 09:41:02]DEBUG : operation functools.partial(, 'INSERT INTO attributes_cache_v10 VALUES (?, ?, ?, ?, ?)
0004|ON CONFLICT (ieee, endpoint_id, cluster, attrid)
0005|DO UPDATE SET
0006|value=excluded.value WHERE value != excluded.value', (00:15:8d:00:05:d2:a8:e0, 1, 1794, 256, 12448624)) completed
0007|[2022-09-02 09:41:02]DEBUG : executing functools.partial()
0008|[2022-09-02 09:41:02]DEBUG : operation functools.partial() completed
0009|[2022-09-02 09:41:02]DEBUG : executing functools.partial(, 'INSERT INTO attributes_cache_v10 VALUES (?, ?, ?, ?, ?)
0010|ON CONFLICT (ieee, endpoint_id, cluster, attrid)
0011|DO UPDATE SET
0012|value=excluded.value WHERE value != excluded.value', (00:15:8d:00:05:d2:a8:e0, 1, 1794, 260, 0))
0013|[2022-09-02 09:41:02]DEBUG : operation functools.partial(, 'INSERT INTO attributes_cache_v10 VALUES (?, ?, ?, ?, ?)
0014|ON CONFLICT (ieee, endpoint_id, cluster, attrid)
0015|DO UPDATE SET
0016|value=excluded.value WHERE value != excluded.value', (00:15:8d:00:05:d2:a8:e0, 1, 1794, 260, 0)) completed
0017|[2022-09-02 09:41:02]DEBUG : executing functools.partial()
0018|[2022-09-02 09:41:02]DEBUG : operation functools.partial() completed
0019|[2022-09-02 09:41:02]DEBUG : executing functools.partial(, 'INSERT INTO attributes_cache_v10 VALUES (?, ?, ?, ?, ?)
0020|ON CONFLICT (ieee, endpoint_id, cluster, attrid)
0021|DO UPDATE SET
0022|value=excluded.value WHERE value != excluded.value', (00:15:8d:00:05:d2:a8:e0, 1, 1794, 258, 8328025))
0023|[2022-09-02 09:41:02]DEBUG : operation functools.partial(, 'INSERT INTO attributes_cache_v10 VALUES (?, ?, ?, ?, ?)
0024|ON CONFLICT (ieee, endpoint_id, cluster, attrid)
0025|DO UPDATE SET
0026|value=excluded.value WHERE value != excluded.value', (00:15:8d:00:05:d2:a8:e0, 1, 1794, 258, 8328025)) completed
0027|[2022-09-02 09:41:02]DEBUG : executing functools.partial()
0028|[2022-09-02 09:41:02]DEBUG : operation functools.partial() completed
0029|[2022-09-02 09:41:02]DEBUG : executing functools.partial(, 'INSERT INTO attributes_cache_v10 VALUES (?, ?, ?, ?, ?)
0030|ON CONFLICT (ieee, endpoint_id, cluster, attrid)
0031|DO UPDATE SET
0032|value=excluded.value WHERE value != excluded.value', (00:15:8d:00:05:d2:a8:e0, 1, 1794, 262, 0))
0033|[2022-09-02 09:41:02]DEBUG : operation functools.partial(, 'INSERT INTO attributes_cache_v10 VALUES (?, ?, ?, ?, ?)
0034|ON CONFLICT (ieee, endpoint_id, cluster, attrid)
0035|DO UPDATE SET
0036|value=excluded.value WHERE value != excluded.value', (00:15:8d:00:05:d2:a8:e0, 1, 1794, 262, 0)) completed
0037|[2022-09-02 09:41:02]DEBUG : executing functools.partial()
0038|[2022-09-02 09:41:02]DEBUG : operation functools.partial() completed
0039|[2022-09-02 09:41:02]DEBUG : executing functools.partial(, 'INSERT INTO attributes_cache_v10 VALUES (?, ?, ?, ?, ?)
0040|ON CONFLICT (ieee, endpoint_id, cluster, attrid)
0041|DO UPDATE SET
0042|value=excluded.value WHERE value != excluded.value', (00:15:8d:00:05:d2:a8:e0, 1, 1794, 264, 0))
0043|[2022-09-02 09:41:02]DEBUG : operation functools.partial(, 'INSERT INTO attributes_cache_v10 VALUES (?, ?, ?, ?, ?)
0044|ON CONFLICT (ieee, endpoint_id, cluster, attrid)
0045|DO UPDATE SET
0046|value=excluded.value WHERE value != excluded.value', (00:15:8d:00:05:d2:a8:e0, 1, 1794, 264, 0)) completed
0047|[2022-09-02 09:41:02]DEBUG : executing functools.partial()
0048|[2022-09-02 09:41:02]DEBUG : operation functools.partial() completed
0049|[2022-09-02 09:41:02]INFO : [DeviceHandler.prepare] Json arg : {'ieee': '00:15:8d:00:05:d2:a8:e0', 'endpoint': 1, 'cluster': 1794, 'cluster_type': 'in', 'attributes': [32], 'allowCache': 0}
0050|[2022-09-02 09:41:02]DEBUG : [0x592B:1:0x0702] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=False, direction=, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True, *is_reply=False), tsn=72, command_id=, *direction=, *is_reply=False)
0051|[2022-09-02 09:41:02]DEBUG : [0x592B:1:0x0702] Sending request: Read_Attributes(attribute_ids=[32])
0052|[2022-09-02 09:41:02]DEBUG : Sending Zigbee request with tsn 72 under 73 request id, data: b'0048002000'
0053|[2022-09-02 09:41:02]DEBUG : Command Command.aps_data_request (20, 73, , , 260, 1794, 1, b'\x00H\x00 \x00', , 0)
0054|[2022-09-02 09:41:02]DEBUG : Send: 0x12db001b0014004900022b59010401020701050000480020000200
0055|[2022-09-02 09:41:02]DEBUG : Frame received: 0x12db00090002002249
0056|[2022-09-02 09:41:02]DEBUG : APS data request response: [2, , 73]
0057|[2022-09-02 09:41:02]DEBUG : Frame received: 0x0edc000700a600
0058|[2022-09-02 09:41:02]DEBUG : Device state changed response: [, 0]
0059|[2022-09-02 09:41:02]DEBUG : Command Command.aps_data_confirm (0,)
0060|[2022-09-02 09:41:02]DEBUG : Send: 0x04dc0007000000
0061|[2022-09-02 09:41:02]DEBUG : Frame received: 0x04dc0013000c002249022b5901010000000000
0062|[2022-09-02 09:41:02]DEBUG : APS data confirm response for request with id 73: 00
0063|[2022-09-02 09:41:02]DEBUG : Request id: 0x49 'aps_data_confirm' for , status: 0x00
0064|[2022-09-02 09:41:02]DEBUG : executing functools.partial(, 'UPDATE devices_v10
0065|SET last_seen=:ts
0066|WHERE ieee=:ieee AND :ts - last_seen > :min_last_seen_delta', {'ts': 1662104462.062012, 'ieee': 00:15:8d:00:05:d2:a8:e0, 'min_last_seen_delta': 30.0})
0067|[2022-09-02 09:41:02]DEBUG : operation functools.partial(, 'UPDATE devices_v10
0068|SET last_seen=:ts
0069|WHERE ieee=:ieee AND :ts - last_seen > :min_last_seen_delta', {'ts': 1662104462.062012, 'ieee': 00:15:8d:00:05:d2:a8:e0, 'min_last_seen_delta': 30.0}) completed
0070|[2022-09-02 09:41:02]DEBUG : executing functools.partial()
0071|[2022-09-02 09:41:02]DEBUG : operation functools.partial() completed
0072|[2022-09-02 09:41:02]DEBUG : Frame received: 0x0edd000700aa00
0073|[2022-09-02 09:41:02]DEBUG : Device state changed response: [, 0]
0074|[2022-09-02 09:41:02]DEBUG : Command Command.aps_data_indication (1, 1)
0075|[2022-09-02 09:41:02]DEBUG : Send: 0x17dd000800010001
0076|[2022-09-02 09:41:02]DEBUG : Frame received: 0x17dd0026001f002202000001022b5901040102070800184801200000420000afff2c504c01b4
0077|[2022-09-02 09:41:02]DEBUG : APS data indication response: [31, , , 1, , 1, 260, 1794, b'\x18H\x01 \x00\x00B\x00', 0, 175, 255, 44, 80, 76, 1, -76]
0078|[2022-09-02 09:41:02]DEBUG : [0x592B:1:0x0702] Received ZCL frame: b'\x18H\x01 \x00\x00B\x00'
0079|[2022-09-02 09:41:02]DEBUG : [0x592B:1:0x0702] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=0, direction=, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True, *is_reply=True), tsn=72, command_id=1, *direction=, *is_reply=True)
0080|[2022-09-02 09:41:02]DEBUG : [0x592B:1:0x0702] Decoded ZCL frame: ZLinkyTICMetering:Read_Attributes_rsp(status_records=[ReadAttributeRecord(attrid=0x0020, status=, value=TypeValue(type=CharacterString, value=''))])
0081|[2022-09-02 09:41:02]DEBUG : executing functools.partial(, 'UPDATE devices_v10
0082|SET last_seen=:ts
0083|WHERE ieee=:ieee AND :ts - last_seen > :min_last_seen_delta', {'ts': 1662104462.075165, 'ieee': 00:15:8d:00:05:d2:a8:e0, 'min_last_seen_delta': 30.0})
0084|[2022-09-02 09:41:02]DEBUG : operation functools.partial(, 'UPDATE devices_v10
0085|SET last_seen=:ts
0086|WHERE ieee=:ieee AND :ts - last_seen > :min_last_seen_delta', {'ts': 1662104462.075165, 'ieee': 00:15:8d:00:05:d2:a8:e0, 'min_last_seen_delta': 30.0}) completed
0087|[2022-09-02 09:41:02]DEBUG : 'aps_data_indication' response from , ep: 1, profile: 0x0104, cluster_id: 0x0702, data: b'1848012000004200'
0088|[2022-09-02 09:41:02]DEBUG : [0x592B:1:0x0702] Couldn't normalize 32 attribute with value
0089|Traceback (most recent call last):
0090|File "/usr/local/lib/python3.9/dist-packages/zigpy/zcl/__init__.py", line 492, in read_attributes
0091|value = self.attributes[record.attrid].type(record.value.value)
0092|File "/usr/local/lib/python3.9/dist-packages/zigpy/types/basic.py", line 259, in __call__
0093|value = int(value)
0094|ValueError: invalid literal for int() with base 10: ''
0095|[2022-09-02 09:41:02]INFO : [00:15:8d:00:05:d2:a8:e0][listener.attribute_updated] Received an attribute update 32= on cluster 1794
0096|[2022-09-02 09:41:02]INFO : [DeviceHandler.post] Attribute Value received : ({32: ''}, {})
0097|[2022-09-02 09:41:02]INFO : 200 POST /device/attributes (127.0.0.1) 28.43ms
0098|[2022-09-02 09:41:02]DEBUG : executing functools.partial()
0099|[2022-09-02 09:41:02]DEBUG : operation functools.partial() completed
0100|[2022-09-02 09:41:02]DEBUG : executing functools.partial(, 'INSERT INTO attributes_cache_v10 VALUES (?, ?, ?, ?, ?)
0101|ON CONFLICT (ieee, endpoint_id, cluster, attrid)
0102|DO UPDATE SET
0103|value=excluded.value WHERE value != excluded.value', (00:15:8d:00:05:d2:a8:e0, 1, 1794, 32, ''))
0104|[2022-09-02 09:41:02]DEBUG : operation functools.partial(, 'INSERT INTO attributes_cache_v10 VALUES (?, ?, ?, ?, ?)
0105|ON CONFLICT (ieee, endpoint_id, cluster, attrid)
0106|DO UPDATE SET
0107|value=excluded.value WHERE value != excluded.value', (00:15:8d:00:05:d2:a8:e0, 1, 1794, 32, '')) completed
0108|[2022-09-02 09:41:02]INFO : [DeviceHandler.prepare] Json arg : {'ieee': '00:15:8d:00:05:d2:a8:e0', 'endpoint': 1, 'cluster': 2820, 'cluster_type': 'in', 'attributes': [1295, 1288, 2312, 2568, 1290, 2314, 2570], 'allowCache': 0}
0109|[2022-09-02 09:41:02]DEBUG : [0x592B:1:0x0b04] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=False, direction=, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True, *is_reply=False), tsn=74, command_id=, *direction=, *is_reply=False)
0110|[2022-09-02 09:41:02]DEBUG : [0x592B:1:0x0b04] Sending request: Read_Attributes(attribute_ids=[1295, 1288, 2312, 2568, 1290, 2314, 2570])
0111|[2022-09-02 09:41:02]DEBUG : Sending Zigbee request with tsn 74 under 75 request id, data: b'004a000f0508050809080a0a050a090a0a'
0112|[2022-09-02 09:41:02]DEBUG : Command Command.aps_data_request (32, 75, , , 260, 2820, 1, b'\x00J\x00\x0f\x05\x08\x05\x08 \x08
0113|\x05
0114|', , 0)
0115|[2022-09-02 09:41:02]DEBUG : Send: 0x12de00270020004b00022b59010401040b011100004a000f0508050809080a0a050a090a0a0200
0116|[2022-09-02 09:41:02]DEBUG : executing functools.partial()
0117|[2022-09-02 09:41:02]DEBUG : operation functools.partial() completed
0118|[2022-09-02 09:41:02]DEBUG : Frame received: 0x12de0009000200224b
0119|[2022-09-02 09:41:02]DEBUG : APS data request response: [2, , 75]
0120|[2022-09-02 09:41:02]DEBUG : Frame received: 0x0edf000700a600
0121|[2022-09-02 09:41:02]DEBUG : Device state changed response: [, 0]
0122|[2022-09-02 09:41:02]DEBUG : Command Command.aps_data_confirm (0,)
0123|[2022-09-02 09:41:02]DEBUG : Send: 0x04df0007000000
0124|[2022-09-02 09:41:02]DEBUG : Frame received: 0x04df0013000c00224b022b5901010000000000
0125|[2022-09-02 09:41:02]DEBUG : APS data confirm response for request with id 75: 00
0126|[2022-09-02 09:41:02]DEBUG : Request id: 0x4b 'aps_data_confirm' for , status: 0x00
0127|[2022-09-02 09:41:02]DEBUG : executing functools.partial(, 'UPDATE devices_v10
0128|SET last_seen=:ts
0129|WHERE ieee=:ieee AND :ts - last_seen > :min_last_seen_delta', {'ts': 1662104462.095805, 'ieee': 00:15:8d:00:05:d2:a8:e0, 'min_last_seen_delta': 30.0})
0130|[2022-09-02 09:41:02]DEBUG : operation functools.partial(, 'UPDATE devices_v10
0131|SET last_seen=:ts
0132|WHERE ieee=:ieee AND :ts - last_seen > :min_last_seen_delta', {'ts': 1662104462.095805, 'ieee': 00:15:8d:00:05:d2:a8:e0, 'min_last_seen_delta': 30.0}) completed
0133|[2022-09-02 09:41:02]DEBUG : executing functools.partial()
0134|[2022-09-02 09:41:02]DEBUG : operation functools.partial() completed
0135|[2022-09-02 09:41:02]DEBUG : Frame received: 0x0ee0000700aa00
0136|[2022-09-02 09:41:02]DEBUG : Device state changed response: [, 0]
0137|[2022-09-02 09:41:02]DEBUG : Command Command.aps_data_indication (1, 1)
0138|[2022-09-02 09:41:02]DEBUG : Send: 0x17e0000800010001
0139|[2022-09-02 09:41:02]DEBUG : Frame received: 0x17e0004b0044002202000001022b59010401040b2d00184a010f050021b10108050021020008090021ffff080a0021ffff0a050021ffff0a090021ffff0a0a0021ffff00affc2c504c01b7
0140|[2022-09-02 09:41:02]DEBUG : APS data indication response: [68, , , 1, , 1, 260, 2820, b'\x18J\x01\x0f\x05\x00!\xb1\x01\x08\x05\x00!\x02\x00\x08 \x00!\xff\xff\x08
0141|\x00!\xff\xff
0142|\x05\x00!\xff\xff
0143|\x00!\xff\xff
0144|\x00!\xff\xff', 0, 175, 252, 44, 80, 76, 1, -73]
0145|[2022-09-02 09:41:02]DEBUG : [0x592B:1:0x0b04] Received ZCL frame: b'\x18J\x01\x0f\x05\x00!\xb1\x01\x08\x05\x00!\x02\x00\x08 \x00!\xff\xff\x08
0146|\x00!\xff\xff
0147|\x05\x00!\xff\xff
0148|\x00!\xff\xff
0149|\x00!\xff\xff'
0150|[2022-09-02 09:41:02]DEBUG : [0x592B:1:0x0b04] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=0, direction=, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True, *is_reply=True), tsn=74, command_id=1, *direction=, *is_reply=True)
0151|[2022-09-02 09:41:02]DEBUG : [0x592B:1:0x0b04] Decoded ZCL frame: ElectricalMeasurement:Read_Attributes_rsp(status_records=[ReadAttributeRecord(attrid=0x050F, status=, value=TypeValue(type=uint16_t, value=433)), ReadAttributeRecord(attrid=0x0508, status=, value=TypeValue(type=uint16_t, value=2)), ReadAttributeRecord(attrid=0x0908, status=, value=TypeValue(type=uint16_t, value=65535)), ReadAttributeRecord(attrid=0x0A08, status=, value=TypeValue(type=uint16_t, value=65535)), ReadAttributeRecord(attrid=0x050A, status=, value=TypeValue(type=uint16_t, value=65535)), ReadAttributeRecord(attrid=0x090A, status=, value=TypeValue(type=uint16_t, value=65535)), ReadAttributeRecord(attrid=0x0A0A, status=, value=TypeValue(type=uint16_t, value=65535))])
0152|[2022-09-02 09:41:02]DEBUG : executing functools.partial(, 'UPDATE devices_v10
0153|SET last_seen=:ts
0154|WHERE ieee=:ieee AND :ts - last_seen > :min_last_seen_delta', {'ts': 1662104462.114545, 'ieee': 00:15:8d:00:05:d2:a8:e0, 'min_last_seen_delta': 30.0})
0155|[2022-09-02 09:41:02]DEBUG : operation functools.partial(, 'UPDATE devices_v10
0156|SET last_seen=:ts
0157|WHERE ieee=:ieee AND :ts - last_seen > :min_last_seen_delta', {'ts': 1662104462.114545, 'ieee': 00:15:8d:00:05:d2:a8:e0, 'min_last_seen_delta': 30.0}) completed
0158|[2022-09-02 09:41:02]DEBUG : 'aps_data_indication' response from , ep: 1, profile: 0x0104, cluster_id: 0x0b04, data: b'184a010f050021b10108050021020008090021ffff080a0021ffff0a050021ffff0a090021ffff0a0a0021ffff'
0159|[2022-09-02 09:41:02]INFO : [00:15:8d:00:05:d2:a8:e0][listener.attribute_updated] Received an attribute update 1295=433 on cluster 2820
0160|[2022-09-02 09:41:02]INFO : [00:15:8d:00:05:d2:a8:e0][listener.attribute_updated] Received an attribute update 1288=2 on cluster 2820
0161|[2022-09-02 09:41:02]INFO : [00:15:8d:00:05:d2:a8:e0][listener.attribute_updated] Received an attribute update 2312=65535 on cluster 2820
0162|[2022-09-02 09:41:02]INFO : [00:15:8d:00:05:d2:a8:e0][listener.attribute_updated] Received an attribute update 2568=65535 on cluster 2820
0163|[2022-09-02 09:41:02]INFO : [00:15:8d:00:05:d2:a8:e0][listener.attribute_updated] Received an attribute update 1290=65535 on cluster 2820
0164|[2022-09-02 09:41:02]INFO : [00:15:8d:00:05:d2:a8:e0][listener.attribute_updated] Received an attribute update 2314=65535 on cluster 2820
0165|[2022-09-02 09:41:02]INFO : [00:15:8d:00:05:d2:a8:e0][listener.attribute_updated] Received an attribute update 2570=65535 on cluster 2820
0166|[2022-09-02 09:41:02]INFO : [DeviceHandler.post] Attribute Value received : ({1295: 433, 1288: 2, 2312: 65535, 2568: 65535, 1290: 65535, 2314: 65535, 2570: 65535}, {})
0167|[2022-09-02 09:41:02]INFO : 200 POST /device/attributes (127.0.0.1) 39.10ms
0168|[2022-09-02 09:41:02]DEBUG : executing functools.partial()
0169|[2022-09-02 09:41:02]DEBUG : operation functools.partial() completed
0170|[2022-09-02 09:41:02]INFO : [DeviceHandler.prepare] Json arg : {'ieee': '00:15:8d:00:05:d2:a8:e0', 'endpoint': 1, 'cluster': 2820, 'cluster_type': 'in', 'attributes': [1293], 'allowCache': 0}
0171|[2022-09-02 09:41:02]DEBUG : executing functools.partial(, 'INSERT INTO attributes_cache_v10 VALUES (?, ?, ?, ?, ?)
0172|ON CONFLICT (ieee, endpoint_id, cluster, attrid)
0173|DO UPDATE SET
0174|value=excluded.value WHERE value != excluded.value', (00:15:8d:00:05:d2:a8:e0, 1, 2820, 1295, 433))
0175|[2022-09-02 09:41:02]DEBUG : operation functools.partial(, 'INSERT INTO attributes_cache_v10 VALUES (?, ?, ?, ?, ?)
0176|ON CONFLICT (ieee, endpoint_id, cluster, attrid)
0177|DO UPDATE SET
0178|value=excluded.value WHERE value != excluded.value', (00:15:8d:00:05:d2:a8:e0, 1, 2820, 1295, 433)) completed
0179|[2022-09-02 09:41:02]DEBUG : [0x592B:1:0x0b04] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=False, direction=, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True, *is_reply=False), tsn=76, command_id=, *direction=, *is_reply=False)
0180|[2022-09-02 09:41:02]DEBUG : [0x592B:1:0x0b04] Sending request: Read_Attributes(attribute_ids=[1293])
0181|[2022-09-02 09:41:02]DEBUG : Sending Zigbee request with tsn 76 under 77 request id, data: b'004c000d05'
0182|[2022-09-02 09:41:02]DEBUG : Command Command.aps_data_request (20, 77, , , 260, 2820, 1, b'\x00L\x00
\x05', , 0)
0183|[2022-09-02 09:41:02]DEBUG : Send: 0x12e1001b0014004d00022b59010401040b010500004c000d050200
0184|[2022-09-02 09:41:02]DEBUG : executing functools.partial()
0185|[2022-09-02 09:41:02]DEBUG : operation functools.partial() completed
0186|[2022-09-02 09:41:02]DEBUG : executing functools.partial(, 'INSERT INTO attributes_cache_v10 VALUES (?, ?, ?, ?, ?)
0187|ON CONFLICT (ieee, endpoint_id, cluster, attrid)
0188|DO UPDATE SET
0189|value=excluded.value WHERE value != excluded.value', (00:15:8d:00:05:d2:a8:e0, 1, 2820, 1288, 2))
0190|[2022-09-02 09:41:02]DEBUG : operation functools.partial(, 'INSERT INTO attributes_cache_v10 VALUES (?, ?, ?, ?, ?)
0191|ON CONFLICT (ieee, endpoint_id, cluster, attrid)
0192|DO UPDATE SET
0193|value=excluded.value WHERE value != excluded.value', (00:15:8d:00:05:d2:a8:e0, 1, 2820, 1288, 2)) completed
0194|[2022-09-02 09:41:02]DEBUG : executing functools.partial()
0195|[2022-09-02 09:41:02]DEBUG : operation functools.partial() completed
0196|[2022-09-02 09:41:02]DEBUG : executing functools.partial(, 'INSERT INTO attributes_cache_v10 VALUES (?, ?, ?, ?, ?)
0197|ON CONFLICT (ieee, endpoint_id, cluster, attrid)
0198|DO UPDATE SET
0199|value=excluded.value WHERE value != excluded.value', (00:15:8d:00:05:d2:a8:e0, 1, 2820, 2312, 65535))
0200|[2022-09-02 09:41:02]DEBUG : operation functools.partial(, 'INSERT INTO attributes_cache_v10 VALUES (?, ?, ?, ?, ?)
0201|ON CONFLICT (ieee, endpoint_id, cluster, attrid)
0202|DO UPDATE SET
0203|value=excluded.value WHERE value != excluded.value', (00:15:8d:00:05:d2:a8:e0, 1, 2820, 2312, 65535)) completed
0204|[2022-09-02 09:41:02]DEBUG : executing functools.partial()
0205|[2022-09-02 09:41:02]DEBUG : operation functools.partial() completed
0206|[2022-09-02 09:41:02]DEBUG : executing functools.partial(, 'INSERT INTO attributes_cache_v10 VALUES (?, ?, ?, ?, ?)
0207|ON CONFLICT (ieee, endpoint_id, cluster, attrid)
0208|DO UPDATE SET
0209|value=excluded.value WHERE value != excluded.value', (00:15:8d:00:05:d2:a8:e0, 1, 2820, 2568, 65535))
0210|[2022-09-02 09:41:02]DEBUG : operation functools.partial(, 'INSERT INTO attributes_cache_v10 VALUES (?, ?, ?, ?, ?)
0211|ON CONFLICT (ieee, endpoint_id, cluster, attrid)
0212|DO UPDATE SET
0213|value=excluded.value WHERE value != excluded.value', (00:15:8d:00:05:d2:a8:e0, 1, 2820, 2568, 65535)) completed
0214|[2022-09-02 09:41:02]DEBUG : executing functools.partial()
0215|[2022-09-02 09:41:02]DEBUG : operation functools.partial() completed
0216|[2022-09-02 09:41:02]DEBUG : executing functools.partial(, 'INSERT INTO attributes_cache_v10 VALUES (?, ?, ?, ?, ?)
0217|ON CONFLICT (ieee, endpoint_id, cluster, attrid)
0218|DO UPDATE SET
0219|value=excluded.value WHERE value != excluded.value', (00:15:8d:00:05:d2:a8:e0, 1, 2820, 1290, 65535))
0220|[2022-09-02 09:41:02]DEBUG : operation functools.partial(, 'INSERT INTO attributes_cache_v10 VALUES (?, ?, ?, ?, ?)
0221|ON CONFLICT (ieee, endpoint_id, cluster, attrid)
0222|DO UPDATE SET
0223|value=excluded.value WHERE value != excluded.value', (00:15:8d:00:05:d2:a8:e0, 1, 2820, 1290, 65535)) completed
0224|[2022-09-02 09:41:02]DEBUG : executing functools.partial()
0225|[2022-09-02 09:41:02]DEBUG : operation functools.partial() completed
0226|[2022-09-02 09:41:02]DEBUG : executing functools.partial(, 'INSERT INTO attributes_cache_v10 VALUES (?, ?, ?, ?, ?)
0227|ON CONFLICT (ieee, endpoint_id, cluster, attrid)
0228|DO UPDATE SET
0229|value=excluded.value WHERE value != excluded.value', (00:15:8d:00:05:d2:a8:e0, 1, 2820, 2314, 65535))
0230|[2022-09-02 09:41:02]DEBUG : operation functools.partial(, 'INSERT INTO attributes_cache_v10 VALUES (?, ?, ?, ?, ?)
0231|ON CONFLICT (ieee, endpoint_id, cluster, attrid)
0232|DO UPDATE SET
0233|value=excluded.value WHERE value != excluded.value', (00:15:8d:00:05:d2:a8:e0, 1, 2820, 2314, 65535)) completed
0234|[2022-09-02 09:41:02]DEBUG : executing functools.partial()
0235|[2022-09-02 09:41:02]DEBUG : operation functools.partial() completed
0236|[2022-09-02 09:41:02]DEBUG : executing functools.partial(, 'INSERT INTO attributes_cache_v10 VALUES (?, ?, ?, ?, ?)
0237|ON CONFLICT (ieee, endpoint_id, cluster, attrid)
0238|DO UPDATE SET
0239|value=excluded.value WHERE value != excluded.value', (00:15:8d:00:05:d2:a8:e0, 1, 2820, 2570, 65535))
0240|[2022-09-02 09:41:02]DEBUG : operation functools.partial(, 'INSERT INTO attributes_cache_v10 VALUES (?, ?, ?, ?, ?)
0241|ON CONFLICT (ieee, endpoint_id, cluster, attrid)
0242|DO UPDATE SET
0243|value=excluded.value WHERE value != excluded.value', (00:15:8d:00:05:d2:a8:e0, 1, 2820, 2570, 65535)) completed
0244|[2022-09-02 09:41:02]DEBUG : executing functools.partial()
0245|[2022-09-02 09:41:02]DEBUG : operation functools.partial() completed
0246|[2022-09-02 09:41:02]DEBUG : Frame received: 0x12e10009000200224d
0247|[2022-09-02 09:41:02]DEBUG : APS data request response: [2, , 77]
0248|[2022-09-02 09:41:02]DEBUG : Frame received: 0x0ee2000700a600
0249|[2022-09-02 09:41:02]DEBUG : Device state changed response: [, 0]
0250|[2022-09-02 09:41:02]DEBUG : Command Command.aps_data_confirm (0,)
0251|[2022-09-02 09:41:02]DEBUG : Send: 0x04e20007000000
0252|[2022-09-02 09:41:02]DEBUG : Frame received: 0x04e20013000c00224d022b5901010000000000
0253|[2022-09-02 09:41:02]DEBUG : APS data confirm response for request with id 77: 00
0254|[2022-09-02 09:41:02]DEBUG : Request id: 0x4d 'aps_data_confirm' for , status: 0x00
0255|[2022-09-02 09:41:02]DEBUG : executing functools.partial(, 'UPDATE devices_v10
0256|SET last_seen=:ts
0257|WHERE ieee=:ieee AND :ts - last_seen > :min_last_seen_delta', {'ts': 1662104462.132192, 'ieee': 00:15:8d:00:05:d2:a8:e0, 'min_last_seen_delta': 30.0})
0258|[2022-09-02 09:41:02]DEBUG : operation functools.partial(, 'UPDATE devices_v10
0259|SET last_seen=:ts
0260|WHERE ieee=:ieee AND :ts - last_seen > :min_last_seen_delta', {'ts': 1662104462.132192, 'ieee': 00:15:8d:00:05:d2:a8:e0, 'min_last_seen_delta': 30.0}) completed
0261|[2022-09-02 09:41:02]DEBUG : executing functools.partial()
0262|[2022-09-02 09:41:02]DEBUG : operation functools.partial() completed
0263|[2022-09-02 09:41:02]DEBUG : Frame received: 0x0ee3000700aa00
0264|[2022-09-02 09:41:02]DEBUG : Device state changed response: [, 0]
0265|[2022-09-02 09:41:02]DEBUG : Command Command.aps_data_indication (1, 1)
0266|[2022-09-02 09:41:02]DEBUG : Send: 0x17e3000800010001
0267|[2022-09-02 09:41:02]DEBUG : Frame received: 0x17e300270020002202000001022b59010401040b0900184c010d050029240900afff2c504c01b3
0268|[2022-09-02 09:41:02]DEBUG : APS data indication response: [32, , , 1, , 1, 260, 2820, b'\x18L\x01
\x05\x00)$ ', 0, 175, 255, 44, 80, 76, 1, -77]
0269|[2022-09-02 09:41:02]DEBUG : [0x592B:1:0x0b04] Received ZCL frame: b'\x18L\x01
\x05\x00)$ '
0270|[2022-09-02 09:41:02]DEBUG : [0x592B:1:0x0b04] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=0, direction=, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True, *is_reply=True), tsn=76, command_id=1, *direction=, *is_reply=True)
0271|[2022-09-02 09:41:02]DEBUG : [0x592B:1:0x0b04] Decoded ZCL frame: ElectricalMeasurement:Read_Attributes_rsp(status_records=[ReadAttributeRecord(attrid=0x050D, status=, value=TypeValue(type=int16s, value=2340))])
0272|[2022-09-02 09:41:02]DEBUG : executing functools.partial(, 'UPDATE devices_v10
0273|SET last_seen=:ts
0274|WHERE ieee=:ieee AND :ts - last_seen > :min_last_seen_delta', {'ts': 1662104462.145691, 'ieee': 00:15:8d:00:05:d2:a8:e0, 'min_last_seen_delta': 30.0})
0275|[2022-09-02 09:41:02]DEBUG : operation functools.partial(, 'UPDATE devices_v10
0276|SET last_seen=:ts
0277|WHERE ieee=:ieee AND :ts - last_seen > :min_last_seen_delta', {'ts': 1662104462.145691, 'ieee': 00:15:8d:00:05:d2:a8:e0, 'min_last_seen_delta': 30.0}) completed
0278|[2022-09-02 09:41:02]DEBUG : 'aps_data_indication' response from , ep: 1, profile: 0x0104, cluster_id: 0x0b04, data: b'184c010d0500292409'
0279|[2022-09-02 09:41:02]INFO : [00:15:8d:00:05:d2:a8:e0][listener.attribute_updated] Received an attribute update 1293=2340 on cluster 2820
0280|[2022-09-02 09:41:02]INFO : [DeviceHandler.post] Attribute Value received : ({1293: 2340}, {})
0281|[2022-09-02 09:41:02]INFO : 200 POST /device/attributes (127.0.0.1) 29.81ms
0282|[2022-09-02 09:41:02]DEBUG : executing functools.partial()
0283|[2022-09-02 09:41:02]DEBUG : operation functools.partial() completed
0284|[2022-09-02 09:41:02]INFO : [DeviceHandler.prepare] Json arg : {'ieee': '00:15:8d:00:05:d2:a8:e0', 'endpoint': 1, 'cluster': 65382, 'cluster_type': 'in', 'attributes': [2, 1, 4, 5, 6, 7, 8], 'allowCache': 0}
0285|[2022-09-02 09:41:02]DEBUG : executing functools.partial(, 'INSERT INTO attributes_cache_v10 VALUES (?, ?, ?, ?, ?)
0286|ON CONFLICT (ieee, endpoint_id, cluster, attrid)
0287|DO UPDATE SET
0288|value=excluded.value WHERE value != excluded.value', (00:15:8d:00:05:d2:a8:e0, 1, 2820, 1293, 2340))
0289|[2022-09-02 09:41:02]DEBUG : operation functools.partial(, 'INSERT INTO attributes_cache_v10 VALUES (?, ?, ?, ?, ?)
0290|ON CONFLICT (ieee, endpoint_id, cluster, attrid)
0291|DO UPDATE SET
0292|value=excluded.value WHERE value != excluded.value', (00:15:8d:00:05:d2:a8:e0, 1, 2820, 1293, 2340)) completed
0293|[2022-09-02 09:41:02]DEBUG : [0x592B:1:0xff66] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=False, direction=, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True, *is_reply=False), tsn=78, command_id=, *direction=, *is_reply=False)
0294|[2022-09-02 09:41:02]DEBUG : [0x592B:1:0xff66] Sending request: Read_Attributes(attribute_ids=[2, 1, 4, 5, 6, 7, 8])
0295|[2022-09-02 09:41:02]DEBUG : Sending Zigbee request with tsn 78 under 79 request id, data: b'004e000200010004000500060007000800'
0296|[2022-09-02 09:41:02]DEBUG : Command Command.aps_data_request (32, 79, , , 260, 65382, 1, b'\x00N\x00\x02\x00\x01\x00\x04\x00\x05\x00\x06\x00\x07\x00\x08\x00', , 0)
0297|[2022-09-02 09:41:02]DEBUG : Send: 0x12e400270020004f00022b5901040166ff011100004e0002000100040005000600070008000200
0298|[2022-09-02 09:41:02]DEBUG : executing functools.partial()
0299|[2022-09-02 09:41:02]DEBUG : operation functools.partial() completed
0300|[2022-09-02 09:41:02]DEBUG : Frame received: 0x12e40009000200224f
0301|[2022-09-02 09:41:02]DEBUG : APS data request response: [2, , 79]
0302|[2022-09-02 09:41:02]DEBUG : Frame received: 0x0ee5000700a600
0303|[2022-09-02 09:41:02]DEBUG : Device state changed response: [, 0]
0304|[2022-09-02 09:41:02]DEBUG : Command Command.aps_data_confirm (0,)
0305|[2022-09-02 09:41:02]DEBUG : Send: 0x04e50007000000
0306|[2022-09-02 09:41:02]DEBUG : Frame received: 0x04e50013000c00224f022b5901010000000000
0307|[2022-09-02 09:41:02]DEBUG : APS data confirm response for request with id 79: 00
0308|[2022-09-02 09:41:02]DEBUG : Request id: 0x4f 'aps_data_confirm' for , status: 0x00
0309|[2022-09-02 09:41:02]DEBUG : executing functools.partial(, 'UPDATE devices_v10
0310|SET last_seen=:ts
0311|WHERE ieee=:ieee AND :ts - last_seen > :min_last_seen_delta', {'ts': 1662104462.16421, 'ieee': 00:15:8d:00:05:d2:a8:e0, 'min_last_seen_delta': 30.0})
0312|[2022-09-02 09:41:02]DEBUG : operation functools.partial(, 'UPDATE devices_v10
0313|SET last_seen=:ts
0314|WHERE ieee=:ieee AND :ts - last_seen > :min_last_seen_delta', {'ts': 1662104462.16421, 'ieee': 00:15:8d:00:05:d2:a8:e0, 'min_last_seen_delta': 30.0}) completed
0315|[2022-09-02 09:41:02]DEBUG : executing functools.partial()
0316|[2022-09-02 09:41:02]DEBUG : operation functools.partial() completed
0317|[2022-09-02 09:41:02]DEBUG : Frame received: 0x0ee6000700aa00
0318|[2022-09-02 09:41:02]DEBUG : Device state changed response: [, 0]
0319|[2022-09-02 09:41:02]DEBUG : Command Command.aps_data_indication (1, 1)
0320|[2022-09-02 09:41:02]DEBUG : Send: 0x17e6000800010001
0321|[2022-09-02 09:41:02]DEBUG : Frame received: 0x17e6004c0045002202000001022b5901040166ff2e00184e010200002000010000420400000000040000200005000021000006000021000007000021000008000021000000afff2c504c01b7
0322|[2022-09-02 09:41:02]DEBUG : APS data indication response: [69, , , 1, , 1, 260, 65382, b'\x18N\x01\x02\x00\x00 \x00\x01\x00\x00B\x04\x00\x00\x00\x00\x04\x00\x00 \x00\x05\x00\x00!\x00\x00\x06\x00\x00!\x00\x00\x07\x00\x00!\x00\x00\x08\x00\x00!\x00\x00', 0, 175, 255, 44, 80, 76, 1, -73]
0323|[2022-09-02 09:41:02]DEBUG : [0x592B:1:0xff66] Received ZCL frame: b'\x18N\x01\x02\x00\x00 \x00\x01\x00\x00B\x04\x00\x00\x00\x00\x04\x00\x00 \x00\x05\x00\x00!\x00\x00\x06\x00\x00!\x00\x00\x07\x00\x00!\x00\x00\x08\x00\x00!\x00\x00'
0324|[2022-09-02 09:41:02]DEBUG : [0x592B:1:0xff66] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=0, direction=, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True, *is_reply=True), tsn=78, command_id=1, *direction=, *is_reply=True)
0325|[2022-09-02 09:41:02]DEBUG : [0x592B:1:0xff66] Decoded ZCL frame: ManufacturerSpecificCluster:Read_Attributes_rsp(status_records=[ReadAttributeRecord(attrid=0x0002, status=, value=TypeValue(type=uint8_t, value=0)), ReadAttributeRecord(attrid=0x0001, status=, value=TypeValue(type=CharacterString, value='')), ReadAttributeRecord(attrid=0x0004, status=, value=TypeValue(type=uint8_t, value=0)), ReadAttributeRecord(attrid=0x0005, status=, value=TypeValue(type=uint16_t, value=0)), ReadAttributeRecord(attrid=0x0006, status=, value=TypeValue(type=uint16_t, value=0)), ReadAttributeRecord(attrid=0x0007, status=, value=TypeValue(type=uint16_t, value=0)), ReadAttributeRecord(attrid=0x0008, status=, value=TypeValue(type=uint16_t, value=0))])
0326|[2022-09-02 09:41:02]DEBUG : executing functools.partial(, 'UPDATE devices_v10
0327|SET last_seen=:ts
0328|WHERE ieee=:ieee AND :ts - last_seen > :min_last_seen_delta', {'ts': 1662104462.184122, 'ieee': 00:15:8d:00:05:d2:a8:e0, 'min_last_seen_delta': 30.0})
0329|[2022-09-02 09:41:02]DEBUG : operation functools.partial(, 'UPDATE devices_v10